Tutorial de logging en Python

Última modificación: 6 de julio de 2020

El tutorial de logging en Python muestra cómo hacer logging en Python con el módulo logging.

Logging

El logging es el proceso de escribir información en archivos de registro. Los archivos de registro contienen información sobre varios eventos que ocurrieron en el sistema operativo, el software o en la comunicación.

Propósito del logging

El logging se realiza con los siguientes propósitos:

• Recopilación de información
• Solución de problemas
• Generación de estadísticas
• Auditoría
• Perfilado

El logging no se limita a identificar errores en el desarrollo de software. También se utiliza en la detección de incidentes de seguridad, la supervisión de las violaciones de las políticas, la provisión de información en caso de problemas, la búsqueda de cuellos de botella en las aplicaciones o la generación de datos de uso.

Qué eventos registrar

Los eventos que deben registrarse incluyen los fallos de validación de entrada, los fallos de autenticación y autorización, los errores de aplicación, los cambios de configuración y los arranques y paradas de la aplicación.

Qué eventos no deben registrarse

Los eventos que no deben registrarse incluyen el código fuente de la aplicación, los valores de identificación de la sesión, los tokens de acceso, los datos personales sensibles, las contraseñas, las cadenas de conexión a la base de datos, las claves de cifrado y los datos de cuentas bancarias y titulares de tarjetas.

Mejores prácticas de registro

Las siguientes son algunas de las mejores prácticas para realizar el registro:

• El registro debe ser significativo.
• El registro debe contener contexto.
• El registro debe estar estructurado y realizarse a diferentes niveles.
• El registro debe ser equilibrado; no debe incluir ni demasiada ni muy poca información.
• Los mensajes de registro deben ser comprensibles para los humanos y analizables por las máquinas.
• El registro en aplicaciones más complejas debe realizarse en varios archivos de registro.
• El registro debe adaptarse al desarrollo y a la producción.

El módulo de registro

El módulo de registro de Python define funciones y clases que implementan un sistema flexible de registro de eventos para aplicaciones y bibliotecas.

Los componentes del módulo de registro

El módulo de registro tiene cuatro componentes principales: loggers, handlers, filtros y formateadores. Los registradores exponen la interfaz que el código de la aplicación utiliza directamente.Los manejadores envían los registros de registro (creados por los registradores) al destino apropiado.Los filtros proporcionan una facilidad de grano más fino para determinar qué registros de registro se emiten.Los formateadores especifican la disposición de los registros de registro en la salida final.

Jerarquía de registro de Python

Los registradores de Python forman una jerarquía. Un registrador llamado main es un padre de main.new.

Los registradores hijos propagan los mensajes hasta los manejadores asociados a sus registradores antecesores. Debido a esto, no es necesario definir y configurar manejadores para todos los loggers de la aplicación. Es suficiente configurar los manejadores para un registrador de nivel superior y crear registradores hijos según sea necesario.

Niveles de registro de Python

Los niveles se utilizan para identificar la gravedad de un evento. Hay seis niveles de registro:

• Crítico
• ERROR
• AVISO
• INFO
• DEBUG
• NOTSET

Si el nivel de registro se establece en WARNING, todos los mensajes WARNINGERROR, y CRITICAL se escriben en el archivo de registro o en la consola. Si se establece en ERROR, sólo se registran los mensajes ERROR y CRITICAL.

Los registradores tienen un concepto de nivel efectivo. Si un nivel no se establece explícitamente en un registrador, el nivel de su padre se utiliza en su lugar como itseffective nivel. Si el padre no tiene un nivel explícito establecido, se examina su padre, y así sucesivamente – se buscan todos los ancestros hasta que se encuentre un nivel explícitamente establecido.

Cuando el registrador se crea con getLogger(), el nivel se establece enNOTSET. Si el nivel de registro no se establece explícitamente con setLevel(), los mensajes se propagan a los padres del registrador. La cadena de registradores ancestrales del registrador se recorre hasta que se encuentra un ancestro con un nivel distinto a NOTSET, o se llega a la raíz. El registrador raíz tiene un nivel predeterminado WARNING.

Registrador raíz

Todos los registradores son descendientes del registrador raíz. Cada logger pasa los mensajes de registro a su padre. Los nuevos loggers se crean con el método getLogger(name). Llamar a la función sin nombre (getLogger()) devuelve el registrador raíz.

El registrador raíz siempre tiene un nivel explícito establecido, que es WARNINGpor defecto.

El registrador raíz se encuentra en la parte superior de la jerarquía y siempre está presente, incluso si no está configurado. En general, el programa o la biblioteca no debe registrar directamente contra el registrador raíz. En su lugar, debe configurarse un registrador específico para el programa. El logger raíz puede usarse para activar y desactivar fácilmente todos los loggers de todas las bibliotecas.

Ejemplo sencillo de logging en Python

El módulo logging tiene métodos sencillos que pueden usarse inmediatamente sin ninguna configuración. Se puede utilizar para un registro sencillo.

simple.py

#!/usr/bin/env pythonimport logginglogging.debug('This is a debug message')logging.info('This is an info message')logging.warning('This is a warning message')logging.error('This is an error message')logging.critical('This is a critical message')

El ejemplo llama a cinco métodos del módulo logging.Los mensajes se escriben en la consola.

$ simple.pyWARNING:root:This is a warning messageERROR:root:This is an error messageCRITICAL:root:This is a critical message

Nota que se utiliza el logger root y sólo se escriben tres mensajes.Esto es porque por defecto, sólo se escriben los mensajes con nivel warning y superior.

Python set logging level

El nivel de logging se establece con setLevel().Establece el umbral para este registrador en lvl.Los mensajes de registro que sean menos graves que lvl serán ignorados.

#!/usr/bin/env pythonimport logginglogger = logging.getLogger('dev')logger.setLevel(logging.DEBUG)logger.debug('This is a debug message')logger.info('This is an info message')logger.warning('This is a warning message')logger.error('This is an error message')logger.critical('This is a critical message')

En el ejemplo, cambiamos el nivel de registro a DEBUG.

logger = logging.getLogger('dev')

El getLogger() devuelve un logger con el nombre especificado.Si name es None, devuelve el logger raíz. El nombre puede ser una cadena separada por puntos que defina la jerarquía de los registros; por ejemplo, ‘a’, ‘a.b’, o ‘a.b.c’. Tenga en cuenta que hay un nombre raíz implícito, que no se muestra.

$ set_level.pyThis is a warning messageThis is an error messageThis is a critical message

Ahora todos los mensajes fueron escritos.

Nivel de registro efectivo de Python

El nivel de registro efectivo es el nivel establecido explícitamente ordeterminado de los padres del registrador.

#!/usr/bin/env pythonimport loggingmain_logger = logging.getLogger('main')main_logger.setLevel(5)dev_logger = logging.getLogger('main.dev')print(main_logger.getEffectiveLevel())print(dev_logger.getEffectiveLevel())

En el ejemplo, examinamos el nivel de registro efectivo de dos loggers.

dev_logger = logging.getLogger('main.dev')

El nivel del dev_logger no se establece; se utiliza entonces el nivel de su padre.

$ effective_level.py55

Esta es la salida.

Controladores de registro de Python

El controlador es un objeto responsable de enviar los mensajes de registro apropiados (basados en la gravedad de los mensajes de registro) al destino especificado por el controlador.

Los controladores se propagan como los niveles. Si el logger no tiene un handler establecido, su cadena de ancestros busca un handler.

#!/usr/bin/env pythonimport logginglogger = logging.getLogger('dev')logger.setLevel(logging.INFO)fileHandler = logging.FileHandler('test.log')fileHandler.setLevel(logging.INFO)consoleHandler = logging.StreamHandler()consoleHandler.setLevel(logging.INFO)logger.addHandler(fileHandler)logger.addHandler(consoleHandler)logger.info('information message')

El ejemplo crea dos handlers para un logger: un handler de archivo y un handler de consola.

fileHandler = logging.FileHandler('test.log')

FileHandler envía los registros del log al test.logarchivo.

consoleHandler = logging.StreamHandler()

StreamHandler envía los registros de bitácora a un stream.Si no se especifica el stream, se utiliza el sys.stderr.

logger.addHandler(fileHandler)

El handler se añade al logger con addHandler().

Formateadores de logging de Python

El formateador es un objeto que configura el orden final,la estructura y el contenido del registro de log. Además de la cadena de mensajes, los registros también incluyen la fecha y la hora, los nombres de los registros y la gravedad del nivel de registro.

#!/usr/bin/env pythonimport logginglogger = logging.getLogger('dev')logger.setLevel(logging.INFO)consoleHandler = logging.StreamHandler()consoleHandler.setLevel(logging.INFO)logger.addHandler(consoleHandler)formatter = logging.Formatter('%(asctime)s %(name)s %(levelname)s: %(message)s')consoleHandler.setFormatter(formatter)logger.info('information message')

El ejemplo crea un logger de consola y añade un formateador a su handler.

formatter = logging.Formatter('%(asctime)s %(name)s %(levelname)s: %(message)s')

Se crea el formateador. Incluye la fecha-hora, el nombre del logger, el nombre del nivel de registro y el mensaje de registro.

consoleHandler.setFormatter(formatter)

El formateador se establece en el handler con setFormatter().

$ formatter.py2019-03-28 14:53:27,446 dev INFO: information message

El mensaje con el formato definido se muestra en la consola.

Python logging basicConfig

El basicConfig() configura el logger raíz. Hace una configuración básica para el sistema de logging creando un stream handler con un defaultformatter. El debug()info()warning()error() y critical() llamanbasicConfig() automáticamente si no se definen manejadores para el registrador raíz.

#!/usr/bin/env pythonimport logginglogging.basicConfig(filename='test.log', format='%(filename)s: %(message)s', level=logging.DEBUG)logging.debug('This is a debug message')logging.info('This is an info message')logging.warning('This is a warning message')logging.error('This is an error message')logging.critical('This is a critical message')

El ejemplo configura el logger raíz con basicConfig.

logging.basicConfig(filename='test.log', format='%(filename)s: %(message)s', level=logging.DEBUG)

Con filename, configuramos el archivo en el que escribimos los mensajes de registro.El format determina lo que se registra en el archivo; tenemosel nombre del archivo y el mensaje. Con level, establecemos el umbral de registro.

$ basic_config.py$ cat test.logbasic_config.py: This is a debug messagebasic_config.py: This is an info messagebasic_config.py: This is a warning messagebasic_config.py: This is an error messagebasic_config.py: This is a critical message

Después de ejecutar el programa, tenemos cinco mensajes escritos en el archivotest.log.

Fichero de registro de PythonConfig

El fileConfig() lee la configuración del registro desde un fichero con formato configparser.

keys=root,devkeys=consoleHandlerkeys=extend,simplelevel=INFOhandlers=consoleHandlerlevel=INFOhandlers=consoleHandlerqualname=devpropagate=0class=StreamHandlerlevel=INFOformatter=extendargs=(sys.stdout,)format=%(asctime)s - %(name)s - %(levelname)s - %(message)sformat=%(asctime)s - %(message)s

El log.conf define un logger, un handler y un formatter.

#!/usr/bin/env pythonimport loggingimport logging.configlogging.config.fileConfig(fname='log.conf')logger = logging.getLogger('dev')logger.info('This is an information message')

El ejemplo lee el archivo de configuración del logger desde el log.conf.

$ file_config.py2019-03-28 15:26:31,137 - dev - INFO - This is an information message

Esta es la salida.

Variable de registro de Python

Los datos dinámicos se registran utilizando el formato de cadena.

#!/usr/bin/env pythonimport loggingroot = logging.getLogger()root.setLevel(logging.INFO)log_format = '%(asctime)s %(filename)s: %(message)s'logging.basicConfig(filename="test.log", format=log_format)# incident happenserror_message = 'authentication failed'root.error(f'error: {error_message}')

El ejemplo escribe datos personalizados en el mensaje de registro.

2019-03-21 14:17:23,196 log_variable.py: error: authentication failed

Este es el mensaje de registro.

Fecha del formato de registro de Python

La fecha se incluye en el mensaje de registro con el asctimeregistro de registro. Con la opción de configuración datefmt podemos formatear la cadena datetime.

#!/usr/bin/env pythonimport logginglogger = logging.getLogger()logger.setLevel(logging.DEBUG)log_format = '%(asctime)s %(filename)s: %(message)s'logging.basicConfig(filename="test.log", format=log_format, datefmt='%Y-%m-%d %H:%M:%S')logger.info("information message")

El ejemplo formatea la fecha-hora del mensaje de registro.

log_format = '%(asctime)s %(filename)s: %(message)s'

Incluimos la cadena de fecha-hora en el registro con asctime.

logging.basicConfig(filename="test.log", format=log_format, datefmt='%Y-%m-%d %H:%M:%S')

La opción datefmt formatea la cadena datetime.

2019-03-21 14:17:23,196 log_variable.py: error: authentication failed2019-03-21 14:23:33 date_time.py: information message

Nota la diferencia en el formato de la cadena datetime.

Rastreo de la pila de registro de Python

El rastreo de la pila es una pila de llamadas de las funciones que se ejecutaron hasta el punto de un lanzamiento de excepciones. El stack trace se incluye con la opción exc_info.

#!/usr/bin/env pythonimport logginglog_format = '%(asctime)s %(filename)s: %(message)s'logging.basicConfig(filename="test.log", format=log_format)vals = try: print(vals)except Exception as e: logging.error("exception occurred", exc_info=True)

En el ejemplo, registramos la excepción que se lanza cuando se intenta acceder a un índice de lista inexistente.

logging.error("exception occurred", exc_info=True)

La traza de la pila se incluye en el registro estableciendo el exc_infoa True.

2019-03-21 14:56:21,313 stack_trace.py: exception occurredTraceback (most recent call last): File "C:\Users\Jano\Documents\pyprogs\pylog\stack_trace.py", line 11, in <module> print(vals)IndexError: list index out of range

La traza de la pila se incluye en el registro.

Logging de Python getLogger

El getLogger() devuelve un logger con el nombre especificado.Si no se especifica ningún nombre, devuelve el logger raíz. Es una práctica común poner el nombre del módulo con __name__.

Todas las llamadas a esta función con un nombre dado devuelven la misma instancia de logger.Esto significa que las instancias de logger nunca necesitan ser pasadas entre diferentes partes de una aplicación.

#!/usr/bin/env pythonimport loggingimport sysmain = logging.getLogger('main')main.setLevel(logging.DEBUG)handler = logging.FileHandler('my.log')format = logging.Formatter('%(asctime)s %(name)s %(levelname)s: %(message)s')handler.setFormatter(format)main.addHandler(handler)main.info('info message')main.critical('critical message')main.debug('debug message')main.warning('warning message')main.error('error message')

El ejemplo crea un nuevo logger con getLogger().Se le da un manejador de archivos y un formateador.

main = logging.getLogger('main')main.setLevel(logging.DEBUG)

Se crea un logger llamado main; establecemos el nivel de registro en DEBUG.

handler = logging.FileHandler('my.log')

Se crea un manejador de archivos. Los mensajes se escribirán en elmy.log archivo.

format = logging.Formatter('%(asctime)s %(name)s %(levelname)s: %(message)s')handler.setFormatter(format)

Se crea un formateador. Incluye la hora, el nombre del registrador, el nivel de registro y el mensaje a registrar. El formateador se añade al handler con setFormatter().

main.addHandler(handler)

El handler se añade al logger con addHandler().

$ cat my.log2019-03-21 14:15:45,439 main INFO: info message2019-03-21 14:15:45,439 main CRITICAL: critical message2019-03-21 14:15:45,439 main DEBUG: debug message2019-03-21 14:15:45,439 main WARNING: warning message2019-03-21 14:15:45,439 main ERROR: error message

Estos son los mensajes de registro escritos.

Configuración YAML del registro de Python

Los detalles del registro pueden ser definidos en un archivo de configuración YAML.YAML es un lenguaje de serialización de datos legible por humanos. Es comúnmente utilizado para archivos de configuración.

$ pip install pyyaml

Necesitamos instalar el módulo pyyaml

version: 1formatters: simple: format: "%(asctime)s %(name)s: %(message)s" extended: format: "%(asctime)s %(name)s %(levelname)s: %(message)s"handlers: console: class: logging.StreamHandler level: INFO formatter: simple file_handler: class: logging.FileHandler level: INFO filename: test.log formatter: extended propagate: falseloggers: dev: handlers: test: handlers: root: handlers: 

En el archivo de configuración, hemos definido varios formateadores, manejadores y registradores. La opción propagate impide propagar los mensajes del logger a los loggers padre; en nuestro caso, al logger raíz.De lo contrario, los mensajes se duplicarían.

#!/usr/bin/env pythonimport loggingimport logging.configimport yamlwith open('config.yaml', 'r') as f: log_cfg = yaml.safe_load(f.read())logging.config.dictConfig(log_cfg)logger = logging.getLogger('dev')logger.setLevel(logging.INFO)logger.info('This is an info message')logger.error('This is an error message')

En el ejemplo, leemos el fichero de configuración y utilizamos el dev logger.

$ log_yaml.py2019-03-28 11:36:54,854 dev: This is an info message2019-03-28 11:36:54,855 dev: This is an error message

Cuando ejecutamos el programa, aparecen dos mensajes en la consola.Los manejadores de la consola utilizan el formateador simple con menos información.

...2019-03-28 11:36:54,854 dev INFO: This is an info message2019-03-28 11:36:54,855 dev ERROR: This is an error message

Hay mensajes de registro dentro del archivo test.log.Son producidos por el formateador extendido con más información.

En este tutorial, hemos trabajado con la librería de registro de Python.

Lista de todos los tutoriales de Python.