Immer wieder sorgen die Blogposts von Kyle Kingsbury, auch bekannt unter seinem Twitter Handle @aphyr, für Aufmerksamkeit. Dieser testet mithilfe der selbst entwickelten Open-Source-Lösung Jepsen bekannte verteilte Datenbanken und veröffentlicht diese Ergebnisse und Analysen auf seinem Blog.

Diese Kolumne erläutert kurz die Theorie zu verteilten Datenbanken und zeigt anschließend, wie man selbst mithilfe von Jepsen ein solches System überprüfen kann.

Verteilte Datenbanken

Verteilte Datenbanken setzen für Skalierung und Verfügbarkeit auf eine horizontale Verteilung. Das heißt, man installiert die Datenbank auf mehreren Knoten und verbindet diese über das Netzwerk zu einem Cluster. Ein solcher Cluster kann den Ausfall eines einzelnen Knotens überleben und weiterarbeiten.

Dieser Vorteil wird allerdings dadurch erkauft, dass die einzelnen Knoten sich über das Netzwerk abstimmen müssen. Netzwerkaufrufe haben jedoch eine gewisse Latenz. Dies führt dazu, dass es immer wieder Zeiten gibt, in denen nicht alle Knoten denselben Stand besitzen. Zudem kann das Netzwerk zwischen den Knoten auch komplett ausfallen.

Solche Systeme gehorchen somit dem CAP- beziehungsweise PACELC-Theorem. CAP sagt aus, dass ein verteiltes System von den Eigenschaften Konsistenz (C, Consistency), Verfügbarkeit (A, Availability) und Partitionstoleranz (P, Partition tolerance) immer nur zwei erfüllen kann. Da jedoch Netzwerkpartitionen in einem verteilten System nie auszuschließen sind, führt es dazu, dass man sich nur zwischen Verfügbarkeit und Konsistenz entscheiden kann.

PACELC erweitert das CAP-Theorem. Es besagt, genau wie CAP, dass man sich im Falle einer Netzwerkpartition zwischen A und C entscheiden muss (PAC). Aber auch wenn das System normal läuft (E, else), muss es sich zwischen Latenz (L, Latency) und Konsistenz (C) entscheiden.

Jepsen

Um zu überprüfen, wie sich ein verteiltes System, insbesondere im Partitionsfall, verhält, kann man mit Jepsen Tests schreiben und deren Ergebnisse anschließend analysieren.

Den Mittelpunkt von Jepsen bildet dabei der Kontrollknoten. Dieser installiert, konfiguriert und startet das zu testende System auf einer Menge von Systemknoten. Anschließend startet er mehrere Prozesse, die gültige Operationen gegen das zu testende System ausführen. Dabei werden Beginn und Ende jeder Operation zusätzlich in einem Log erfasst. Neben diesen regulären Prozessen gibt es einen Nemesis-Prozess. Dieser produziert gezielt Fehlerfälle wie beispielsweise Netzwerkpartitionen. Nach einem Testlauf nutzt Jepsen ein Modell und einen Checker, um die im Log aufgezeichnete Historie des Tests zu analysieren. Neben einer Prüfung auf Korrektheit können auch diverse Graphen erzeugt werden.

Um all dies zu ermöglichen, stellt Jepsen, in Form einer Clojure-Bibliothek, Funktionen und Datenstrukturen bereit, die den Entwickler bei den folgenden Punkten unterstützen:

Im Folgenden wird gezeigt, wie jeder dieser Punkte konkret mit Jepsen umgesetzt wird.

System installieren

Als Erstes muss das zu testende System auf mehreren Knoten installiert und konfiguriert werden. Zusätzlich müssen auf jedem Knoten noch ein paar Dinge für die Nutzung von Jepsen vorbereitet werden. Die beiden Hauptabstraktionen, die Jepsen hierzu anbietet, sind die Clojure-Protokolle, vergleichbar mit Interfaces in Java: jepsen.db/DB und jepsen.os/OS.

jepsen.os/OS besteht aus den beiden Funktionen setup! und teardown! und ist dafür zuständig, einen Knoten für die Verwendung mit Jepsen vorzubereiten beziehungsweise anschließend wieder aufzuräumen. Jepsen selbst stellt Implementierungen für Debian und SmartOS zur Verfügung. Da die bestehenden Jepsen-Tests zumeist Debian einsetzen, bietet sich dessen Verwendung an.

Nachdem das Betriebssystem für die Verwendung von Jepsen vorbereitet ist, muss das zu testende System installiert werden. Hierzu muss das Protokoll jepsen.db/DB implementiert werden. Listing 1 zeigt eine mögliche Implementierung für etcd.

(def dir "/opt/etcd")
(def binary "etcd")
(def logfile (str dir "/etcd.log"))
(def pidfile (str dir "/etcd.pid"))

(deftype Etcd [version]
  db/DB
  (setup! [db test node]
    (info "Setting up etcd")
    (c/su
      (let [url (str "https://storage.googleapis.com/etcd/"
                     version
                     "/etcd-"
                     version
                     "-linux-amd64.tar.gz")]
        (cu/install-archive! url dir))
      (cu/start-daemon!
        {:logfile logfile
         :pidfile pidfile
         :chdir dir}
        binary
        :--log-output :stderr
        :--name (name node)
        :--listen-peer-urls (peer-url node)
        :--listen-client-urls (client-url node)
        :--advertise-client-urls (client-url node)
        :--initial-cluster-state :new
        :--initial-advertise-peer-urls (peer-url node)
        :--initial-cluster (initial-cluster test))
      (Thread/sleep 5000)))

  (teardown! [db test node]
    (info "Tearing down etcd")
    (cu/stop-daemon! binary pidfile)
    (c/su
      (c/exec :rm :-rf dir))))
Listing 1: Installation von etcd

Für die Installation wird zuerst ein tar.gz-Archiv von etcd heruntergeladen und entpackt. Anschließend wird das vorhandene etcd-Binary als Dämonprozess gestartet. Da diese Dinge für viele Systeme gebraucht werden, enthält Jepsen hierfür Hilfsfunktionen. Als letzten Schritt bei der Installation wird noch 5 Sekunden gewartet, um dem System Zeit zum Hochfahren zu geben.

Das Aufräumen sieht ähnlich aus. Erst wird der vormals gestartete Prozess gestoppt und danach das komplette Installationsverzeichnis gelöscht.

Einsammeln von Logdateien

Zur detaillierten Analyse nach einem Testlauf werden häufig die Logdateien des Systems benötigt. Da jedoch nach einem Lauf das komplette Verzeichnis gelöscht wird, gehen diese verloren. Es muss also dafür gesorgt werden, die Logdateien von den einzelnen Systemknoten auf den Kontrollknoten zu kopieren. Auch hierfür bietet Jepsen ein Clojure-Protokoll, jepsen.db/Logfiles, an. Dazu wird der in Listing 1 gezeigte Typ um die Zeilen aus Listing 2 ergänzt.

db/LogFiles
  (log-files [db test node]
    [logfile])
Listing 2: Einsammeln der Logdateien

Anschließend befinden sich nach einem Testlauf die Logdateien aller Systemknoten auf dem Kontrollknoten im Verzeichnis store/latest/<node-name>/.

Definition und Ausführung von Operationen

Nachdem nun das zu testende System installiert und gestartet ist, müssen die möglichen Operationen definiert werden. Im Falle von etcd sind das die drei Operationen Read, Write und Compare-And-Set (CAS). Listing 3 zeigt, wie diese in Clojure definiert werden. Alle Operationen sind vom Typ invoke und haben einen Funktionsnamen f und einen Wert value.

(defn r [_ _] {:type :invoke, :f :read, :value nil})
(defn w [_ _] {:type :invoke, :f :write, :value (rand-int 5)})
(defn cas [_ _] {:type :invoke, :f :cas,
                 :value [(rand-int 5) (rand-int 5)]})
Listing 3: Definition der Operationen

Um diese Operationen nun auszuführen, wird ein Client benötigt. Dieser weiß, wie er eine Verbindung zum zu testenden System aufbaut und wie die definierten Operationen technisch umgesetzt werden. Hierzu muss das Protokoll jepsen.client/Client implementiert werden. Listing 4 zeigt eine beispielhafte Implementierung für etcd.

(defrecord EtcdClient [conn]
  client/Client
  (setup! [client test node]
    (assoc client
           :conn (v/connect (client-url node)
                            {:timeout 5000})))
  (invoke! [client test op]
    (case (:f op)
      :read (assoc op
                   :type :ok,
                   :value (parse-long (v/get conn "cats")))
      :write (do (v/reset! conn "cats" (:value op))
                 (assoc op :type :ok))
      :cas (try+
             (let [[v v'] (:value op)]
               (assoc op :type (if (v/cas! conn "cats" v v')
                                 :ok
                                 :fail)))
             (catch [:errorCode 100] _
               (assoc op :type :fail, :error :not-found)))))
  (teardown! [_ test]))
Listing 4: Client für etcd

Der gesamte Client nutzt die Clojure-Bibliothek Verschlimmbesserung für die Kommunikation mit etcd. Mithilfe dieser wird in der Funktion setup! eine Verbindung zu etcd hergestellt.

Die Funktion invoke! wird während eines Tests mehrfach mit verschiedenen Operationen aufgerufen. Basierend auf der konkreten Operation wird also entweder der Wert zum Schlüssel cats gelesen, gesetzt oder mittels CAS verändert. Als Rückgabe fordert Jepsen hier eine Map, die mindestens den Schlüssel type enthält. Der Wert ok sagt dabei aus, dass alles funktioniert hat, fail wird genutzt, wenn die Operation nicht erfolgreich ausgeführt werden konnte, und info kann genutzt werden, wenn man nicht sicher ist, ob es erfolgreich war. Zusätzlich enthält die Antwort auf eine Read-Operation noch den tatsächlich gelesenen Wert.

Als letzten Schritt muss nun noch eine Abfolge von Operationen generiert und tatsächlich ausgeführt werden. Hierzu wird ein Generator definiert. Dieser generiert nach definierten Regeln bei jedem Aufruf eine zufällige Operation, die anschließend vom Client ausgeführt wird. Listing 5 zeigt einen möglichen Generator.

(defn generator [time-limit]
  (->> (gen/mix [r w cas])
       (gen/stagger 1/10)
       (gen/clients)
       (gen/time-limit time-limit)))
Listing 5: Generator für Operationen

Dieser Generator wählt zufällig eine aus den drei zur Verfügung stehenden Operationen aus. Nach jeder Operation wartet er eine kurze Zeit, bis die nächste Operation gewählt wird. Und zuletzt bricht dieser Generator ab, wenn das konfigurierte Zeitlimit abgelaufen ist. Lässt man Jepsen nun laufen, entsteht ein Jepsen-Log ähnlich zu dem in Listing 6.

2017-09-20 13:41:29,901{GMT} -> INFO -> [jepsen test runner] jepsen. core: Running test:
2017-09-20 13:41:30,585{GMT} -> INFO [jepsen node ec2-18-196-0-107.eu- central-1.compute.amazonaws.com] jepsen.os.debian: ec2-18-196-0-107.eu- central-1.compute.amazonaws.com setting up debian
...
2017-09-20 13:41:32,626{GMT} -> INFO -> [jepsen node ec2-18-196-0-107. eu-central-1.compute.amazonaws.com] jepsen.etcdemo: Setting up etcd ...
2017-09-20 13:41:39,256{GMT} -> INFO -> [jepsen worker 0] jepsen.core: Worker 0 starting
...
2017-09-20 13:41:49,745{GMT} -> INFO -> [jepsen worker 3] jepsen.util: -> 3 -> :invoke :read nil
2017-09-20 13:41:49,748{GMT} -> INFO -> [jepsen worker 3] jepsen.util: 3->:ok->:read1
2017-09-20 13:41:49,876{GMT} -> INFO -> [jepsen worker 4] jepsen.util: 4 -> :invoke -> :cas -> [2 4]
2017-09-20 13:41:49,877{GMT} -> INFO -> [jepsen worker 3] jepsen.util: 3 -> :invoke -> :write 2
2017-09-20 13:41:49,882{GMT} -> INFO -> [jepsen worker 3] jepsen.util: 3->:ok->:write2
2017-09-20 13:41:49,883{GMT} -> INFO -> [jepsen worker 4] jepsen.util: 4->:fail->:cas[24]
2017-09-20 13:41:50,228{GMT} -> INFO -> [jepsen worker 2] jepsen.util: 2 -> :invoke -> :write 0
2017-09-20 13:41:50,233{GMT} -> INFO -> [jepsen worker 2] jepsen.util: 2->:ok->:write0
...
2017-09-20 13:41:54,870{GMT} -> INFO -> [jepsen worker 3] jepsen.core: Worker 3 done
...
2017-09-20 13:41:54,872{GMT} -> INFO -> [jepsen test runner] jepsen. core: Snarfing log files
...
2017-09-20 13:41:54,878{GMT} -> INFO -> [jepsen node ec2-18-194-134- 185.eu-central-1.compute.amazonaws.com] jepsen.core: downloading /opt/ etcd/etcd.log to etcd.log
2017-09-20 13:41:54,894{GMT} -> INFO -> [jepsen test runner] jepsen. core: Run complete, writing
...
2017-09-20 13:41:54,928{GMT} -> INFO -> [jepsen node ec2-18-194-87-54. eu-central-1.compute.amazonaws.com] jepsen.control.util: Stopping etcd 2017-09-20 13:41:55,243{GMT} -> INFO -> [jepsen test runner] jepsen. core: Analyzing
2017-09-20 13:41:55,243{GMT} -> INFO -> [jepsen test runner] jepsen. core: Analysis complete
2017-09-20 13:41:55,245{GMT} -> INFO -> [jepsen results] jepsen.store: Wrote /home/admin/jepsen.etcdemo/store/etcdemo/20170920T134129.000Z/ results.edn
2017-09-20 13:41:55,248{GMT} -> INFO -> [main] jepsen.core: {:valid? true}

Everything looks good!
Listing 6: Auszug aus Jepsen-Log

Anhand dieses Logs kann man den gesamten Verlauf des Tests nachvollziehen. Zuerst wurden das Betriebssystem und etcd installiert. Anschließend werden die Prozesse gestartet. Diese führen nun parallel zufällige Operationen aus und protokollieren deren Start und Ergebnis. Zum Schluss werden alle Logdateien der Systemknoten eingesammelt, das System wird gestoppt und die Ergebnisse werden analysiert.

Testergebnisse prüfen

Bisher prüft Jepsen lediglich, dass alle Operationen durchlaufen, ohne Fehler zu werfen. Operationen, die in einem fail enden, sind dabei keine Fehler, sondern durchaus erwartet. Dadurch, dass zufällige Werte von 1 bis 5 geschrieben und auch für CAS genutzt werden, ist es nicht verwunderlich, wenn im Schnitt ca. 4/5 dieser Operationen fehlschlagen, da der Wert, der vor dem Set verglichen wird, nicht passt.

Natürlich möchte man die Ergebnisse des Tests auch auf andere Dinge als nur „Lief ohne Fehler durch“ analysieren. Hierzu müssen zwei Dinge definiert werden: das Modell, das man überprüfen möchte, und ein oder mehrere Checker, die mithilfe des Logs prüfen, ob das Modell eingehalten wird.

Um eigene Modelle zu definieren, nutzt Jepsen die Clojure-Bibliothek Knossos. Neben der Möglichkeit, eigene Modelle zu definieren, liefert Knossos auch einige bereits fertige Modelle mit. Eines davon ist das Modell eines CASRegisters (s. Listing 7).

(defrecord CASRegister [value]
  Model
  (step [r op]
    (condp = (:f op)
      :write (CASRegister. (:value op))
      :cas (let [[cur new] (:value op)]
             (if (= cur value)
               (CASRegister. new)
               (inconsistent (str "can‘t CAS " value " from " cur
                                  " to " new))))
      :read (if (or (nil? (:value op))
                    (= value (:value op)))
              r
              (inconsistent (str "can‘t read " (:value op)
                                 " from register " value)))))
  Object
  (toString [this] (pr-str value)))
Listing 7: Knossos CASRegister

Kurz gesagt beschreibt dieses Modell, dass ein Write dazu führt, dass der Wert auf den Wert des Writes gesetzt wird, dass ein Read auch wirklich den zuletzt geschriebenen Wert gelesen hat und dass ein CAS ausgeführt werden durfte oder nicht.

Neben dem Modell werden zusätzlich ein oder mehrere Checker definiert. Einer der von Jepsen mitgelieferten Checker prüft dabei das Modell auf Linearisierbarkeit, das heißt, er prüft, ob jede Operation in sich atomar verlaufen ist. Checker müssen aber nicht zwangsweise das Modell überprüfen, sondern werden innerhalb von Jepsen auch dazu genutzt, diverse Visualisierungen zu erzeugen. Somit lassen sich zum Beispiel Graphen für den Durchsatz rendern.

Fehler im Cluster provozieren

Die bisherigen Testläufe fördern noch keine Fehler zutage. Etcd läuft stabil und kann parallele Operationen fehlerfrei verarbeiten. Um dies zu ändern, gibt es den Nemesis-Prozess. Dieser läuft parallel zu den eigentlichen Clients und ist dazu da, das zu testende System durcheinanderzubringen. Hierzu kann er beispielsweise Netzwerkpartitionen erzeugen, das heißt, das Netzwerk zwischen Systemknoten unterbrechen, Systemknoten abschießen oder Wartungsoperationen initiieren.

Neben der Angabe, was der Nemesis machen soll, muss auch der Generator erweitert werden (s. Listing 8). In diesem Falle wird 5 Sekunden gewartet, bevor der Nemesis gestartet wird, um diesen nach weiteren 5 Sekunden wieder zu stoppen. Nimmt man nun zum Beispiel den in Jepsen bereits vorhandenen Nemesis, um das Netzwerk zwischen den Systemknoten in zufällige Hälften zu teilen, und lässt Jepsen mehrmals laufen, erhält man früher oder später einen Fehler. Zusätzlich zum Log erzeugt Jepsen hier eine Visualisierung (s. Abb. 1).

(defn generator [time-limit]
  (->> (gen/mix [r w cas])
       (gen/stagger 1/10)
       (gen/nemesis
         (gen/seq (cycle [(gen/sleep 5)
                          {:type :info, :f :start}
                          (gen/sleep 5)
                          {:type :info, :f :stop}])))
       (gen/time-limit time-limit)))
Listing 8: Nemesis konfigurieren
Abb. 1: Visualisierung eines Fehlerfalls

Die Visualisierung zeigt, dass Prozess 8 eine Read-Operation ausgeführt hat, die mit dem Wert 2 beantwortet wurde. Jepsen hat allerdings festgestellt, dass etcd vorher bereits auf ein Read mit 1 geantwortet hat (Prozess 1) und zwischen diesen beiden Reads nur Write- oder CAS-Operationen stattgefunden haben, die den Wert nicht auf 2 geändert haben können. Insofern hat dieser Testlauf es geschafft, das zu testenden System in einen Zustand zu bringen, in dem die Eigenschaft der Linearisierbarkeit nicht mehr gilt.

Dieses Ergebnis sagt allerdings nicht aus, ob dies auch ein Bug ist. Hierzu muss man sich noch angucken, welche Garantien das zu testende System überhaupt bietet. Sollte es allerdings Linearisierbarkeit garantieren, dann wurde ein Bug gefunden.

Fazit

Diese Kolumne hat, mithilfe des Beispiels etcd, gezeigt, wie man mit Jepsen verteilte Systeme überprüfen kann.

Hierzu setzt man zuerst die Systemknoten auf und installiert dort das verteilte System. Anschließend definiert man mögliche Operationen und implementiert einen Client, um diese auch auszuführen. Mit einem Modell und einem Checker kann man nun gewisse Eigenschaften des Systems überprüfen und dabei Fehler oder Performanzprobleme finden.

Wer sich für das Thema interessiert, sollte die bisher von Kyle Kingsbury veröffentlichten Analysen lesen. Dabei ist jedoch zu beachten, dass die Analysen häufig gegen mittlerweile veraltete Versionen der Datenbanken gemacht wurden. Demnach müssen diese heute nicht mehr stimmen. Wer auf Nummer sicher gehen möchte, kann die Analysen natürlich auch gegen neuere Versionen oder noch nicht getestete Datenbanken selbst ausführen.

Das komplette Beispiel dieser Kolumne ist auf GitHub unter dem Link https://github.com/mvitz/javaspektrum-jepsen verfügbar.