En el desarrollo de software y la automatización de pruebas, la depuración inicial a menudo se realiza mediante la impresión de mensajes en la consola del IDE. Sin embargo, este enfoque resulta insuficiente para obtener información sobre la ejecución de proyectos de automatización de pruebas completos. Aquí es donde entra en juego la recopilación de registros (logs), permitiendo revisar el estado de ejecución después de cada ejecución.
- Conceptos Fundamentales de los Registros
1.1. Propósito de los Registros
La importancia de registrar información de eventos durante el desarrollo o las pruebas de un proyecto es crucial. Los registros actúan como pistas para diagnosticar y solucionar problemas, de manera similar a cómo un detective utiliza indicios para reconstruir un caso.
1.2. Niveles de Registro
Los eventos que ocurren durante la ejecución de un programa varían en severidad, desde información de depuración hasta errores críticos. Por ello, es necesario clasificar los registros por niveles para una localización de problemas más precisa. Los niveles de registro, ordenados por severidad creciente, son:
- DEBUG: Información detallada para depuración.
- INFO: Confirmación de que las operaciones transcurren como se espera.
- WARNING: Indica eventos inesperados o problemas potenciales futuros (ej. disco lleno) que no impiden el funcionamiento normal del software.
- ERROR: Problemas más serios que impiden la ejecución de ciertas funcionalidades.
- CRITICAL: Errores graves que impiden la continuación del programa.
La jerarquía de seevridad es: CRITICAL > ERROR > WARNING > INFO > DEBUG.
Al configurar un nivel de registro, se capturan todos los niveles iguales o superiores. Por ejemplo, si se establece el nivel en INFO, se registrarán mensajes INFO, WARNING, ERROR y CRITICAL, pero no DEBUG. Si se establece en DEBUG, se capturarán todos los niveles. El nivel de registro predeterminado es WARNING.
En proyectos de automatización, se suele utilizar INFO para el flujo general y ERROR para prever y registrar fallos.
1.3. Formato de Registro
Para mejorar la legibilidad y facilitar la identificación de problemas, los registros deben tener un formato consistente. Un formato común incluye la fecha y hora, el nombre del módulo, el número de línea, el nivel del registro y el mensaje específico. Un registro desorganizado dificulta la localización de errores.
2020-09-30 10:45:05,119 logging_test.py[line:7] DEBUG this is debug message.
2020-09-30 10:45:05,119 logging_test.py[line:9] INFO this is info message.
2020-09-30 10:45:05,119 logging_test.py[line:11] WARNING this is warning message.
2020-09-30 10:45:05,120 logging_test.py[line:13] ERROR this is error message.
2020-09-30 10:45:05,120 logging_test.py[line:15] CRITICAL this is critical message.
1.4. Ubicación de los Puntos de Registro
La colocación estratégica de los puntos de registro es fundamental y debe basarse en la lógica del negocio. Por ejemplo, antes de ejecutar un caso de prueba de cambio de contraseña, se podría insertar un registro como "Iniciando ejecución de cambio de contraseña...". De igual manera, antes de iniciar el proceso de inicio de sesión, registrar "Preparando inicio de sesión...". Un registro de "Inicio de sesión completado" colocado incorrectamente podría generar ambigüedad sobre si el problema ocurrió antes o después del intento de inicio de sesión.
- El Módulo
loggingde Python
2.1. Introducción
logging es el módulo de registro integrado en Python, que proporciona un sistema de registro versátil con diferentes niveles. Permite registrar información mediante diversas salidas, como archivos, peticiones HTTP, correo electrónico (SMTP) o sockets. Comúnmente, se opta por escribir registros en archivos con extensiones .txt o .log.
2.2. Importación
Para utilizar el módulo logging, es necesario importarlo:
import logging
- Configuración Básica del Módulo
logging
3.1. Función basicConfig()
La forma más sencilla de configurar el registro es utilizando la función logging.basicConfig(**kwargs).
3.2. Parámetros Clave de basicConfig()
- filename: Especifica el nombre o la ruta completa del archivo de registro (ej.
E:/app-ui-autotest/log/log.txt). - filemode: Define el modo de apertura del archivo. El valor predeterminado es 'a' (append/agregar). Otros modos comunes son:
- 'w': Escritura (sobrescribe el archivo si existe).
- 'r': Lectura.
- 'a': Agregado (añade al final del archivo existente).
- level: Establece el nivel mínimo de registro para el logger raíz.
- format: Define el formato de salida de los mensajes de registro.
3.3. Ejemplo 1: Registro en Consola (y Archivo)
# -*- coding:utf-8 -*-
import logging
logging.basicConfig(filename='./log.txt',
level=logging.DEBUG,
format='%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s')
logging.debug('This is debug message')
logging.info('This is info message')
logging.warning('This is warning message')
logging.error('This is error message')
logging.critical('This is critical message')
La salida en el archivo log.txt (y en la consola si no se especifica filename) será:
2020-09-30 10:45:05,119 logging_test.py[line:7] DEBUG This is debug message.
2020-09-30 10:45:05,119 logging_test.py[line:9] INFO This is info message.
2020-09-30 10:45:05,119 logging_test.py[line:11] WARNING this is warning message.
2020-09-30 10:45:05,120 logging_test.py[line:13] ERROR this is error message.
2020-09-30 10:45:05,120 logging_test.py[line:15] CRITICAL this is critical message.
3.4. Ejemplo 2: Registro en Archivo con Nivel INFO
Si se modifica el nivel a INFO, los mensajes de nivel DEBUG no se registrarán:
logging.basicConfig(filename='log.txt',
level=logging.INFO,
format='%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s')
# ... (llamadas a logging.debug, .info, .warning, .error, .critical)
Salida en log.txt:
2020-09-30 10:45:05,119 logging_test.py[line:9] INFO This is info message.
2020-09-30 10:45:05,119 logging_test.py[line:11] WARNING this is warning message.
2020-09-30 10:45:05,120 logging_test.py[line:13] ERROR this is error message.
2020-09-30 10:45:05,120 logging_test.py[line:15] CRITICAL this is critical message.
La diferencia clave con el ejemplo anterior es la inclusión del parámetro filename y el nivel INFO, que excluye los mensajes DEBUG.
- Flujo de Procesamiento de Registros Modular
El módulo logging se compone de cuatro elementos principales:
- Logger: Responsable de la captura de eventos de registro.
- Handler: Determina el destino de los mensajes de registro (archivo, consola, etc.).
- Filter: Permite un control más granular sobre qué mensajes se procesan.
- Formatter: Define el formato de presentación de los mensajes de registro.
4.1. Logger (Registrador)
Se utiliza para obtener una instancia de registro. Si no se crea explícitamente, se utiliza el root logger con nivel WARNING por defecto. El logger:
- Proporciona la interfaz para registrar eventos.
- Filtra los mensajes según los niveles establecidos.
- Distribuye los mensajes filtrados a los Handlers correspondientes.
4.2. Handler (Mananejador)
Los Handlers envían los mensajes de registro a su destino. Para enviar registros a la consola y a un archivo simultáneamente, se necesitan dos Handlers: uno para la consola y otro para el archivo. Se añaden al logger mediante el método addHandler().
4.2.1. StreamHandler
Envía los registros a flujos como sys.stdout o sys.stderr, típicamente lo que se ve en la consola del IDE. Su constructor es StreamHandler(strm), donde strm es el flujo de destino (por defecto sys.stderr).
4.2.2. FileHandler
Escribe los registros en un archivo en disco. Hereda de StreamHandler y se encarga de abrir el archivo. El constructor es FileHandler(filename, mode='a').
4.3. Filter (Filtro)
Permite aplicar reglas de filtrado más complejas que las basadas únicamente en niveles. Su uso puede proporcionar un control más refinado sobre qué registros se procesan.
4.4. Formatter (Formateador)
Define el formato y contenido de los mensajes de registro. El formato de fecha predeterminado es %Y-%m-%d %H:%M:%S. Otros especificadores de formato incluyen:
%(levelno)s: Nivel numérico del registro.%(levelname)s: Nombre del nivel del registro.%(pathname)s: Ruta completa del archivo fuente.%(filename)s: Nombre del archivo fuente.%(funcName)s: Nombre de la función donde se generó el registro.%(lineno)d: Número de línea en el archivo fuente.%(asctime)s: Fecha y hora del registro.%(thread)d: ID del hilo.%(threadName)s: Nombre del hilo.%(process)d: ID del proceso.%(message)s: Mensaje de registro.
4.5. Ejemplo: Registro en Consola y Archivo
Este ejemplo configura un logger que escribe tanto en la consola como en un archivo:
# -*- coding:utf-8 -*-
import logging
# 1. Crear el registrador (Logger)
logger = logging.getLogger() # Obtiene el root logger o un logger específico
logger.setLevel(logging.DEBUG) # Nivel mínimo para el logger
# 2. Crear los manejadores (Handlers)
# Handler para escribir en archivo
log_file_path = './log.txt'
file_handler = logging.FileHandler(log_file_path, mode='a', encoding='utf-8')
file_handler.setLevel(logging.INFO) # Nivel mínimo para el handler de archivo
# Handler para escribir en consola
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.INFO) # Nivel mínimo para el handler de consola
# 3. Definir el formato
log_format = logging.Formatter('%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s')
# 4. Asignar el formato a los handlers
file_handler.setFormatter(log_format)
console_handler.setFormatter(log_format)
# 5. Añadir los handlers al logger
logger.addHandler(file_handler)
logger.addHandler(console_handler)
# 6. Registrar mensajes
logger.info("This is info message")
logger.warning("This is warning message")
logger.error("This is error message")
logger.critical("This is critical message")
La salida en la consola y en el archivo log.txt será:
2020-10-07 15:54:04,752 test.py[line:3] INFO This is info message
2020-10-07 15:54:04,752 test.py[line:4] WARNING This is warning message
2020-10-07 15:54:04,752 test.py[line:5] ERROR This is error message
2020-10-07 15:54:04,752 test.py[line:6] CRITICAL This is critical message
- Aplicación Práctica: Registro en un Proyecto de Automatización Móvil
5.1. Escenario
Implementar la captura de registros para la operación de inicio de sesión en la aplicación móvil "Toutiao".
5.2. Configuración Simple
# -*- coding:utf-8 -*-
import logging
from appium import webdriver
logging.basicConfig(filename='./testLog.log',
level=logging.INFO,
format='%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s')
def setup_android_driver():
desired_caps = {
"platformName": "Android",
"platformVersion": "10",
"deviceName": "PCT_AL10",
"appPackage": "com.ss.android.article.news",
"appActivity": ".activity.MainActivity",
"unicodeKeyboard": True,
"resetKeyboard": True,
"noReset": True,
}
logging.info("Iniciando la aplicación Toutiao...")
driver = webdriver.Remote('http://127.0.0.1:4723/wd/hub', desired_caps)
return driver
def perform_login(driver):
'''Realiza la operación de inicio de sesión en Toutiao'''
logging.info("Iniciando proceso de login en Toutiao...")
try:
# Pasos para la interacción con la UI (elementos y clics)
driver.find_element_by_id("com.ss.android.article.news:id/cji").click() # Aceptar aviso
driver.find_element_by_id("android:id/button1").click() # Confirmar permisos
driver.find_element_by_xpath("//android.widget.TabWidget/android.widget.RelativeLayout[@index=3]").click() # Ir a perfil (sin login)
driver.find_element_by_id("com.ss.android.article.news:id/a10").click() # Botón de login
driver.find_element_by_id("com.ss.android.article.news:id/bgh").click() # Menú login
driver.find_element_by_xpath("//android.widget.LinearLayout[@index=4]").click() # Seleccionar login por contraseña
driver.find_element_by_id("com.ss.android.article.news:id/bu").send_keys("18768124236") # Ingresar usuario
driver.find_element_by_id("com.ss.android.article.news:id/c5").send_keys("xiaoqq3915172") # Ingresar contraseña
driver.find_element_by_id("com.ss.android.article.news:id/a2o").click() # Botón de login
except Exception as e:
logging.error("Error durante el login: {}".format(e))
else:
logging.info("Login exitoso...")
driver_instance = setup_android_driver()
perform_login(driver_instance)
Si el inicio de sesión es exitoso, el archivo testLog.log contendrá:
2020-09-30 18:20:05,119 logging_test.py[line:21] INFO Initiating Toutiao app launch...
2020-09-30 18:20:10,119 logging_test.py[line:27] INFO Initiating login process in Toutiao...
2020-09-30 18:21:07,120 logging_test.py[line:41] INFO Login successful...
5.3. Desafío: Mantenibilidad en Proyectos Multi-Módulo
El enfoque anterior funciona bien para un solo módulo. Sin embargo, en proyectos de automatización con múltiples módulos, replicar esta configuración en cada archivo es ineficiente y difícil de mantener. Surge la necesidad de una solución centralizada.
5.4. Estrategias de Solución
- Configuración de Registro en Código: Crear un módulo Python dedicado (ej.
logger_config.py) que configure el logger y sus handlers. Otros módulos importan y utilizan esta instancia de logger. - Configuración Externa (Archivo): Separar la configuración del registro (formato, rutas, niveles) en un archivo de configuración externo (ej.
logging.conf) y cargarla mediante un módulo específico.
5.5. Estrategia 1: Configuración Centralizada en Python
Archivo: logger_setup.py
# -*- coding:utf-8 -*-
import logging
# Configurar el logger
logger = logging.getLogger()
logger.setLevel(logging.DEBUG)
# Definir formato
log_format = logging.Formatter('%(asctime)s %(filename)s[line:%(lineno)d] %(levelname)s %(message)s')
# Handler para archivo
file_handler = logging.FileHandler('./log.txt', mode='a', encoding='utf-8')
file_handler.setLevel(logging.INFO)
file_handler.setFormatter(log_format)
logger.addHandler(file_handler)
# Handler para consola
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.INFO)
console_handler.setFormatter(log_format)
logger.addHandler(console_handler)
Archivo: test_module.py (en otro directorio, por ejemplo, tests/)
# -*- coding:utf-8 -*-
from appium import webdriver
from ..logger_setup import logger # Ajustar la ruta de importación según la estructura del proyecto
def setup_driver():
desired_caps = {
"platformName": "Android", "platformVersion": "10", "deviceName": "PCT_AL10",
"appPackage": "com.ss.android.article.news", "appActivity": ".activity.MainActivity",
"unicodeKeyboard": True, "resetKeyboard": True, "noReset": True,
}
logger.info("Iniciando la aplicación Toutiao...")
driver = webdriver.Remote('http://127.0.0.1:4723/wd/hub', desired_caps)
return driver
def login_action(driver):
logger.info("Iniciando proceso de login...")
try:
# ... (lógica de interacción con la UI)
logger.info("Login exitoso...")
except Exception as e:
logger.error("Error durante el login: {}".format(e))
driver_instance = setup_driver()
login_action(driver_instance)
Al ejecutar test_module.py, los registros se generarán y se guardarán en log.txt y en la consola.
5.6. Estrategia 2: Configuración mediante Archivo .conf
5.6.1. Archivo de Configuración: logger.conf
[loggers]
keys=root, exampleLogger
[handlers]
keys=consoleHandler, fileHandler
[formatters]
keys=formatter_simple, formatter_detailed
[logger_root]
level=DEBUG
handlers=consoleHandler, fileHandler
[logger_exampleLogger]
level=DEBUG
handlers=consoleHandler, fileHandler
qualname=exampleLogger
propagate=0
[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=formatter_simple
args=(sys.stdout,)
[handler_fileHandler]
class=FileHandler
level=DEBUG
formatter=formatter_detailed
args=('./log.txt', 'a', 'UTF-8') # Ruta, modo, codificación
[formatter_simple]
format=%(levelname)s: %(message)s
[formatter_detailed]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
Nota: Los comentarios en español dentro del archivo .conf deben ser eliminados o traducidos al inglés para evitar errores de codificación.
5.6.2. Cargar Configuración y Crear Logger
Archivo: base_logger.py
# -*- coding:utf-8 -*-
import logging.config
import sys
CONFIG_FILE = './logger.conf' # Ruta al archivo de configuración
# Cargar la configuración del archivo
logging.config.fileConfig(CONFIG_FILE)
# Obtener una instancia del logger configurado
logger = logging.getLogger('exampleLogger')
5.6.3. Uso en un Módulo de Prueba
Archivo: test_runner.py
# -*- coding:utf-8 -*-
from appium import webdriver
from log_utils.base_logger import logger # Asumiendo que base_logger.py está en un paquete log_utils
def setup_driver():
desired_caps = {
"platformName": "Android", "platformVersion": "10", "deviceName": "PCT_AL10",
"appPackage": "com.ss.android.article.news", "appActivity": ".activity.MainActivity",
"unicodeKeyboard": True, "resetKeyboard": True, "noReset": True,
}
logger.info("Iniciando la aplicación Toutiao...")
driver = webdriver.Remote('http://127.0.0.1:4723/wd/hub', desired_caps)
return driver
def login_action(driver):
logger.info("Iniciando proceso de login...")
try:
# ... (lógica de interacción con la UI)
logger.info("Login exitoso...")
except Exception as e:
logger.error("Error durante el login: {}".format(e))
driver_instance = setup_driver()
login_action(driver_instance)
La salida en la consola y en log.txt seguirá el formato definido en logger.conf.
- Consideraciones Adicionales: Logger para Entornos Multi-hilo
En aplicacoines que utilizan múltiples hilos, es importante que los registros incluyan información sobre el hilo que los genera para evitar confusiones.
6.1. Clase de Logger para Multi-hilo
# -*- coding:utf-8 -*-
import os
import logging
import time
class MultiThreadLogger(object):
def __init__(self, log_dir, logger_name, level=logging.DEBUG):
timestamp = time.strftime("%Y-%m-%d")
log_filename = os.path.join(log_dir, f"{logger_name}-{timestamp}.log")
self.logger = logging.getLogger(log_filename)
self.logger.setLevel(level)
formatter = logging.Formatter('[%(asctime)s %(threadName)s] [%(levelname)s] %(message)s', '%Y-%m-%d %H:%M:%S')
file_handler = logging.FileHandler(log_filename, encoding='utf-8')
file_handler.setFormatter(formatter)
file_handler.setLevel(level)
self.logger.addHandler(file_handler)
def debug(self, message):
self.logger.debug(message)
def info(self, message):
self.logger.info(message)
def warning(self, message):
self.logger.warning(message)
def error(self, message):
self.logger.error(message)
def critical(self, message):
self.logger.critical(message)
if __name__ == '__main__':
# Ejemplo de uso:
log_directory = "/tmp/my_logs/" # Asegurarse de que el directorio exista
os.makedirs(log_directory, exist_ok=True)
thread_logger = MultiThreadLogger(log_directory, "app_log")
thread_logger.debug('Mensaje de depuración')
thread_logger.info('Mensaje informativo')
thread_logger.warning('Advertencia')
thread_logger.error('Error')
thread_logger.critical('Mensaje crítico')
6.2. Ejemplo de Uso en un Script Principal
Este fragmento de código muestra cómo se podría integrar la clase MultiThreadLogger en un script más complejo, aunque el ejemplo proporcionado es una simplificación.
# -*- coding:utf-8 -*-
import sys
import threading
# Asumiendo que MultiThreadLogger está en un archivo llamado 'multi_thread_logger.py'
# y que la ruta está configurada correctamente en sys.path
# from multi_thread_logger import MultiThreadLogger
# --- Definición de la clase MultiThreadLogger aquí para simplificar ---
import os
import logging
import time
class MultiThreadLogger(object):
def __init__(self, log_dir, logger_name, level=logging.DEBUG):
timestamp = time.strftime("%Y-%m-%d")
log_filename = os.path.join(log_dir, f"{logger_name}-{timestamp}.log")
self.logger = logging.getLogger(log_filename)
self.logger.setLevel(level)
formatter = logging.Formatter('[%(asctime)s %(threadName)s] [%(levelname)s] %(message)s', '%Y-%m-%d %H:%M:%S')
file_handler = logging.FileHandler(log_filename, encoding='utf-8')
file_handler.setFormatter(formatter)
file_handler.setLevel(level)
self.logger.addHandler(file_handler)
def debug(self, message): self.logger.debug(message)
def info(self, message): self.logger.info(message)
def warning(self, message): self.logger.warning(message)
def error(self, message): self.logger.error(message)
def critical(self, message): self.logger.critical(message)
# --- Fin de la definición de la clase ---
# Simulación de un script principal que usa el logger
class DataProcessor:
def __init__(self, log_directory, log_name):
os.makedirs(log_directory, exist_ok=True)
self.logger = MultiThreadLogger(log_directory, log_name)
def process_data(self, data_item):
thread_name = threading.current_thread().name
self.logger.info(f"Procesando ítem '{data_item}' en el hilo '{thread_name}'.")
# Simulación de procesamiento
time.sleep(0.1)
if "error" in data_item.lower():
self.logger.error(f"Error al procesar '{data_item}' en el hilo '{thread_name}'.")
else:
self.logger.info(f"Ítem '{data_item}' procesado exitosamente en el hilo '{thread_name}'.")
def run_processing_threads(processor, items):
threads = []
for i, item in enumerate(items):
thread = threading.Thread(target=processor.process_data, args=(item,), name=f"Worker-{i+1}")
threads.append(thread)
thread.start()
for thread in threads:
thread.join()
if __name__ == '__main__':
log_dir = "./logs"
logger_instance = DataProcessor(log_dir, "data_processing")
data_to_process = ["Record 1", "Record 2", "Item with error", "Record 4"]
run_processing_threads(logger_instance, data_to_process)
print(f"Procesamiento completado. Verifique los registros en el directorio '{log_dir}'.")
Este ejemplo demuestra cómo la clase MultiThreadLogger registra mensajes junto con el nombre del hilo que los generó, lo cual es esencial para depurar aplicaciones multi-hilo.