Django Logging, The Right Way
Un buon logging è fondamentale per il debug e la risoluzione dei problemi. Non solo è utile nello sviluppo locale, ma in produzione è indispensabile. Quando si esaminano i log per un problema, è raro sentire qualcuno dire: “Abbiamo troppi log nella nostra applicazione”, ma è comune sentire il contrario. Quindi, con questo in mente, iniziamo.
Un corso intensivo di logger Python
In cima ad ogni file, dovreste avere qualcosa come questo:
import logginglogger = logging.getLogger(__name__)__name__ valuterà il percorso Python tratteggiato del modulo, ad esempio myproject/myapp/views.py userà myproject.myapp.views. Ora possiamo usare quel logger in tutto il file in questo modo:
# 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")Nota: i logger di Python gestiranno l’inserimento di variabili nel vostro messaggio di log se le passate come argomenti nella funzione di log. Se il log non ha bisogno di essere mandato in output, la sostituzione della variabile non avverrà mai, aiutando ad evitare un piccolo impatto sulle prestazioni per un log che non sarà mai usato.
Concia il tuo codice liberamente con queste istruzioni di log. Ecco la regola empirica che uso per i livelli di log:
-
debug: Informazioni non necessarie per il funzionamento regolare, ma utili nello sviluppo. -
info: Informazioni utili durante il funzionamento regolare. -
warning: Informazioni che potrebbero essere problematiche, ma non urgenti. -
error: Informazioni che sono importanti e che probabilmente richiedono un’attenzione immediata. -
critical: Non mi trovo ad usare questo in pratica, ma se hai bisogno di uno più alto dierror, eccolo
Dove registrare
La tua applicazione non dovrebbe preoccuparsi di dove vanno i suoi log. Invece, dovrebbe registrare tutto nella console (stdout/stderr) e lasciare che il server decida cosa farne da lì. Tipicamente questo viene messo in un file dedicato (e logrotato), catturato dal diario di Systemd o da Docker, inviato a un servizio separato come ElasticSearch, o qualche combinazione di questi. La memorizzazione dei log è un problema di distribuzione, non di applicazione.
L’unica cosa di cui la vostra applicazione deve preoccuparsi è il formato dei log. Tipicamente questo è solo una stringa con i dati rilevanti, ma se il tuo server aggiunge già un timestamp al log, probabilmente vuoi escluderlo dal tuo formatter. Allo stesso modo, se il vostro aggregatore di log può accettare JSON, un formattatore come python-json-logger può essere più appropriato.
Configurare il logger
Scrivere ai logger in Python è facile. Configurarli per andare nel posto giusto è più impegnativo di quanto ci si aspetti. Inizierò bypassando il logging di default di Django come descritto nel mio post precedente. Questo ci fornirà una tabula rasa con cui lavorare.
Impostare Sentry
I servizi di segnalazione degli errori sono fondamentali per qualsiasi sito non banale. Per impostazione predefinita questi catturano le eccezioni non catturate, ti notificano il problema (solo una volta per incidente) e forniscono una bella interfaccia per vedere lo stato dell’applicazione quando si è verificata l’eccezione. Il mio servizio preferito per questo è Sentry.
Possiamo portare Sentry un passo avanti inviando anche tutti i messaggi di log che sono warning o superiori al servizio. Questi sarebbero altrimenti persi in un mare di file di log che in pratica vengono raramente rivisti. Per fare questo, aggiungeremo un logger “root” che serve a raccogliere tutti i log che vengono inviati da qualsiasi modulo Python. Questo assomiglia a questo nelle impostazioni di Django,
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': , }, },})Logging dalla tua applicazione
Mentre potresti voler conoscere solo gli avvisi e gli errori dalle tue dipendenze di terze parti, di solito vuoi una visione molto più profonda del codice della tua applicazione. Idealmente, il tuo codice vive tutto sotto un singolo spazio dei nomi, così può essere catturato con una singola aggiunta al loggers. Supponiamo che il tuo progetto utilizzi lo spazio dei nomi myproject, basandosi sul codice di cui sopra aggiungerai questo:
logging.config.dictConfig({ # ... 'loggers': { '': { 'level': 'WARNING', 'handlers': , }, 'myproject': { 'level': 'INFO', 'handlers': , # required to avoid double logging with root logger 'propagate': False, }, },})Ma cosa succede se vuoi indagare più a fondo su qualcosa nella tua applicazione con il logging debug? Dover impegnare il nuovo codice e distribuirlo sembra eccessivo. Questo è un ottimo caso d’uso per le variabili d’ambiente. Possiamo modificare la stanza precedente in questo modo:
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, }, },})Ora il logging della nostra applicazione sarà predefinito a info, ma può essere facilmente aumentato temporaneamente impostando la variabile d’ambiente LOGLEVEL=debug. In alternativa, se la memorizzazione dei log non è un problema, considerate di loggare sempre al livello debug. Sono abbastanza facili da filtrare con un semplice grep o tramite il tuo strumento di visualizzazione dei log, ad esempio Kibana.
Eliminare il rumore
Una volta che hai impostato e fatto funzionare i tuoi log, potresti scoprire che alcuni moduli registrano informazioni che non ti interessano veramente e servono solo a creare ulteriore rumore (ti sto guardando newrelic). Per questi moduli, possiamo aggiungere un altro logger per escluderli. La prima opzione è quella di registrarli nella console, ma evitando di propagarli al logger di root che li invierebbe a Sentry:
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, }, },})Se trovate che siano troppo rumorosi, anche per la console, possiamo abbandonarli del tutto:
logging.config.dictConfig({ # ... 'loggers': { # ... # Don't log this module at all 'noisy_module': { 'level': 'NOTSET', 'propagate': False, }, },})Local Request Logging
Una chicca nella configurazione predefinita di Django è la registrazione delle richieste con runserver. Sovrascrivendo la configurazione di Django, la perdiamo, ma è abbastanza facile riaggiungerla:
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