Django Logging, The Right Way

Un buen registro es crítico para depurar y solucionar problemas. No sólo es útil en el desarrollo local, sino que en producción es indispensable. Al revisar los registros de un problema, es raro escuchar a alguien decir: «Tenemos demasiado registro en nuestra aplicación», pero es común escuchar lo contrario. Así que, con eso en mente, vamos a empezar.

Un curso acelerado de registradores de Python

En la parte superior de cada archivo, debe tener algo como esto:

import logginglogger = logging.getLogger(__name__)

__name__ se evaluará a la ruta de Python de punto del módulo, por ejemplo, myproject/myapp/views.py utilizará myproject.myapp.views. Ahora podemos usar ese logger en todo el archivo así:

# 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: Los loggers de Python se encargarán de insertar variables en su mensaje de log si los pasas como argumentos en la función de logging. Si el registro no necesita ser emitido, la sustitución de la variable no ocurrirá nunca, ayudando a evitar un pequeño golpe de rendimiento para un registro que nunca será utilizado.

Perfora tu código generosamente con estas declaraciones de registro. Esta es la regla general que utilizo para los niveles de registro:

  • debug: Información no necesaria para la operación regular, pero útil en el desarrollo.
  • info: Información que es útil durante la operación regular.
  • warning: Información que podría ser problemática, pero no es urgente.
  • error: Información que es importante y probablemente requiere una atención rápida.
  • critical: No me encuentro usando esto en la práctica, pero si usted necesita uno más alto que error, aquí está

Dónde registrar

Su aplicación no debe preocuparse por dónde van sus registros. En su lugar, debe registrar todo en la consola (stdout/stderr) y dejar que el servidor decida qué hacer con él a partir de ahí. Típicamente esto se pone en un archivo dedicado (y logrotated), capturado por el diario Systemd o Docker, enviado a un servicio separado como ElasticSearch, o alguna combinación de estos. El almacenamiento de registros es una preocupación de despliegue, no una preocupación de la aplicación.

La única cosa que su aplicación tiene que preocuparse es el formato de los registros. Típicamente esto es sólo una cadena con los datos relevantes, pero si su servidor ya agrega una marca de tiempo al registro, probablemente quiera excluirla de su propio formatter. Del mismo modo, si su agregador de registros puede aceptar JSON, un formateador como python-json-logger puede ser más apropiado.

Configuración del Logger

Escribir a los loggers en Python es fácil. Configurarlos para que vayan al lugar correcto es más desafiante de lo que esperas. Empezaré por omitir el registro por defecto de Django como se describe en mi post anterior. Eso nos proporcionará una pizarra en blanco con la que trabajar.

Configuración de Sentry

Los servicios de reporte de errores son críticos para cualquier sitio no trivial. Por defecto, estos atrapan las excepciones no capturadas, le notifican el problema (sólo una vez por incidente), y proporcionan una interfaz agradable para ver el estado de la aplicación cuando se produjo la excepción. Mi servicio favorito para esto es Sentry.

Podemos llevar a Sentry un paso más allá enviando cualquier mensaje de registro que sea warning o superior al servicio también. De lo contrario, se perderían en un mar de archivos de registro que, en la práctica, rara vez se revisan. Para hacer esto, añadiremos un registrador «raíz» que sirve como un cajón de sastre para cualquier registro que se envíe desde cualquier módulo de Python. Esto se parece a esto en la configuración de 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 de tu aplicación

Aunque puede que sólo quieras saber sobre las advertencias y errores de tus dependencias de terceros, normalmente quieres una visión mucho más profunda del código de tu aplicación. Idealmente, todo su código vive bajo un solo espacio de nombres para que pueda ser capturado con una sola adición a la loggers. Supongamos que su proyecto utiliza el espacio de nombres myproject, basándose en el código de arriba usted añadiría esto:

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

¿Pero qué pasa si quiere investigar algo en su aplicación más profundamente con el registro debug? Tener que confirmar el nuevo código y desplegarlo se siente como una exageración. Este es un gran caso de uso para las variables de entorno. Podemos modificar la estrofa anterior para que se vea así:

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, }, },})

Ahora el registro de nuestra aplicación será por defecto info, pero puede ser fácilmente incrementado temporalmente estableciendo la variable de entorno LOGLEVEL=debug. Alternativamente, si el almacenamiento de registros no es un problema, considere siempre el registro en el nivel debug. Son bastante fáciles de filtrar con un simple grep o a través de su herramienta de visualización de registros, por ejemplo, Kibana.

Cortando el ruido

Una vez que tenga su registro configurado y en funcionamiento, puede encontrar algunos módulos de registro de información que realmente no le importa y sólo sirven para crear ruido adicional (te estoy mirando newrelic). Para estos módulos, podemos añadir otro registrador para excluirlos. La primera opción es registrarlos en la consola, pero evitar propagarlos al logger raíz que los enviaría 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, }, },})

Si encuentras que son demasiado ruidosos, incluso para la consola, podemos eliminarlos por completo:

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

Local Request Logging

Una de las cosas buenas de la configuración por defecto de Django es el registro de peticiones con runserver. Al anular la configuración de Django, lo perdemos, pero es bastante fácil de añadir de nuevo:

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