Diagnoseprotokollierung mit dem NGINX JavaScript-Modul

Fehlerbehebung in der Produktion ohne Feinabstimmung des Fehlerprotokolls

Herausgeber – Dieser Blog ist einer von mehreren, die sich mit der Protokollierung mit NGINX und NGINX Plus befassen. Bitte beachten Sie auch:

• Anwendungsverfolgung mit NGINX und NGINX Plus
• Sampling-Anfragen mit bedingter NGINX-Protokollierung

Es ist auch eines von vielen Blogs über Anwendungsfälle für das NGINX-JavaScript-Modul. Die vollständige Liste finden Sie unter Anwendungsfälle für das NGINX-JavaScript-Modul .

NGINX unterstützt Organisationen jeder Größe beim Betrieb ihrer unternehmenskritischen Websites, Anwendungen und APIs. Unabhängig von Ihrem Umfang und der Wahl der Bereitstellungsinfrastruktur ist der Betrieb in der Produktion nicht einfach. In diesem Artikel sprechen wir nur über einen der schwierigen Aspekte einer Produktionsbereitstellung – die Protokollierung. Genauer gesagt diskutieren wir den Balanceakt, die richtige Menge detaillierter Protokolle zur Fehlerbehebung zu sammeln, ohne mit unnötigen Daten überschwemmt zu werden.

Grundlagen der Protokollierung

NGINX bietet zwei verschiedene Protokollierungsmechanismen: Zugriffsprotokollierung für Clientanforderungen und Fehlerprotokollierung für den Fall, dass etwas schief geht. Diese Mechanismen sind sowohl im HTTP- als auch im Stream-Modul (TCP/UDP) verfügbar, hier konzentrieren wir uns jedoch auf den HTTP-Verkehr. (Es gibt auch einen dritten Protokollierungsmechanismus, der den Debug-Schweregrad verwendet, auf den wir hier jedoch nicht näher eingehen.)

Eine typische, standardmäßige NGINX-Protokollierungskonfiguration sieht folgendermaßen aus.

http { 
log_format main 
'$remote_addr - $remote_user [$time_local] "$request" '
'$status $body_bytes_sent "$http_referer" '
'"$http_user_agent" "$http_x_forwarded_for"';

access_log /var/log/nginx/access.log main; # Protokollieren im Format „main“
error_log /var/log/nginx/error.log warn; # Protokollieren bis zum Schweregrad „warn“
...
}

Die Direktive „log_format“ beschreibt den Inhalt und die Struktur der Protokolleinträge, die erstellt werden, wenn die Direktive „ access_log “ in die Konfiguration aufgenommen wird. Das obige Beispiel ist eine Erweiterung des Common Log Format (CLF), das von vielen Webservern verwendet wird. Mit der Direktive error_log geben Sie den Schweregrad der zu protokollierenden Meldungen an, nicht jedoch den Inhalt oder das Format der Einträge, da diese festgelegt sind. Mehr dazu im nächsten Abschnitt.

Weitere wichtige Aspekte der NGINX-Protokollierung sind:

• Protokollierungsanweisungen werden automatisch von Konfigurationskontexten auf niedrigerer Ebene übernommen. Beispielsweise wird eine access_log- Direktive im http -Kontext auf alle server{}- Blöcke angewendet.
• Eine Protokollierungsdirektive in einem untergeordneten Kontext überschreibt geerbte Direktiven.
• Im selben Kontext können mehrere Protokollierungsanweisungen vorhanden sein. Beispielsweise könnten zwei access_log- Direktiven verwendet werden, um sowohl eine Standard-CLF-Protokolldatei als auch ein zweites, detaillierteres Protokoll zu erstellen.

Die Realität der Protokollierung in der Produktion

Im Allgemeinen möchten wir das Zugriffsprotokoll zur Bereitstellung von Analyse- und Nutzungsstatistiken und das Fehlerprotokoll zur Fehlererkennung und Fehlerbehebung verwenden. Doch der Betrieb eines Produktionssystems ist selten so einfach. Hier sind einige häufige Herausforderungen:

• Zugriffsprotokolle enthalten nicht genügend Details zur Fehlerbehebung
• Fehlerprotokolle geben zwar viele Details zum Schweregrad der Informationen an, sind aber für den normalen Betrieb zu ausführlich.
• Das Fehlerprotokollformat ist festgelegt und kann daher nicht angepasst werden, um Variablen von besonderem Interesse einzuschließen.
• Einträge im Fehlerprotokoll enthalten nicht den Kontext der Anfrage und sind schwer dem entsprechenden Zugriffsprotokolleintrag zuzuordnen.

Darüber hinaus kann das Ändern der NGINX-Konfiguration zum Hinzufügen oder Entfernen von Protokollierungsdetails in einer Produktionsumgebung auch das Durchlaufen eines Änderungskontrollprozesses und die erneute Bereitstellung der Konfiguration erfordern. Völlig sicher, aber etwas umständlich bei der Behebung eines Live-Problems wie „Warum sehe ich einen Anstieg in 4xx / 5xx Fehler?“. Dies wird natürlich noch verstärkt, wenn mehrere NGINX-Instanzen denselben Datenverkehr in einem Cluster verarbeiten.

Verwenden eines zweiten Zugriffsprotokolls für Fehler

Das Anpassen des Formats des Zugriffsprotokolls zum Anreichern der für jede Anforderung erfassten Daten ist ein gängiger Ansatz für erweiterte Analysen, eignet sich jedoch nicht gut für die Diagnose oder Fehlerbehebung. Das Hauptzugriffsprotokoll mit zwei Aufgaben zu betrauen, ist eine konstruierte Lösung, da wir für die Fehlerbehebung in der Regel viel mehr Informationen benötigen als für die normale Analyse. Das Hinzufügen zahlreicher Variablen zum Hauptzugriffsprotokoll kann das Protokollvolumen mit Daten, die nur gelegentlich nützlich sind, drastisch erhöhen.

Stattdessen können wir ein zweites Zugriffsprotokoll verwenden und nur dann darin schreiben, wenn wir auf einen Fehler stoßen, der eine Fehlerbehebung erfordert. Die Direktive access_log unterstützt bedingtes Protokollieren mit dem Parameter if . Anforderungen werden nur protokolliert, wenn die Auswertung der angegebenen Variable einen Wert ungleich Null und nicht leer ergibt.

map $status $is_error { 400 1; # Ungültige Anfrage, einschließlich abgelaufenem Client-Zertifikat 495 1; # Client-Zertifikatfehler 502 1; # Ungültiges Gateway (es konnte kein Upstream-Server ausgewählt werden) 504 1; # Gateway-Timeout (konnte keine Verbindung zum ausgewählten Upstream herstellen) Standard 0; } access_log /var/log/nginx/access_debug.log access_debug if=$is_error; # Diagnoseprotokollierung access_log /var/log/nginx/access.log main;

Mit dieser Konfiguration übergeben wir die Variable $status durch einen Map- Block, um den Wert der Variable $is_error zu bestimmen, der dann vom if- Parameter der Direktive access_log ausgewertet wird. Wenn $is_error ausgewertet wird zu1 wir schreiben einen speziellen Protokolleintrag in die Datei access_debug.log .

Diese Konfiguration erkennt jedoch keine Fehler, die während der Anforderungsverarbeitung auftreten und letztendlich behoben werden, und führt daher zu einem Status200 OK . Ein solches Beispiel ist, wenn NGINX die Last zwischen mehreren Upstream-Servern ausgleicht. Wenn beim ausgewählten Server ein Fehler auftritt, leitet NGINX die Anforderung unter den durch die Direktive „proxy_next_upstream“ konfigurierten Bedingungen an den nächsten Server weiter. Solange einer der Upstream-Server erfolgreich antwortet, erhält der Client eine erfolgreiche Antwort, die mit dem Status protokolliert wird200 . Aufgrund der Wiederholungsversuche ist das Benutzererlebnis jedoch wahrscheinlich dürftig und es ist möglicherweise nicht sofort ersichtlich, dass ein Upstream-Server nicht einwandfrei funktioniert. Immerhin haben wir ein200 .

Wenn NGINX versucht, eine Verbindung zu mehreren Upstream-Servern herzustellen, werden alle ihre Adressen in der Variable „$upstream_addr“ erfasst. Dasselbe gilt für andere $upstream_* -Variablen, zum Beispiel $upstream_status, das den Antwortcode von jedem Serverversuch erfasst. Wenn wir also mehrere Einträge in diesen Variablen sehen, wissen wir, dass etwas Schlimmes passiert ist – wir haben wahrscheinlich ein Problem mit mindestens einem der Upstream-Server.

Wie wäre es, wenn wir auch in access_debug.log schreiben, wenn die Anforderung an mehrere Upstream-Server weitergeleitet wurde?

map $upstream_status $multi_upstreams { "~," 1; # Hat ein Komma default 0; } map $status $is_error { 400 1; # Ungültige Anfrage, einschließlich abgelaufenem Client-Zertifikat 495 1; # Client-Zertifikatfehler 502 1; # Ungültiges Gateway (es konnte kein Upstream-Server ausgewählt werden) 504 1; # Gateway-Timeout (Verbindung zum ausgewählten Upstream konnte nicht hergestellt werden) default $multi_upstreams; # Wenn wir mehr als einen Upstream-Server ausprobiert hätten } access_log /var/log/nginx/access_debug.log access_debug if=$is_error; # Diagnoseprotokollierung access_log /var/log/nginx/access.log main; # Normale Protokollierung

Hier verwenden wir einen weiteren Map- Block, um eine neue Variable ( $multi_upstreams ) zu erzeugen, deren Wert vom Vorhandensein eines Kommas ( , ) in $upstream_status abhängt. Ein Komma bedeutet, dass mehr als ein Statuscode vorhanden ist und daher mehr als ein Upstream-Server gefunden wurde. Diese neue Variable bestimmt den Wert von $is_error , wenn $status nicht einer der aufgelisteten Fehlercodes ist.

An diesem Punkt haben wir unser reguläres Zugriffsprotokoll und eine spezielle access_debug.log -Datei, die fehlerhafte Anforderungen enthält, aber wir haben das access_debug -Protokollformat noch nicht definiert. Stellen wir nun sicher, dass wir in der Datei access_debug.log alle Daten haben, die wir zur Diagnose von Problemen benötigen.

JSON-Protokollierung mit JavaScript

Das Einfügen von Diagnosedaten in access_debug.log ist nicht schwierig. NGINX bietet über 100 Variablen im Zusammenhang mit der HTTP-Verarbeitung und wir können eine spezielle log_format- Direktive definieren, die so viele davon erfasst, wie wir benötigen. Allerdings bringt die Entwicklung eines einfachen Protokollformats für diesen Zweck auch einige Nachteile mit sich.

• Es handelt sich um ein benutzerdefiniertes Format. Sie müssen einem Protokollparser beibringen, wie er es lesen kann.
• Einträge können sehr lang und für Menschen während der Live-Fehlerbehebung schwer zu lesen sein
• Sie müssen ständig auf das Protokollformat zurückgreifen, um Einträge zu interpretieren
• Es ist nicht möglich, nicht deterministische Werte wie „alle Anforderungsheader“ zu protokollieren.

Wir können diese Herausforderungen bewältigen, indem wir Protokolleinträge in einem strukturierten Format wie JSON schreiben und dabei das NGINX-JavaScript-Modul <.htmla> (njs) verwenden. Das JSON-Format wird auch von Protokollverarbeitungssystemen wie Splunk , LogStash , Graylog und Loggly weitgehend unterstützt. Indem wir die log_format -Syntax auf eine JavaScript-Funktion auslagern, profitieren wir von der nativen JSON-Syntax mit Zugriff auf alle NGINX-Variablen und zusätzlichen Daten aus dem njs-Objekt „ r “ .

js_import conf.d/json_log.js;js_set $json_debug_log json_log.debugLog;

log_format access_debug escape=none $json_debug_log; # Auslagern auf njs 
access_log /var/log/nginx/access_debug.log access_debug if=$is_error;

Die Direktive js_import gibt die Datei mit dem JavaScript-Code an und importiert sie als Modul. Den Code selbst finden Sie hier . Immer wenn wir einen Zugriffsprotokolleintrag schreiben, der das Protokollformat access_debug verwendet, wird die Variable $json_debug_log ausgewertet. Diese Variable wird durch Ausführen der JavaScript-Funktion debugLog ausgewertet, wie in der Direktive js_set definiert.

Diese Kombination aus JavaScript-Code und NGINX-Konfiguration erzeugt Diagnoseprotokolle, die wie folgt aussehen.

$ tail --lines=1 /var/log/nginx/access_debug.log | jq { "Zeitstempel": "2020-09-21T11:25:55+00:00", "Verbindung": { "Anzahl der Anfragen": 1, "verstrichene Zeit": 0,555, "pipelined": falsch, "ssl": { "Protokoll": „TLSv1.2“, „Chiffre“: "ECDHE-RSA-AES256-GCM-SHA384", "session_id": "b302f76a70dfec92f6bd72de5732692481ebecbbc69a4d81c900ae4dc928485c", "session_reused": false, "client_cert": { "status": "KEINE" } } }, "Anfrage": { "Client": "127.0.0.1", "Port": 443, "Host": "foo.example.com", "Methode": "GET", "uri": "/one", "http_version": 1.1, "bytes_received": 87, "Header": { "Host": "foo.example.com:443", "User-Agent": "curl/7.64.1", "Akzeptieren": "*/*" } }, "Upstreams": [ { "Serveradresse": "10.37.0.71", "server_port": 443, "Verbindungszeit": null, "Headerzeit": null, "Antwortzeit": 0,551, "bytes_sent": 0, "bytes_received": 0, "Status": 504 }, { "Serveradresse": "10.37.0.72", "server_port": 443, "Verbindungszeit": 0,004, "header_zeit": 0,004, "Antwortzeit": 0,004, "bytes_sent": 92, "bytes_received": 4161, "Status": 200 } ], "Antwort": { "Status": 200, "bytes_sent": 186, "Header": { "Inhaltstyp": "text/html", "Inhaltslänge": "4161" } } }

Das JSON-Format ermöglicht uns, separate Objekte für Informationen zur gesamten HTTP-Verbindung (einschließlich SSL/TLS), Anforderung, Upstreams und Antwort zu haben. Beachten Sie, wie der erste Upstream (10.37.0.71) den Status zurückgegeben hat 504(Gateway- Timeout), bevor NGINX den nächsten Upstream (10.37.0.72) versuchte, der erfolgreich antwortete. Das Timeout von einer halben Sekunde (gemeldet als „response_time“ im ersten Element des Upstream- Objekts) ist für den größten Teil der Gesamtlatenz für diese erfolgreiche Antwort verantwortlich (gemeldet als „elapsed_time“ im Verbindungsobjekt ).

Dies ist ein weiteres Beispiel für einen (abgekürzten) Protokolleintrag für einen Clientfehler, der durch ein abgelaufenes Client-Zertifikat verursacht wurde.

{ 
"Zeitstempel": "2020-09-22T10:20:50+00:00",
"Verbindung": {
"SSL": {
"Protokoll": „TLSv1.2“,
„Chiffre“: „ECDHE-RSA-AES256-GCM-SHA384“,
„Sitzungs-ID“: "30711efbe047c38a98c2209cc4b5f196988dcf2d7f1f2c269fde7269c370432e",
"session_reused": falsch,
"client_cert": {
"status": „FEHLER: Zertifikat ist abgelaufen“,
„Seriennummer“: "1006",
"Fingerabdruck": "0c47cc4bd0fefbc2ac6363345cfbbf295594fe8d",
"Betreff": "emailAddress=liam@nginx.com,CN=test01,OU=Demo CA,O=nginx,ST=CA,C=US",
"Aussteller": „CN=Demo Intermediate CA,OU=Demo CA,O=nginx,ST=CA,C=US“,
„startet“: „20. Sept. 2019 12:00:11 GMT“,
„läuft ab“: „20. Sept. 2020 12:00:11 GMT“,
„abgelaufen“: wahr,
...
„Antwort“: {
„Status“: 400,
"bytes_sent": 283,
"Header": {
"Inhaltstyp": "text/html",
"Inhaltslänge": "215"
}
}

Zusammenfassung

Indem wir nur dann ausführliche Diagnosedaten generieren, wenn ein Fehler auftritt, ermöglichen wir eine Fehlerbehebung in Echtzeit, ohne dass eine Neukonfiguration erforderlich ist. Erfolgreiche Anfragen werden nicht beeinträchtigt, da der JavaScript-Code nur ausgeführt wird, wenn wir in der Protokollierungsphase einen Fehler erkennen, nachdem das letzte Byte an den Client gesendet wurde.

Die vollständige Konfiguration ist auf GitHub verfügbar – warum probieren Sie sie nicht in Ihrer Umgebung aus? Wenn Sie NGINX Plus noch nicht verwenden, starten Sie noch heute eine kostenlose 30-Tage-Testversion oder kontaktieren Sie uns, um Ihre Anwendungsfälle zu besprechen .