Django Logging, The Right Way

Gutes Logging ist entscheidend für das Debugging und die Fehlersuche bei Problemen. Sie ist nicht nur bei der lokalen Entwicklung hilfreich, sondern auch in der Produktion unverzichtbar. Wenn man sich die Protokolle zu einem Problem ansieht, hört man selten jemanden sagen: „Wir haben zu viel Protokollierung in unserer Anwendung“, aber häufig hört man das Gegenteil. Also, mit diesem Gedanken im Hinterkopf, lasst uns anfangen.

A Crash Course in Python Loggers

Am Anfang jeder Datei sollte so etwas stehen:

import logginglogger = logging.getLogger(__name__)

__name__ wird auf den gepunkteten Python-Pfad des Moduls ausgewertet, z.B. myproject/myapp/views.py wird myproject.myapp.views verwenden. Jetzt können wir diesen Logger in der gesamten Datei wie folgt verwenden:

# A simple string logged at the "warning" levellogger.warning("Your log message is here")# A string with a variable at the "info" levellogger.info("The value of var is %s", var)# Logging the traceback for a caught exceptiontry: function_that_might_raise_index_error()except IndexError: # equivalent to logger.error(msg, exc_info=True) logger.exception("Something bad happened")

Hinweis: Pythons Logger fügen Variablen in Ihre Logmeldung ein, wenn Sie sie als Argumente in der Logging-Funktion übergeben. Wenn das Protokoll nicht ausgegeben werden muss, wird die Variablensubstitution nie stattfinden, was dazu beiträgt, einen kleinen Leistungseinbruch für ein Protokoll zu vermeiden, das nie verwendet wird.

Pfeffern Sie Ihren Code großzügig mit diesen Protokollierungsanweisungen. Hier ist die Faustregel, die ich für die Protokollierungsebenen verwende:

  • debug: Informationen, die für den regulären Betrieb nicht benötigt werden, aber für die Entwicklung nützlich sind.
  • info: Informationen, die während des regulären Betriebs hilfreich sind.
  • warning: Informationen, die problematisch sein könnten, aber nicht dringend sind.
  • error: Informationen, die wichtig sind und wahrscheinlich sofortige Aufmerksamkeit erfordern.
  • critical: Ich verwende dies in der Praxis nicht, aber wenn Sie einen höheren Wert als error benötigen, hier ist er

Wo protokollieren

Ihre Anwendung sollte sich nicht darum kümmern, wo ihre Protokolle hingehen. Stattdessen sollte sie alles auf der Konsole protokollieren (stdout/stderr) und den Server entscheiden lassen, was er damit machen soll. In der Regel wird dies in einer dedizierten (und protokollierten) Datei abgelegt, vom Systemd-Journal oder von Docker erfasst, an einen separaten Dienst wie ElasticSearch oder eine Kombination dieser Möglichkeiten gesendet. Die Speicherung von Protokollen ist eine Frage der Bereitstellung, nicht eine Frage der Anwendung.

Das Einzige, um das sich Ihre Anwendung kümmern muss, ist das Format der Protokolle. Normalerweise ist dies nur eine Zeichenkette mit den relevanten Daten, aber wenn Ihr Server dem Protokoll bereits einen Zeitstempel hinzufügt, möchten Sie diesen wahrscheinlich von Ihrem eigenen formatter ausschließen. Ebenso, wenn Ihr Log-Aggregator JSON akzeptieren kann, kann ein Formatierer wie python-json-logger besser geeignet sein.

Konfigurieren des Loggers

Das Schreiben an Logger in Python ist einfach. Sie so zu konfigurieren, dass sie an die richtige Stelle gehen, ist schwieriger, als man erwarten würde. Ich beginne damit, die Standardprotokollierung von Django zu umgehen, wie in meinem vorherigen Beitrag beschrieben. Das gibt uns eine leere Tafel, mit der wir arbeiten können.

Einrichten von Sentry

Fehlerberichterstattungsdienste sind für jede nicht-triviale Seite wichtig. Standardmäßig fangen diese Dienste nicht abgefangene Ausnahmen ab, benachrichtigen Sie über das Problem (nur einmal pro Vorfall) und bieten eine schöne Schnittstelle, um den Zustand der Anwendung zu sehen, als die Ausnahme auftrat. Mein Lieblingsdienst hierfür ist Sentry.

Wir können Sentry einen Schritt weiter bringen, indem wir alle Protokollmeldungen, die warning oder höher sind, ebenfalls an den Dienst senden. Diese würden sonst in einem Meer von Protokolldateien verloren gehen, die in der Praxis selten überprüft werden. Zu diesem Zweck fügen wir einen „Root“-Logger hinzu, der als Sammelstelle für alle Logs dient, die von einem beliebigen Python-Modul gesendet werden. In den Django-Einstellungen sieht das in etwa so aus:

import logging.configLOGGING_CONFIG = Nonelogging.config.dictConfig({ 'version': 1, 'disable_existing_loggers': False, 'formatters': { 'console': { # exact format is not important, this is the minimum information 'format': '%(asctime)s %(name)-12s %(levelname)-8s %(message)s', }, }, 'handlers': { 'console': { 'class': 'logging.StreamHandler', 'formatter': 'console', }, # Add Handler for Sentry for `warning` and above 'sentry': { 'level': 'WARNING', 'class': 'raven.contrib.django.raven_compat.handlers.SentryHandler', }, }, 'loggers': { # root logger '': { 'level': 'WARNING', 'handlers': , }, },})

Protokollierung von Ihrer Anwendung

Während Sie vielleicht nur über Warnungen und Fehler von Ihren Drittanbieter-Abhängigkeiten Bescheid wissen wollen, möchten Sie in der Regel einen viel tieferen Einblick in Ihren Anwendungscode. Im Idealfall befindet sich Ihr Code in einem einzigen Namespace, so dass er mit einem einzigen Zusatz zum loggers erfasst werden kann. Nehmen wir an, Ihr Projekt verwendet den Namespace myproject, dann würden Sie, aufbauend auf dem obigen Code, Folgendes hinzufügen:

logging.config.dictConfig({ # ... 'loggers': { '': { 'level': 'WARNING', 'handlers': , }, 'myproject': { 'level': 'INFO', 'handlers': , # required to avoid double logging with root logger 'propagate': False, }, },})

Was aber, wenn Sie etwas in Ihrer Anwendung mit der debug-Protokollierung genauer untersuchen wollen? Es wäre zu viel Aufwand, neuen Code zu übertragen und zu implementieren. Dies ist ein großartiger Anwendungsfall für Umgebungsvariablen. Wir können die vorherige Stanza so ändern, dass sie wie folgt aussieht:

import osLOGLEVEL = os.environ.get('LOGLEVEL', 'info').upper()logging.config.dictConfig({ # ... 'loggers': { '': { 'level': 'WARNING', 'handlers': , }, 'myproject': { 'level': LOGLEVEL, 'handlers': , # required to avoid double logging with root logger 'propagate': False, }, },})

Jetzt wird die Anwendungsprotokollierung standardmäßig auf info eingestellt, kann aber durch Setzen der Umgebungsvariablen LOGLEVEL=debug vorübergehend erhöht werden. Wenn die Speicherung von Protokollen kein Problem darstellt, können Sie alternativ auch eine Protokollierung auf der Ebene debug in Betracht ziehen. Sie sind einfach genug, um mit einem einfachen grep oder über Ihr Log-Visualisierungstool, z. B. Kibana, herauszufiltern.

Das Rauschen herausschneiden

Wenn Sie Ihr Logging eingerichtet haben und es läuft, werden Sie vielleicht feststellen, dass einige Module Informationen protokollieren, die Sie nicht wirklich interessieren und nur dazu dienen, zusätzliches Rauschen zu erzeugen (ich schaue Sie an newrelic). Für diese Module können wir einen weiteren Logger hinzufügen, um sie auszublenden. Die erste Option ist, sie auf der Konsole zu protokollieren, aber zu vermeiden, dass sie an den Root-Logger weitergegeben werden, der sie an Sentry senden würde:

logging.config.dictConfig({ # ... 'loggers': { '': { 'level': 'WARNING', 'handlers': , }, 'myproject': { 'level': LOGLEVEL, 'handlers': , # required to avoid double logging with root logger 'propagate': False, }, # Don't send this module's logs to Sentry 'noisy_module': { 'level':'ERROR', 'handlers': , 'propagate': False, }, },})

Wenn Sie finden, dass sie zu laut sind, sogar für die Konsole, können wir sie ganz weglassen:

logging.config.dictConfig({ # ... 'loggers': { # ... # Don't log this module at all 'noisy_module': { 'level': 'NOTSET', 'propagate': False, }, },})

Lokales Request Logging

Eine Nettigkeit in Djangos Standardkonfiguration ist das Request Logging mit Runserver. Indem wir Djangos Konfiguration überschreiben, verlieren wir sie, aber es ist einfach genug, sie wieder hinzuzufügen:

from django.utils.log import DEFAULT_LOGGINGlogging.config.dictConfig({ # ... 'formatters': { # ... 'django.server': DEFAULT_LOGGING, }, 'handlers': { # ... 'django.server': DEFAULT_LOGGING, }, 'loggers': { # ... 'django.server': DEFAULT_LOGGING, },})

Leave a Reply