En Python una forma muy común con la cual podemos testear nuestras aplicaciones es simplemente colocando pequeñas impresiones en consola. Sí, así como lo lees. Me atrevo a decir que todos, en algún momento lo la carrera, habremos utilizando mensajes en consola para poder comprobar el funcionamiento de nuestras aplicaciones. Bueno, por lo menos yo sí. 😬

Admitámoslo, es algo bastante sencillo de hacer. Basta con colocar algún mensaje o imprimir el valor de alguna variable para conocer el comportamiento del programa.

def mi_super_funcion():
    print('Entramos a la función')
    response = request.get(URL)
    return response.text

if __name__ == '__main__':
    print('Antes del llamado de la función')
    resultado = mi_super_funcion()
    print('El valor es:', resultado)

A mí en lo particular me gusta utilizar el mensaje entramos aquí! para cerciorarme si el llamado a una función o un método se realizo de forma correcta.

Si bien es cierto en la mayoría de los casos esta "técnica" nos permite encontrar errores o comportamientos no esperados, también es importante mencionar que no es la forma correcta de hacerlo, y mucho menos es profesional. Si en dado caso nosotros queremos testear nuestra aplicación mediante mensajes, utilizando el standard output o el standard error, lo mejor que podemos hacer es apoyarnos del módulo logging. 🐍

A partir de este módulo seremos capaces de clasificar los mensaje los cuales queremos el usuario visualice en consola. Este módulo trabaja con 5 tipos de mensajes.

Su orden es ascendente, siendo el primer tipo de mensaje (Debug) el de menos importancia, y el último (Critical) el más importante.

Lo interesante del módulo es que ya se encuentra dentro a la biblioteca standard de Python, así que no será necesario instalar absolutamente nada para poder utilizarlo.

import logging

Para nosotros poder clasificar los mensajes, lo haremos mediante funciones. Veamos un ejemplo.

import logging

logging.debug('Mensaje Debug')
logging.info('Mensaje Info')
logging.warning('Mensaje Warning')
logging.error('Mensaje Error')
logging.critical('Mensaje Critical')

Si nosotros ejecutamos este script obtendremos como resultado la siguiente salida.

WARNING:root:Mensaje Warning
ERROR:root:Mensaje Error
CRITICAL:root:Mensaje Critical

Solo visualizaremos los mensajes más importantes: Warning, Error y Critical. Esto se debe principalmente a la configuración por default de logging. Verás, cada tipo de mensaje tiene asociado un nivel de importancia.

Por default logging esta configurado para solo mostrar los mensajes cuyo nivel sea mayor igual a 30. Si queremos modificar la configuración haremos uso del la función basicConfig.

logging.basicConfig(level=logging.DEBUG)

En este caso indico que quiero visualizar en consola todos aquellos mensajes cuyo valor sea mayor igual a 10, en otras palabras, todos los mensajes.

Lo interesante de la función basicConfig son las reglas que podemos establecer. A travez de esta función seremos capaces de indicar qué mensaje, con qué formato queremos el usuarios visualice en consola. Inclusive, si así lo deseamos, podemos almacenar los mensajes en un archivo log, basta con indicarlo en la función.

Veamos un ejemplo.

logging.basicConfig(level=logging.DEBUG, 
                    filename='pywombat.log',
                    filemode='w+',
                    format='%(levelname)s - %(message)s')

En este ejemplo almacenamos dentro del archivo pywombat.log todos aquellos mensajes a partir del tipo log. Los mensajes tendrán el siguiente formato: El tipo de mensaje (Nível) - el mensaje per se.

Si ejecutamos el script, obtendremos como resultado el siguiente archivo.

DEBUG - Mensaje Debug
INFO - Mensaje Info
WARNING - Mensaje Warning
ERROR - Mensaje Error
CRITICAL - Mensaje Critical

Es importante mencionar que, en dado caso nosotros almacenemos lo mensajes dentro de un archivo, estos no se mostrarán en consola.

En este caso el formato de lo mensajes es muy sencillo, sin embargo podemos complicarlo un poco más ¿Qué les parece si almacenamos la fecha exacta en la que el mensaje se "imprimió"?

logging.basicConfig(level=logging.DEBUG, 
                    filename='pywombat.log',
                    filemode='w+',
                    format='%(asctime)s - %(levelname)s - %(message)s',
                    datefmt='%m/%d/%Y %H:%M:%S')

En este caso agregamos %(asctime)s al formato del mensaje, además de utilizar el parámetro datefmt donde indicando el formato de la fecha. Cool, ya podemos obtener información más detallada sobre cada mensaje, y lo mejor es que tenemos un log creado, cualquier error no pasará desapercibido.

Threads Y procesos

Algo que me encanta del módulo __logging_ es la forma tan sencilla en la que podemos conocer qué thread o que proceso esta imprimiendo un mensaje. Esto sin duda es super útil cuando nos encontramos trabajando de forma concurrente. Veamos un ejemplo.

import logging
import threading

logging.basicConfig(level=logging.DEBUG,
                    format="%(threadName)s - %(processName)s -%(message)s")

if __name__ == '__main__':
    logging.info("Hola mundo desde el thread principal")

    threading.Thread(target=
        lambda: logging.info("Hola mundo desde un nuevo thread")
    ).start()

Si ejecutamos obtendremos la siguiente salida.

MainThread - MainProcess -Hola mundo desde el thread principal
Thread-1 - MainProcess -Hola mundo desde un nuevo thread

En dado caso deseemos conocer, ya sea el id del thread o el id del proceso, dejaremos a un lado threadName y processName y nos apoyaremos simplemente de thread y process, respectivamente.

logging.basicConfig(level=logging.DEBUG,
                    format="%(thread)s - %(process)s -%(message)s")

Excepciones

Otra cosa interesante del módulo logging, es la forma tan sencilla en la cual podemos capturar Excepciones.

import logging

logging.basicConfig(level=logging.DEBUG, 
                    format='%(levelname)s - %(message)s')

dividendo = 5
divisor = 0

try:
    resultado = dividendo / divisor
    logging.info(resultado)

except Exception as e:
    logging.error("Exception", exc_info=False)

Para nosotros capturar los errores haremos uso del parámetro exc_info. Si colocamos como valor False entonces el error no se mostrará en consola.

ERROR - Exception

Configuraciones avanzadas

Si en dado caso queremos agregar información extra a nuestros mensaje, sepamos qué podemos hacerlo. Dentro del parámetro format indicamos el nuevo valor a mostrar, y al momento de imprimir el mensaje haremos uso del parámero extra. Mediante un diccionario indicaremos los valores extras.

import logging

logging.basicConfig(level=logging.DEBUG, format="%(foo)s - %(message)s")

logging.warning('Hola mundo', extra={'foo': 'bar'})

bar - Hola mundo

Conclusión

Sin duda una muy buena forma de poder testear nuestras aplicaciones es mediante el módulo logging, no solo porque con él podremos obtener información adicional de lo que esta sucediendo en tiempo de ejecución, si no que además, si así lo deseamos, podemos llevar un log de todo lo ocurrido en la aplicación, de tal forma que todos los errores y posibles fallos, así como comportamientos inesperados, queden almacenados en un historial, el cual sin duda nos será de mucha utilidad. Dejemos a un lado los clásicos prints para comenzar desarrollar aplicaciones de forma profesional. 😉