Instrumentieren verteilter Systeme für Einblicke in die Betriebsabläufe

Als ich nach dem College bei Amazon anfing, bestand eine meiner ersten Eingliederungsaufgaben darin, den Webserver von amazon.com auf meinem Entwickler-Desktop ans Laufen zu bringen. Beim ersten Versuch hatte ich es nicht geschafft und ich war mir nicht sicher, was ich falsch gemacht hatte. Ein hilfsbereiter Kollege schlug vor, ich solle mir die Protokolle ansehen, um festzustellen, wo das Problem lag. Dazu, sagte er, solle ich "die Protokolldatei per cat ausgeben". Ich war überzeugt, dass sie mir einen Streich spielen oder einen Witz über Katzen machen, den ich nicht verstehe. Im College hatte ich nur Linux benutzt, um zu kompilieren, um die Versionsverwaltung und einen Texteditor zu verwenden. Daher wusste ich nicht, dass "cat" ein Befehl ist, um am Terminal eine Datei auszugeben, die ich zur Suche nach Mustern in ein anderes Programm einspeisen kann.

Meine Kollegen wiesen mich auf Tools wie cat, grep, sed und awk hin. Ausgestattet mit diesen neuen Werkzeugen, tauchte ich auf meinem Entwickler-Desktop in die Webserver-Protokolle von amazon.com ein. Die Webserver-Anwendung war bereits so instrumentiert, dass alle möglichen nützlichen Informationen in die Protokolle einflossen. Dadurch konnte ich feststellen, welche Konfiguration mir entging, die den Start des Webservers verhinderte, die zeigte, wo er möglicherweise abstürzte oder wo er nicht mit einem nachgelagerten Service kommunizierte. Die Website besteht aus vielen veränderlichen Teilen und am Anfang war sie für mich praktisch eine Blackbox. Nachdem ich mich jedoch eingehend mit dem System befasst hatte, lernte ich, wie man feststellt, wie der Server funktioniert und wie man mit seinen Abhängigkeiten interagiert, indem man sich einfach nur die Ausgabe der Instrumentierung ansieht.

Um Services entsprechend unseren hohen Verfügbarkeits- und Latenzstandards zu betreiben, müssen wir als Servicezuständige messen, wie sich unsere Systeme verhalten.

Zum Erhalt der notwendigen Telemetriedaten messen Servicezuständige die betriebliche Leistung an mehreren Stellen, um verschiedene Perspektiven zum Gesamtverhalten der Systeme zu bekommen. Das ist selbst bei einer einfachen Architektur schon kompliziert. Denken Sie an einen Service, den Kunden über einen Load Balancer aufrufen: Der Service kommuniziert mit einem Remote-Cache und einer Remote-Datenbank. Jede Komponente soll Metriken über ihr Verhalten ausgeben. Zudem wünschen wir uns Metriken dazu, wie jede Komponente das Verhalten anderer Komponenten wahrnimmt. Wenn Metriken aus all diesen Perspektiven zusammengeführt werden, kann ein Servicezuständiger die Quelle von Problemen schnell aufspüren und nach der Ursache suchen.

Viele AWS-Services bieten automatisch betriebliche Einblicke in Ihre Ressourcen. Amazon DynamoDB beispielsweise stellt Amazon CloudWatch-Metriken zu den Erfolgs- und Fehlerraten und zur Latenz bereit, wie sie vom Service gemessen werden. Wenn wir jedoch Systeme entwickeln, die diese Services nutzen, benötigen wir viel bessere Einblicke in das Verhalten unserer Systeme. Die Instrumentierung erfordert einen expliziten Code, der festhält, wie lange Aufgaben dauern, wie oft bestimmte Codepfade durchlaufen werden, Metadaten darüber, woran die Aufgabe gearbeitet hat und welche Teile der Aufgaben erfolgreich waren oder fehlgeschlagen sind. Wenn ein Team keine explizite Instrumentierung hinzufügt, müsste es den eigenen Service sozusagen als Blackbox betreiben.

Wenn wir beispielsweise einen Service-API-Vorgang implementieren würden, der Produktinformationen nach Produkt-ID abruft, könnte der Code wie im folgenden Beispiel aussehen. Dieser Code sucht nach Produktinformationen zuerst in einem lokalen Cache, dann in einem Remote-Cache und danach in einer Datenbank:

Wenn ich diesen Service betreiben würde, bräuchte ich eine Menge an Instrumentierung in diesem Code, um sein Verhalten in der Produktion nachvollziehen zu können. Ich müsste Probleme im Zusammenhang mit fehlgeschlagenen oder langsamen Anfragen beheben sowie Trends und Anzeichen dafür erkennen können, dass verschiedene Abhängigkeiten unterdimensioniert sind oder sich falsch verhalten. Nachfolgend ist derselbe Code aufgeführt, kommentiert mit einigen der Fragen, die ich über das Produktionssystem insgesamt oder für eine bestimmte Anfrage beantworten können müsste:

Der Code zur Beantwortung all dieser Fragen (und weiterer) ist um einiges länger als die eigentliche Geschäftslogik. Einige Bibliotheken können zwar helfen, die Menge an Instrumentierungscode zu verringern, dennoch muss sich der Entwickler Fragen nach der Transparenz stellen, die die Bibliotheken benötigen. Anschließend muss er die Instrumentierung bewusst einbauen.

Wenn man ein Problem im Zusammenhang mit einer Anfrage behebt, die ein verteiltes System durchläuft, kann das Geschehen mitunter schwer nachvollziehbar sein, wenn man diese Anfrage nur auf der Grundlage einer einzigen Interaktion betrachtet. Um das Puzzle zusammenzusetzen, ist es unserer Ansicht nach hilfreich, alle Messungen über all diese Systeme an einer Stelle zusammenzuführen. Dazu muss vorher jeder Service so instrumentiert werden, dass eine Trace-ID für jede Aufgabe aufgezeichnet und an alle anderen Services weitergegeben wird, die an der betreffenden Aufgabe mitwirken. Die systemübergreifende Zusammenstellung der Instrumentierung für eine bestimmte Trace-ID kann je nach Bedarf im Anschluss oder mit einem Service wie AWS X-Ray nahezu in Echtzeit erfolgen.

Die Instrumentierung ermöglicht die Fehlerbehebung auf mehreren Ebenen, vom kurzen Blick auf Metriken, um festzustellen, ob es Anomalien gibt, die zu geringfügig sind, um Alarme auszulösen, bis hin zur Durchführung einer Untersuchung, um die Ursache dieser Anomalien herauszufinden.

Auf der höchsten Ebene wird die Instrumentierung zu Metriken zusammengefasst, die Alarme auslösen und in Dashboards angezeigt werden können. Mithilfe dieser aggregierten Metriken können Bediener die Gesamtanfragerate, die Latenz der Serviceaufrufe und die Fehlerraten überwachen. Diese Alarme und Metriken machen uns auf Anomalien oder Veränderungen aufmerksam, die untersucht werden müssen.

Nachdem wir eine Anomalie festgestellt haben, müssen wir den Grund für ihr Auftreten herausfinden. Zur Beantwortung dieser Frage nutzen wir Metriken, die durch noch mehr Instrumentierung ermöglicht werden. Durch Instrumentierung der Zeit, die zur Verarbeitung verschiedener Teile einer Anfrage benötigt wird, können wir feststellen, welcher Teil der Verarbeitung langsamer als normal läuft oder häufiger Fehler auslöst.

Zwar können aggregierte Timer und Metriken uns helfen, Ursachen auszuschließen oder einen bestimmten Untersuchungsbereich hervorzuheben, doch liefern sie nicht immer eine vollständige Erklärung. So können wir beispielsweise anhand von Metriken erkennen, dass Fehler auf einen bestimmten API-Vorgang zurückzuführen sind, doch unter Umständen zeigen die Metriken nicht genügend Details zum Fehlergrund. An dieser Stelle sehen wir uns die rohen, detaillierten Protokolldaten an, die der Service für das betreffende Zeitfenster ausgibt. Die rohen Protokolle lassen dann die Ursache des Problems erkennen – entweder den jeweiligen Fehler oder bestimmte Aspekte der Anfrage, die einen Edge-Fall auslösen.

Zur Instrumentierung muss Code erstellt werden. Das bedeutet, dass wir uns bei der Implementierung neuer Funktionen die Zeit nehmen müssen, um zusätzlichen Code hinzuzufügen, der angibt, was geschehen ist, ob es erfolgreich war oder nicht, und wie lange es gedauert hat. Da die Instrumentierung solch eine gängige Codierungsaufgabe ist, sind bei Amazon im Laufe der Jahre Verfahren zur Bewältigung gängiger Muster entwickelt worden: Standardisierung für gängige Instrumentierungsbibliotheken und Standardisierung für strukturiertes protokollbasiertes Metrik-Reporting.

Die Standardisierung der Metrik-Instrumentierungsbibliotheken hilft Autoren von Bibliotheken, den Nutzern ihrer Bibliotheken Einblicke in die Betriebsweise der Bibliothek zu geben. Häufig verwendete HTTP-Clients sind zum Beispiel in diese gängigen Bibliotheken integriert. Daher erhält ein Serviceteam, wenn es Remote-Aufrufe an einen anderen Service implementiert, automatisch eine Instrumentierung über diese Aufrufe.

Wenn eine instrumentierte Anwendung ausgeführt wird und arbeitet, werden die resultierenden Telemetriedaten in eine strukturierte Protokolldatei geschrieben. Im Allgemeinen werden sie als ein Protokolleintrag pro "Arbeitseinheit" ausgegeben, unabhängig davon, ob es sich um eine Anfrage an einen HTTP-Service oder eine Nachricht aus einer Warteschlange handelt.

Bei Amazon werden Messungen in der Anwendung nicht aggregiert und gelegentlich in ein Metrik-Aggregationssystem übertragen. Alle Timer und Zähler für jede Arbeitseinheit werden in eine Protokolldatei geschrieben. Anschließend werden die Protokolle verarbeitet und aggregierte Metriken von einem anderen System nachträglich berechnet. Auf diese Weise erhalten wir alles Benötigte, von übergeordneten aggregierten Betriebsmetriken bis hin zu detaillierten Fehlerbehebungsdaten auf Anfrageebene – alles mit einem einzigen Ansatz für die Instrumentierung von Code. Bei Amazon protokollieren wir zuerst und generieren später aggregierte Metriken.

Meistens instrumentieren wir unsere Services so, dass zwei Arten von Protokolldaten ausgegeben werden: Anfragedaten und Debugging-Daten. Anfrageprotokolldaten werden in der Regel als ein einzelner strukturierter Protokolleintrag für jede Arbeitseinheit dargestellt. Diese Daten enthalten Eigenschaften der Anfrage und geben Auskunft darüber, wer die Anfrage gestellt hat und wofür sie war. Außerdem enthalten sie Zähler dafür, wie oft die Dinge passiert sind, und Timer dafür, wie lange sie gedauert haben. Das Anfrageprotokoll dient als Prüfprotokoll und Beleg für alles, was im Service geschehen ist. Debugging-Daten umfassen unstrukturierte oder lose strukturierte Daten von allen Debugging-Zeilen, die Anwendungen ausgeben. Typischerweise handelt es sich hierbei um unstrukturierte Protokolleinträge wie Log4j-Fehler- oder Warnprotokollzeilen. Bei Amazon werden diese beiden Arten von Daten in der Regel in separaten Protokolldateien ausgegeben, teilweise aus historischen Gründen, aber auch, weil es praktisch sein kann, die Protokollanalyse in einem homogenen Format von Protokolleinträgen durchzuführen.

Agents wie der CloudWatch Logs-Agent verarbeiten beide Arten von Protokolldaten in Echtzeit und senden die Daten an CloudWatch Logs. CloudWatch Logs wiederum generiert aggregierte Metriken über den Service nahezu in Echtzeit. Amazon CloudWatch Alarms liest diese aggregierten Metriken und löst Alarme aus.

Obwohl es kostspielig sein kann, so viele Details zu jeder Anfrage zu protokollieren, halten wir das bei Amazon für sehr wichtig. Denn schließlich müssen wir kurzzeitige Veränderungen bei der Verfügbarkeit, Latenzspitzen und vom Kunden gemeldete Probleme untersuchen. Ohne detaillierte Protokolle können wir unseren Kunden keine Antworten geben und den Service für sie nicht verbessern.  

Das Thema Überwachung und Alarme ist äußerst umfangreich. In diesem Artikel gehen wir auf Themen wie das Festlegen und Optimieren von Alarmschwellen, das Organisieren von Betriebs-Dashboards, das Messen der Leistung auf Server- und Clientseite, kontinuierlich laufende "Frühwarn"-Anwendungen und die Wahl des richtigen Systems zur Aggregation von Metriken und zur Analyse von Protokollen nicht ein.

Vielmehr geht es in diesem Artikel vor allem um die Notwendigkeit, unsere Anwendungen so zu instrumentieren, dass die richtigen rohen Messdaten generiert werden. Wir beschreiben die Dinge, auf die Teams bei Amazon bei der Instrumentierung ihrer Anwendungen besonderen Wert legen (bzw. vermeiden).

In diesem Abschnitt beschreibe ich gute Gewohnheiten, die wir bei Amazon im Laufe der Zeit zur Protokollierung unserer strukturierten Daten "pro Arbeitseinheit" entwickelt haben. Ein Protokoll, das die entsprechenden Kriterien erfüllt, enthält Zähler, die angeben, wie oft Dinge passieren, Timer, die anzeigen, wie lange sie gedauert haben, und Eigenschaften, die Metadaten über jede Arbeitseinheit umfassen.

• Einen Anfrageprotokolleintrag für jede Arbeitseinheit ausgeben. Eine Arbeitseinheit ist üblicherweise eine Anfrage, die unser Service erhalten hat, oder eine Nachricht, die er aus einer Warteschlange abruft. Wir schreiben einen Serviceprotokolleintrag für jede Anfrage, die unser Service erhält. Wir fassen nicht mehrere Arbeitseinheiten zusammen. So können wir uns bei der Fehlerbehebung für eine fehlgeschlagene Anfrage einen einzelnen Protokolleintrag ansehen. Dieser Eintrag enthält die relevanten Eingabeparameter zur Anfrage, die erkennen lassen, was versucht wurde, Informationen über den Aufrufer sowie alle Zeit- und Zählerinformationen an einer Stelle.
• Höchstens einen Protokolleintrag für eine bestimmte Anfrage ausgeben. Bei Implementierung eines blockierungsfreien Service mag es sinnvoll erscheinen, für jede Stufe einer Verarbeitungs-Pipeline einen separaten Protokolleintrag auszugeben. Wir dagegen haben bei der Fehlerbehebung dieser Systeme mehr Erfolg damit, wenn wir ein Handle für ein einzelnes "Metrikobjekt" rund um die Zwischenstufen in der Pipeline erstellen und dann die Metriken nach Abschluss aller Stufen als Einheit serialisiert ausgeben. Wenn mehrere Protokolleinträge pro Arbeitseinheit vorliegen, erschwert das die Protokollanalyse und erhöht den ohnehin schon kostspieligen Protokoll-Overhead um ein Vielfaches. Bei der Erstellung eines neuen blockierungsfreien Service versuchen wir, den Lebenszyklus der Metrikprotokollierung im Voraus zu planen, da eine spätere Überarbeitung und Korrektur sehr schwierig ist.
• Lang laufende Aufgaben in mehrere Protokolleinträge aufteilen. Im Gegensatz zur vorherigen Empfehlung entschließen wir uns bei lang laufenden, mehrminütigen oder mehrstündigen workflow-ähnlichen Aufgaben unter Umständen dazu, regelmäßig einen separaten Protokolleintrag auszugeben. So können wir feststellen, ob Fortschritte erzielt werden oder wo sich die Aufgabe verzögert.
• Details zur Anfrage aufzeichnen, bevor Aufgaben wie eine Validierung durchgeführt werden. Unserer Ansicht nach ist es wichtig, dass bei der Fehlerbehebung und der Prüfprotokollierung genügend Informationen zur jeweiligen Anfrage protokolliert werden, damit wir wissen, was damit erreicht werden sollte. Zudem halten wir es für wichtig, diese Informationen so früh wie möglich zu protokollieren, bevor die Anfrage durch Validierungs-, Authentifizierungs- oder Drosselungslogik abgelehnt werden kann. Wenn wir Informationen aus einer eingehenden Anfrage protokollieren, säubern wir die eingehenden Daten (d. h., wir codieren sie, versehen sie mit Escape-Zeichen und kürzen sie), bevor wir sie protokollieren. Beispielsweise wollen wir keine 1 MB langen Zeichenfolgen in unseren Serviceprotokolleintrag aufnehmen, wenn der Aufrufer einen übergeben hat. Das würde die Gefahr voll belegter Festplatten und unerwartet hoher Kosten für Protokollspeicher mit sich bringen. Ein weiteres Beispiel für die Säuberung ist das Herausfiltern von ASCII-Steuerzeichen oder Escape-Sequenzen, die für das Protokollformat relevant sind. Es könnte verwirrend sein, wenn der Aufrufer einen eigenen Serviceprotokolleintrag übergäbe und ihn in unsere Protokolle einfügen könnte! Siehe auch: https://xkcd.com/327/
• Möglichkeit zur Protokollierung mit erhöhter Ausführlichkeit einplanen. Zur Behebung einiger Arten von Problemen enthält das Protokoll nicht genügend Details zu den problematischen Anfragen, um herausfinden zu können, warum sie fehlgeschlagen sind. Die betreffenden Informationen können im Service verfügbar sein, doch die Informationsmenge könnte zu groß sein, um eine ständige Protokollierung zu rechtfertigen. Es kann hilfreich sein, über eine Konfigurationseinstellung zu verfügen, die sich verändern lässt, um die Ausführlichkeit des Protokolls während der Untersuchung eines Problems vorübergehend zu erhöhen. Diese Einstellung können Sie für einzelne Hosts, für einzelne Clients oder für eine flottenübergreifende Stichprobenrate hochsetzen. Denken Sie aber unbedingt daran, die Einstellung danach wieder zurückzusetzen.
• Metriknamen kurz (aber nicht zu kurz) halten. Amazon benutzt seit über 15 Jahren die gleiche Serialisierung von Serviceprotokollen. Bei dieser Serialisierung wird jeder Zähler- und Timername in jedem Serviceprotokolleintrag in Klartext wiederholt. Um den Protokollierungs-Overhead zu minimieren, verwenden wir kurze, aber aussagekräftige Timernamen. Amazon beginnt mit der Einführung neuer Serialisierungsformate, die auf einem binären Serialisierungsprotokoll basieren, das als Amazon Ion bezeichnet wird. Letztendlich muss ein Format gewählt werden, das die Tools zur Protokollanalyse verstehen können und das sich zudem möglichst effizient serialisieren, deserialisieren und speichern lässt.
• Sicherstellen, dass die Protokollvolumen groß genug sind, um die Protokollierung bei maximalem Durchsatz zu bewältigen. Wir testen unsere Services stundenlang bei maximaler Dauerlast (oder sogar Überlastung). Wir müssen sicherstellen, dass unser Service bei der Verarbeitung von übermäßigem Datenverkehr noch über die Ressourcen verfügt, um Protokolle mit der Rate zu versenden, mit der neue Protokolleinträge generiert werden. Andernfalls sind die Festplatten irgendwann voll. Die Protokollierung lässt sich auch so konfigurieren, dass sie in einer anderen Dateisystempartition als der Root-Partition erfolgt, sodass das System bei übermäßiger Protokollierung nicht ausfällt. Später erörtern wir andere Abhilfen hierfür, wie etwa die Verwendung dynamischer Stichproben proportional zum Durchsatz. Doch unabhängig von der Strategie ist es wichtig, Tests durchzuführen.
• Verhalten des Systems berücksichtigen, wenn Festplatten voll sind. Wenn die Festplatte eines Servers voll ist, kann er keine Protokolle auf der Festplatte speichern. Sollte ein Service in diesem Fall keine Anfragen mehr annehmen oder Protokolle löschen und ohne Überwachung weiterarbeiten? Der Betrieb ohne Protokollierung ist riskant, daher stellen wir anhand von Systemtests sicher, dass Server mit fast vollen Festplatten erkannt werden.
• Uhren synchronisieren. Der Begriff "Zeit" in verteilten Systemen ist bekanntermaßen kompliziert. In verteilten Algorithmen nutzen wir keine Uhrensynchronisierung, sie ist aber notwendig, um die Protokolle zu verstehen. Wir führen Daemons wie Chrony oder ntpd für die Uhrensynchronisierung aus und überwachen Server auf Uhrzeitabweichungen. Informationen dazu, wie sich dies vereinfachen lässt, finden Sie unter Amazon Time Sync Service.
• Nullzahlen für Verfügbarkeitsmetriken ausgeben. Fehlerzahlen sind nützlich, doch Fehlerprozentsätze können ebenfalls hilfreich sein. Eine Strategie zur Instrumentierung für eine "Verfügbarkeitsprozentsatz"-Metrik, die sich für uns als nützlich erwiesen hat, besteht darin, eine 1 auszugeben, wenn eine Anfrage erfolgreich ist, und eine 0, wenn sie fehlschlägt. Die "durchschnittliche" Statistik der resultierenden Metrik ergibt dann die Verfügbarkeitsrate. Das absichtliche Ausgeben eines 0-Datenpunktes kann auch in anderen Situationen hilfreich sein. Wenn eine Anwendung beispielsweise eine Leader-Auswahl durchführt, kann die regelmäßige Ausgabe einer 1 für den Fall, dass ein Prozess der Leader ist, und einer 0 für den Fall, dass der Prozess nicht der Leader ist, nützlich sein, um den Zustand der nachfolgenden Prozesse zu überwachen. Wenn ein Prozess keine 0 mehr ausgibt, ist es so leichter zu erkennen, dass darin ein Fehler vorliegt und der Prozess nicht übernehmen kann, wenn etwas mit dem Leader passiert.

• Verfügbarkeit und Latenz aller Abhängigkeiten protokollieren. Dieses Protokoll ist nach unseren Erfahrungen besonders hilfreich zur Beantwortung von Fragen danach, warum eine Anfrage langsam verarbeitet wurde oder fehlgeschlagen ist. Ohne dieses Protokoll können wir nur Diagramme von Abhängigkeiten mit Diagrammen eines Service vergleichen und raten, ob eine Spitze in der Latenz eines abhängigen Service zum Fehlschlagen einer untersuchten Anfrage geführt hat. Viele Service- und Client-Frameworks untersuchen Metriken automatisch, aber andere Frameworks (wie zum Beispiel das AWS SDK) erfordern eine manuelle Instrumentierung.
• Abhängigkeitsmetriken pro Aufruf, pro Ressource, pro Statuscode usw. aufgliedern. Wenn wir in derselben Arbeitseinheit mehrmals mit derselben Abhängigkeit interagieren, beziehen wir Metriken zu jedem Aufruf separat ein und machen deutlich, mit welcher Ressource jede Anfrage interagierte. Beim Aufruf von Amazon DynamoDB beispielsweise ist es nach den Erfahrungen einiger Teams hilfreich, Zeit- und Latenzmetriken pro Tabelle, pro Fehlercode und sogar pro Anzahl der Wiederholungsversuche einzubeziehen. Dies erleichtert die Fehlerbehebung in Fällen, in denen der Service durch wiederholte Versuche aufgrund von fehlgeschlagenen bedingten Prüfungen verlangsamt wurde. Diese Metriken ließen auch Fälle erkennen, in denen die vom Client wahrgenommene Zunahme der Latenz tatsächlich auf verlangsamende Wiederholungsversuche oder auf das Durchlaufen eines Ergebnissatzes zurückzuführen war und nicht auf Paketverluste oder Netzwerklatenz.
• Tiefe von Speicherwarteschlangen aufzeichnen, wenn darauf zugegriffen wird. Wenn eine Anfrage mit einer Warteschlange interagiert und wir ein Objekt daraus entnehmen oder etwas darin einfügen, halten wir dabei die aktuelle Warteschlangentiefe im Metrikobjekt fest. Für In-Memory-Warteschlangen sind diese Informationen sehr günstig abzurufen. Für verteilte Warteschlangen sind diese Metadaten bei Antworten auf API-Aufrufe unter Umständen kostenlos verfügbar. Diese Protokollierung hilft, in Zukunft Rückstände und Latenzursachen aufzuspüren. Wenn wir Objekte einer Warteschlange entnehmen, messen wir darüber hinaus, wie lange sie in der Warteschlange waren. Das bedeutet, dass wir der Nachricht unsere eigene Metrik "Zeitpunkt der Einreihung in Warteschlange" hinzufügen müssen, bevor wir sie dort überhaupt ablegen.
• Zusätzlichen Zähler für jeden Fehlergrund hinzufügen. Erwägen Sie das Hinzufügen von Code, der den spezifischen Fehlergrund für jede fehlgeschlagene Anfrage zählt. Das Anwendungsprotokoll enthält Informationen dazu, was zum Fehler geführt hat, sowie eine detaillierte Ausnahmenachricht. Nach unseren Erfahrungen ist es jedoch auch hilfreich, längerfristige Trends bei den Fehlerursachen in den Metriken erkennen zu können, ohne im Anwendungsprotokoll nach diesen Informationen suchen zu müssen. Es ist ganz praktisch, mit einer separaten Metrik für jede Fehlerklasse zu beginnen.
• Fehler nach Ursachenkategorie organisieren. Werden alle Fehler in derselben Metrik zusammengefasst, wird die Metrik unübersichtlich und ist wenig hilfreich. Nach unseren Erfahrungen sollten zumindest die Fehler, die auf den Client zurückzuführen sind, von Fehlern getrennt werden, die auf den Server zurückführen sind. Eine weitergehende Aufschlüsselung kann hilfreich sein. In DynamoDB beispielsweise können Clients bedingte Schreibanfragen stellen, die einen Fehler zurückgeben, wenn das zu ändernde Element nicht den Vorbedingungen in der Anfrage entspricht. Diese Fehler sind absichtlich und wir gehen davon aus, dass sie gelegentlich auftreten. Hingegen sind Fehler vom Typ "Ungültige Anfrage" von Clients höchstwahrscheinlich Bugs, die wir beheben müssen.
• Wichtige Metadaten über die Arbeitseinheit protokollieren. In einem strukturierten Metrikprotokoll fügen wir auch genügend Metadaten über eine Anfrage hinzu, damit wir später feststellen können, von wem die Anfrage stammte und was damit durchgeführt werden sollte. Dazu gehören Metadaten, deren Vorliegen in unserem Protokoll ein Kunde erwarten würde, wenn er sich mit Problemen an uns wendet. DynamoDB protokolliert beispielsweise den Namen der Tabelle, mit der eine Anfrage interagiert, und Metadaten wie etwa dazu, ob der Lesevorgang ein konsistenter Lesevorgang war oder nicht. Die Anwendung protokolliert jedoch nicht die Daten, die in der Datenbank gespeichert oder daraus abgerufen werden.
• Protokolle mit Zugriffskontrolle und Verschlüsselung schützen. Da Protokolle ein gewisses Maß an sensiblen Informationen enthalten, ergreifen wir Maßnahmen zum Schutz und zur Sicherung dieser Daten. Dazu gehören die Verschlüsselung von Protokollen, die Beschränkung des Zugriffs auf Bediener, die Probleme beheben, und das regelmäßige Baselining des Zugriffs.
• Keine sensiblen Informationen in Protokolle aufnehmen. Protokolle müssen einige sensible Informationen enthalten, damit sie nützlich sind. Bei Amazon halten wir es für wichtig, dass Protokolle genügend Informationen enthalten, damit erkennbar ist, von wem eine bestimmte Anfrage stammt. Besonders sensible Informationen hingegen lassen wir weg, wie zum Beispiel Anfrageparameter, die das Routing oder das Verhalten bei der Verarbeitung der Anfrage nicht beeinflussen. Wenn der Code beispielsweise eine Kundennachricht analysiert und diese Analyse fehlschlägt, darf die Nutzlast zum Schutz der Privatsphäre des Kunden nicht protokolliert werden, so schwierig sich die spätere Fehlerbehebung dadurch auch gestalten mag. Mithilfe von Tools treffen wir Entscheidungen darüber, was mit einer Opt-in- statt mit einer Opt-out-Methode protokolliert werden kann, um so die Protokollierung eines neuen, später hinzugefügten sensiblen Parameters zu verhindern. Services wie Amazon API Gateway ermöglichen die Festlegung, welche Daten in das Zugriffsprotokoll aufgenommen werden sollen, was als guter Opt-in-Mechanismus dient.
• Trace-ID protokollieren und in Backend-Aufrufen propagieren. An der Verarbeitung einer Kundenanfrage sind im Normalfall viele Services beteiligt. Bei vielen AWS-Anfragen können das bloß zwei oder drei Services sein, während bei Anfragen auf amazon.com wesentlich mehr Services beteiligt sein können. Um bei der Fehlerbehebung in einem verteilten System das Geschehen nachzuvollziehen, propagieren wir ein und dieselbe Trace-ID in den Systemen, sodass wir Protokolle aus verschiedenen Systemen zusammenstellen können, um festzustellen, wo Fehler passiert sind. Bei einer Trace-ID handelt es sich um eine Art Meta-Anfrage-ID, die einer verteilten Arbeitseinheit vom "Eingangs"-Service, der Ausgangspunkt für die Arbeitseinheit war, zugewiesen wird. AWS X-Ray ist ein Service, der durch die Bereitstellung eines Teils dieser Propagierung weiterhilft. Unserer Meinung nach ist es wichtig, den Trace an unsere Abhängigkeiten zu übergeben. In einer Umgebung mit mehreren Threads ist es sehr schwierig und fehleranfällig, wenn das Framework diese Propagierung in unserem Auftrag durchführt. Deshalb haben wir es uns zur Gewohnheit gemacht, Trace-IDs und andere Anfrageinhalte (wie ein Metrikobjekt!) in unseren Methodensignaturen zu übergeben. Zudem ist es unseren Erfahrungen nach praktisch, ein Kontextobjekt in unseren Methodensignaturen zu übergeben. So müssen wir keine Überarbeitung vornehmen, wenn wir in Zukunft ein ähnliches zu übergebendes Muster finden. Für AWS-Teams geht es nicht nur um die Fehlerbehebung in unseren Systemen, sondern auch darum, dass Kunden die Fehler in ihren Systemen beheben. Kunden verlassen sich darauf, dass AWS X-Ray-Traces zwischen den AWS-Services übergeben werden, wenn diese im Auftrag des Kunden miteinander interagieren. Daher müssen wir die AWS X-Ray-Trace-IDs der Kunden in den Services propagieren, damit sie vollständige Trace-Daten erhalten.
• Je nach Statuscode und Größe verschiedene Latenzmetriken protokollieren. Fehler erfolgen oft schnell – etwa bei Verweigerung des Zugriffs, bei der Drosselung und bei Validierungsfehlern. Wenn Clients in einer hohen Rate gedrosselt werden, kann die Latenz trügerisch gut erscheinen. Zur Vermeidung dieser Verfälschung der Metriken protokollieren wir einen separaten Timer für erfolgreiche Antworten und konzentrieren uns in unseren Dashboards und Alarmen auf diese Metrik, anstatt eine generische Zeitmetrik zu verwenden. Wenn es einen Vorgang gibt, der je nach Eingabe- oder Antwortgröße langsamer sein kann, erwägen wir zudem die Ausgabe einer kategorisierten Latenzmetrik, wie zum Beispiel SmallRequestLatency und LargeRequestLatency. Darüber hinaus stellen wir sicher, dass unsere Anfragen und Antworten angemessen begrenzt sind, um komplexe Ausfall- und Fehlermodi zu vermeiden. Doch selbst in einem sorgfältig konzipierten Service kann dieses Verfahren zum Bucketing von Metriken das Kundenverhalten isolieren und ablenkende Störungen aus Dashboards heraushalten.

In diesem Abschnitt werden gute Gewohnheiten beschrieben, die wir bei Amazon zur Protokollierung unstrukturierter Debug-Protokolldaten entwickelt haben.

• Anwendungsprotokoll frei von Spam halten. Obwohl wir unter Umständen über Protokollanweisungen auf INFO- und DEBUG-Ebene im Anfragepfad verfügen, die bei der Entwicklung und beim Debugging in Testumgebungen helfen sollen, ziehen wir die Deaktivierung diese Protokollebenen in der Produktion in Erwägung. Anstatt uns für Informationen zur Verfolgung von Anfragen auf das Anwendungsprotokoll zu verlassen, betrachten wir das Serviceprotokoll als einen Ort für die Trace-Informationen, mit deren Hilfe wir leicht Metriken erstellen und längerfristige aggregierte Trends erkennen können. Allerdings gibt es in diesem Zusammenhang keine eindeutige Regel. Wir überprüfen unsere Protokolle kontinuierlich, um festzustellen, ob sie zu ungenau (oder nicht umfangreich genug) sind, und die Protokollebenen im Laufe der Zeit anzupassen. Beim Eintauchen in die Protokolle finden wir beispielsweise oft Protokollanweisungen, die zu ungenau sind, oder Metriken, die wir gerne hätten. Zum Glück sind diese Verbesserungen oft einfach umzusetzen. Daher haben wir es uns zur Gewohnheit gemacht, schnelle nachfolgende Backlog-Elemente zu archivieren, um unsere Protokolle sauber zu halten.
• Entsprechende Anfrage-ID einbeziehen. Bei der Behebung eines Fehlers im Anwendungsprotokoll möchten wir oft Details über die Anfrage oder den Aufrufer sehen, der den Fehler ausgelöst hat. Wenn beide Protokolle die gleiche Anfrage-ID enthalten, können wir mühelos zwischen den Protokollen hin und her springen. Bei richtiger Konfiguration geben Bibliotheken zur Anwendungsprotokollierung die entsprechende Anfrage-ID aus und die Anfrage-ID wird als ThreadLocal festgelegt. Wenn eine Anwendung aus mehreren Threads besteht, sollten Sie besonders darauf achten, die richtige Anfrage-ID festzulegen, wenn ein Thread mit der Verarbeitung einer neuen Anfrage beginnt.
• Rate des Fehler-Spams eines Anwendungsprotokolls begrenzen. Normalerweise gibt ein Service nicht viel an das Anwendungsprotokoll aus. Wenn er jedoch plötzlich anfängt, eine große Menge an Fehlern anzuzeigen, beginnt er unter Umständen plötzlich, in einer hohen Rate sehr große Protokolleinträge mit Stack-Traces auszugeben. Eine Möglichkeit, die wir zum Schutz davor gefunden haben, ist die Begrenzung der Rate, wie oft ein bestimmter Logger protokolliert.
• Formatzeichenfolgen gegenüber String#format oder der Verkettung von Zeichenfolgen den Vorzug geben. Ältere API-Vorgänge für Anwendungsprotokolle akzeptieren eine Nachricht mit einer einzelnen Zeichenfolge anstelle der log4j2-API mit Zeichenfolgen im varargs-Format. Wenn Code mit DEBUG-Anweisungen instrumentiert wird, die Produktion aber auf ERROR-Ebene konfiguriert ist, kann unter Umständen Arbeit nutzlos für die Formatierung von DEBUG-Nachrichtenzeichenfolgen aufgewendet werden, die ignoriert werden. Einige API-Protokollierungsvorgänge unterstützen die Übergabe von beliebigen Objekten, deren toString()-Methoden nur aufgerufen werden, wenn der Protokolleintrag ausgegeben wird.
• Anfrage-IDs aus fehlgeschlagenen Serviceaufrufen protokollieren. Wenn ein Service aufgerufen wird und einen Fehler zurückgibt, gibt er wahrscheinlich auch eine Anfrage-ID zurück. Für uns hat es sich als nützlich erwiesen, die Anfrage-ID in unser Protokoll aufzunehmen. So gibt es, wenn wir beim Servicezuständigen nachhaken müssen, eine Möglichkeit, wie er die eigenen entsprechenden Serviceprotokolleinträge mühelos aufspüren kann. Timeout-Fehler machen dies schwierig, denn der Service hat möglicherweise noch keine Anfrage-ID zurückgegeben oder eine Client-Bibliothek hat sie unter Umständen nicht analysiert. Trotzdem werden Anfrage-IDs, die wir vom Service zurückbekommen, von uns protokolliert.

Für die überwiegende Mehrheit der Services bei Amazon bedeutet die Protokollierung jeder Anfrage keinen unangemessenen Kostenaufwand. Bei Services mit höherem Durchsatz gelangt man in einen Graubereich, aber auch hier protokollieren wir oft dennoch jede Anfrage. Zum Beispiel würde man sicher davon ausgehen, dass DynamoDB, das allein pro Sekunde über 20 Millionen Anfragen im Zusammenhang mit internem Amazon-Datenverkehr verarbeitet, nicht sehr viel protokolliert. Doch tatsächlich protokolliert die Anwendung jede Anfrage zum Zwecke der Fehlerbehebung sowie aus Prüf- und Compliance-Gründen. Nachfolgend sind einige allgemeine Tipps aufgeführt, mit deren Hilfe wir bei Amazon die Protokollierung bei höherem Durchsatz pro Host effizienter gestalten:

• Stichprobenartige Protokollierung. Anstatt jeden Eintrag zu schreiben, sollten Sie in Erwägung ziehen, nur jeden N-ten Eintrag auszugeben. Bei jedem Eintrag wird auch angegeben, wie viele Einträge übersprungen wurden, sodass Systeme zur Metrikaggregation das tatsächliche Protokollvolumen in den berechneten Metriken abschätzen können. Andere Stichprobenalgorithmen wie Reservoir Sampling bieten repräsentativere Stichproben. Bei anderen Algorithmen wird der Protokollierung von Fehlern oder langsame Anfragen gegenüber der Protokollierung von erfolgreichen, schnellen Anfragen Vorrang eingeräumt. Bei der stichprobenartigen Protokollierung besteht jedoch keine Möglichkeit, Kunden zu helfen und spezifische Fehler zu beheben. Durch einige Compliance-Bestimmungen ist diese Form der Protokollierung von vornherein ausgeschlossen.
• Serialisierung und Wegschreiben der Protokolle in einen separaten Thread auslagern. Hierbei handelt es sich um eine einfache Änderung, auf die häufig zurückgegriffen wird.
• Häufiger Protokollwechsel. Das stündliche Wechseln von Protokolldateien mag praktisch erscheinen, da Sie weniger Dateien handhaben müssen, doch durch das Wechseln jede Minute ergeben sich mehrere Verbesserungen. Der Agent beispielsweise, der die Protokolldatei liest und komprimiert, liest die Datei aus dem Seiten-Cache anstatt von der Festplatte. Und die CPU-Nutzung und die E/A für die Komprimierung und den Versand der Protokolle werden über die Stunde verteilt, anstatt dass sie immer am Ende der Stunde ausgelöst werden.
• Protokolle vorkomprimiert schreiben. Wenn ein Protokolle versendender Agent Protokolle komprimiert, bevor er sie an einen Archivierungsservice sendet, verzeichnen die System-CPU und die Festplatte regelmäßig Spitzen. Es ist möglich, diese Kosten zu amortisieren und die Festplatten-E/A um die Hälfte zu reduzieren, indem komprimierte Protokolle an die Festplatte übertragen werden. Das ist jedoch mit einigen Risiken verbunden. Für uns hat es sich als nützlich erwiesen, einen Komprimierungsalgorithmus zu verwenden, der im Falle eines Anwendungsabsturzes verkürzte Dateien verarbeiten kann.
• In RAM-Disk/tmpfs (temporary file system) schreiben. Es kann für einen Service einfacher sein, Protokolle bis zum Versand vom Server in den Arbeitsspeicher zu schreiben, anstatt sie auf die Festplatte zu schreiben. Nach unserer Erfahrung funktioniert dies beim Protokollwechsel jede Minute besser als beim Protokollwechsel jede Stunde.
• Speicherinterne Aggregate. Wenn Hunderttausende von Transaktionen pro Sekunde auf einem einzigen Rechner verarbeitet werden müssen, ist es möglicherweise zu kostspielig, einen Protokolleintrag pro Anfrage zu schreiben. Allerdings verliert man durch das Überspringen dieses Schritts viel an Transparenz. Daher ist es unserer Ansicht nach hilfreich, nicht vorzeitig zu optimieren.
• Ressourcennutzung überwachen. Wir achten darauf, wie nah wir einem Skalierungslimit sind. Wir messen unsere E/A und CPU-Nutzung pro Server und wie viel von diesen Ressourcen von den protokollierenden Agents genutzt werden. Belastungstests führen wir sie so lange durch, dass wir nachweisen können, dass unsere Protokolle versendende Agents mit unserem Durchsatz Schritt halten können.

Bei Amazon kümmern wir uns auch um den Betrieb der von uns geschriebenen Services, sodass wir alle Experten für deren Fehlerbehebung werden müssen. Dazu gehört auch die Fähigkeit, Protokolle mühelos zu analysieren. Es stehen uns viele Tools zur Verfügung, von der lokalen Protokollanalyse zur Betrachtung einer relativ kleinen Zahl von Protokollen bis hin zur verteilten Protokollanalyse für das Durchsuchen und Aggregieren von Ergebnissen aus einer riesigen Menge an Protokollen.

Nach unseren Erfahrungen ist es wichtig, in die Tools und Runbooks zur Protokollanalyse der Teams zu investieren. Wenn die Protokolle zum aktuellen Zeitpunkt klein sind, aber ein Service im Laufe der Zeit voraussichtlich wachsen wird, achten wir darauf, wann unsere aktuellen Tools nicht mehr skalierbar sind, damit wir in eine Lösung zur verteilten Protokollanalyse investieren können.

Für die Protokollanalyse sind unter Umständen Erfahrungen mit verschiedenen Linux-Befehlszeilenprogrammen erforderlich. Ein gängiges Tool zum Aufspüren der IP-Adressen mit dem größten Kommunikationsumfang im Protokoll ist zum Beispiel:

Es gibt jedoch eine ganze Reihe anderer Tools, die zur Beantwortung komplexerer Fragen im Zusammenhang mit Protokollen nützlich sind, darunter:

• jq: https://stedolan.github.io/jq/
• RecordStream: https://github.com/benbernard/RecordStream

Verteilte Protokollanalysen können mit jedem Big Data-Analyseservice durchgeführt werden (zum Beispiel Amazon EMR, Amazon Athena, Amazon Aurora und Amazon Redshift). Einige Services sind allerdings mit Protokollierungssystemen ausgestattet, zum Beispiel Amazon CloudWatch Logs.

• CloudWatch Logs Insights
• AWS X-Ray: https://aws.amazon.com/xray/
• Amazon Athena: https://aws.amazon.com/athena/

Als Servicezuständiger und Softwareentwickler verbringe ich sehr viel Zeit damit, mir die Ergebnisse der Instrumentierung anzuschauen – Diagramme in Dashboards, einzelne Protokolldateien – und Tools zur verteilten Protokollanalyse wie CloudWatch Logs Insights zu verwenden. Das sind einige meiner Lieblingsbeschäftigungen. Wenn ich nach Erledigung einer schwierigen Aufgabe eine Pause brauche, lade ich meine Akkus wieder auf und belohne mich, indem ich in die Protokolle eintauche. Ich beginne mit Fragen wie: "Warum weist diese Metrik hier eine Spitze auf?" oder: "Könnte die Latenz dieses Vorgangs niedriger sein?". Wenn meine Fragen in eine Sackgasse führen, denke ich mir oft eine Messung aus, die im Code hilfreich wäre. Anschließend füge ich die Instrumentierung hinzu, teste sie und schicke den Code zur Überprüfung an meine Teamkollegen.

Obwohl die von uns eingesetzten Managed Services mit vielen Metriken ausgestattet sind, müssen wir uns viele Gedanken darüber machen, wie wir unsere eigenen Services so instrumentieren, damit wir die Einblicke erhalten, die wir für deren effektiven Betrieb benötigen. Bei betrieblichen Ereignisse müssen wir schnell feststellen, warum wir ein Problem haben und was wir unternehmen können, um Abhilfe zu schaffen. Die richtigen Metriken in unseren Dashboards sind entscheidend, damit wir die entsprechende Diagnose schnell durchführen können. Da wir darüber hinaus unsere Services ständig verändern, neue Funktionen hinzufügen und die Art und Weise ändern, wie sie mit ihren Abhängigkeiten interagieren, hört das Aktualisieren und Hinzufügen der richtigen Instrumentierung nie auf.

• "Look at your data" vom ehemaligen Amazonian John Rauser: https://www.youtube.com/watch?v=coNDCIMH8bk (einschließlich der Stelle nach 13:22, wo er Protokolle ausdruckt, um sie sich genauer anschauen zu können)
• "Investigating anomalies" vom ehemaligen Amazonian John Rauser: https://www.youtube.com/watch?v=-3dw09N5_Aw
• "How humans see data" vom ehemaligen Amazonian John Rauser: https://www.youtube.com/watch?v=fSgEeI2Xpdc
• https://www.akamai.com/uk/en/about/news/press/2017-press/akamai-releases-spring-2017-state-of-online-retail-performance-report.jsp