Python Admin

Logging em Python: logging module, structlog e Boas Práticas: Do Básico ao Avançado Já leu

O módulo logging nativo do Python O módulo é parte da biblioteca padrão do Python e fornece um sistema flexível para registrar mensagens de eventos durante a execução de um programa. Ao contrário de simplesmente usar , o logging oferece controle sobre o nível de severidade das mensagens, permite direcioná-las para diferentes saídas (arquivo, console, email) e facilita a depuração em ambientes de produção. O funciona através de uma hierarquia de componentes: loggers criam os registros, handlers determinam para onde as mensagens vão, formatadores definem como as mensagens aparecem, e filtros controlam quais mensagens são processadas. Essa separação de responsabilidades torna o sistema robusto e reutilizável em projetos de qualquer tamanho. Configuração básica A forma mais simples de usar logging é chamar antes de qualquer log ser registrado. Esse método configura um logger padrão com um handler de console. Quando executado, você verá algo assim: Loggers, Handlers e Formatadores Para aplicações reais, você precisa entender como compor esses elementos manualmente.

O módulo logging nativo do Python

O módulo logging é parte da biblioteca padrão do Python e fornece um sistema flexível para registrar mensagens de eventos durante a execução de um programa. Ao contrário de simplesmente usar print(), o logging oferece controle sobre o nível de severidade das mensagens, permite direcioná-las para diferentes saídas (arquivo, console, email) e facilita a depuração em ambientes de produção.

O logging funciona através de uma hierarquia de componentes: loggers criam os registros, handlers determinam para onde as mensagens vão, formatadores definem como as mensagens aparecem, e filtros controlam quais mensagens são processadas. Essa separação de responsabilidades torna o sistema robusto e reutilizável em projetos de qualquer tamanho.

Configuração básica

A forma mais simples de usar logging é chamar logging.basicConfig() antes de qualquer log ser registrado. Esse método configura um logger padrão com um handler de console.

import logging

# Configuração básica
logging.basicConfig(
    level=logging.DEBUG,
    format='%(asctime)s - %(name)s - %(levelname)s - %(message)s',
    datefmt='%d/%m/%Y %H:%M:%S'
)

logger = logging.getLogger(__name__)

logger.debug("Mensagem de debug")
logger.info("Informação geral")
logger.warning("Aviso importante")
logger.error("Erro que ocorreu")
logger.critical("Erro crítico do sistema")

Quando executado, você verá algo assim:

12/01/2024 14:30:45 - __main__ - DEBUG - Mensagem de debug
12/01/2024 14:30:45 - __main__ - INFO - Informação geral
12/01/2024 14:30:45 - __main__ - WARNING - Aviso importante
12/01/2024 14:30:45 - __main__ - ERROR - Erro que ocorreu
12/01/2024 14:30:45 - __main__ - CRITICAL - Erro crítico do sistema

Loggers, Handlers e Formatadores

Para aplicações reais, você precisa entender como compor esses elementos manualmente. Um logger é obtido com logging.getLogger('nome'), onde o nome geralmente é o nome do módulo. Um handler define o destino (arquivo, console, etc.). Um formatador define a estrutura das mensagens.

import logging

# Criar logger
logger = logging.getLogger('minha_aplicacao')
logger.setLevel(logging.DEBUG)

# Handler para arquivo
file_handler = logging.FileHandler('app.log')
file_handler.setLevel(logging.ERROR)

# Handler para console
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.INFO)

# Formatador
formatter = logging.Formatter(
    '%(asctime)s | %(name)s | %(levelname)s | %(message)s',
    datefmt='%Y-%m-%d %H:%M:%S'
)

# Aplicar formatador aos handlers
file_handler.setFormatter(formatter)
console_handler.setFormatter(formatter)

# Adicionar handlers ao logger
logger.addHandler(file_handler)
logger.addHandler(console_handler)

# Usar o logger
logger.debug("Este debug só aparece no console")
logger.error("Este erro aparece em ambos")

Neste exemplo, mensagens DEBUG e INFO vão apenas para o console, enquanto erros vão para arquivo. Isso demonstra como você pode ter diferentes níveis de severidade para diferentes destinos em uma mesma aplicação.

Configuração via arquivo

Para projetos mais complexos, é comum usar um arquivo de configuração YAML ou JSON. Aqui usaremos um dicionário Python (que pode ser carregado de um JSON).

import logging.config
import json

config = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "standard": {
            "format": "%(asctime)s [%(levelname)s] %(name)s: %(message)s"
        },
        "detailed": {
            "format": "%(asctime)s [%(levelname)s] %(name)s.%(funcName)s:%(lineno)d - %(message)s"
        }
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "level": "DEBUG",
            "formatter": "standard",
            "stream": "ext://sys.stdout"
        },
        "file": {
            "class": "logging.handlers.RotatingFileHandler",
            "level": "WARNING",
            "formatter": "detailed",
            "filename": "app.log",
            "maxBytes": 10485760,
            "backupCount": 5
        }
    },
    "loggers": {
        "": {
            "handlers": ["console", "file"],
            "level": "DEBUG",
            "propagate": True
        }
    }
}

logging.config.dictConfig(config)
logger = logging.getLogger(__name__)

logger.info("Aplicação iniciada")
logger.warning("Atenção: memória baixa")

Esse padrão é escalável e permite mudar o comportamento do logging sem alterar o código da aplicação.

Introdução ao structlog

O structlog é uma biblioteca de terceiros que traz uma abordagem moderna e estruturada ao logging em Python. Enquanto o módulo nativo trabalha com strings, o structlog trabalha com dicionários e contextos, o que torna muito mais fácil gerar logs em formato JSON, estruturado, ideal para análise em sistemas de monitoramento como ELK Stack, Datadog ou Splunk.

A maior vantagem do structlog é a capacidade de manter contexto através da execução do programa. Você pode vincular informações uma única vez e elas aparecem em todos os logs subsequentes sem precisar repeti-las. Além disso, o structlog oferece um excelente suporte a processadores que transformam e enriquecem as mensagens de log.

Instalação e configuração básica

pip install structlog
import structlog

# Configuração padrão (saída para console em formato legível)
structlog.configure(
    processors=[
        structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
    ],
    context_class=dict,
    logger_factory=structlog.PrintLoggerFactory(),
    cache_logger_on_first_use=False,
)

log = structlog.get_logger()

log.msg("Usuário autenticado", user_id=42, username="joao")
log.msg("Pagamento processado", valor=150.50, status="sucesso")

A saída será clara e estruturada:

user_id=42 username='joao' event='Usuário autenticado'
valor=150.5 status='sucesso' event='Pagamento processado'

Contexto e variadics

O structlog permite vincular contexto que persiste através de chamadas de função. Isso é particularmente útil em requisições web ou processamentos que envolvem múltiplas funções.

import structlog

structlog.configure(
    processors=[
        structlog.processors.JSONRenderer()
    ],
    context_class=dict,
    logger_factory=structlog.PrintLoggerFactory(),
)

log = structlog.get_logger()

# Vincular contexto
context_log = log.bind(request_id="abc-123", user_id=7)

context_log.msg("Iniciando processamento")
context_log.msg("Validando dados")
context_log.msg("Salvando resultado")

# A saída será JSON com os mesmos campos em cada linha:
# {"request_id": "abc-123", "user_id": 7, "event": "Iniciando processamento"}
# {"request_id": "abc-123", "user_id": 7, "event": "Validando dados"}
# {"request_id": "abc-123", "user_id": 7, "event": "Salvando resultado"}

Processadores personalizados

Um dos diferenciais do structlog é a capacidade de criar processadores que transformam logs. Aqui criamos um processador que adiciona timestamp e filtra campos sensíveis.

import structlog
import json
from datetime import datetime

def adicionar_timestamp(logger, name, event_dict):
    """Adiciona timestamp ao log"""
    event_dict['timestamp'] = datetime.utcnow().isoformat()
    return event_dict

def remover_campos_sensiveis(logger, name, event_dict):
    """Remove senhas e tokens dos logs"""
    campos_sensiveis = ['password', 'token', 'api_key', 'credit_card']
    for campo in campos_sensiveis:
        if campo in event_dict:
            event_dict[campo] = '***REDACTED***'
    return event_dict

structlog.configure(
    processors=[
        adicionar_timestamp,
        remover_campos_sensiveis,
        structlog.processors.JSONRenderer()
    ],
    context_class=dict,
    logger_factory=structlog.PrintLoggerFactory(),
)

log = structlog.get_logger()

log.msg("Usuário fez login", user_email="teste@example.com", 
        password="minhasenha123")

# Saída:
# {"timestamp": "2024-01-12T14:30:45.123456", "user_email": "teste@example.com", "password": "***REDACTED***", "event": "Usuário fez login"}

Integração com logging nativo

O structlog pode ser configurado para funcionar sobre o módulo nativo logging do Python, permitindo beneficiar-se de ambos os mundos: a flexibilidade do structlog com a robustez do sistema padrão.

import structlog
import logging.config

# Configurar logging nativo primeiro
logging_config = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "json": {
            "()": structlog.stdlib.ProcessorFormatter,
            "processor": structlog.processors.JSONRenderer(),
        }
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "json",
        }
    },
    "root": {
        "handlers": ["console"],
        "level": "INFO",
    }
}

logging.config.dictConfig(logging_config)

# Configurar structlog para usar logging
structlog.configure(
    processors=[
        structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
    ],
    context_class=dict,
    logger_factory=structlog.stdlib.LoggerFactory(),
    cache_logger_on_first_use=True,
)

log = structlog.get_logger()
log.msg("Sistema iniciado com sucesso", versao="1.0.0")

Boas práticas em logging

Logging é uma das atividades mais importantes em desenvolvimento profissional, mas também uma das mais negligenciadas. Um bom sistema de logging permite que você entenda o que aconteceu em produção sem precisar de um debugger, economizando tempo e reduzindo riscos.

A primeira regra é: use nomes descritivos para loggers. Normalmente, você obtém um logger com o nome do módulo usando __name__. Isso cria uma hierarquia que facilita filtrar logs por componente. Além disso, sempre prefira usar variáveis com nomes significativos nos seus logs em vez de valores "mágicos" — isso ajuda na análise posterior.

Níveis apropriados para cada situação

Cada nível de log tem um propósito. Usar o nível errado torna impossível filtrar os logs relevantes. Aqui está uma guia de quando usar cada um:

import logging

logger = logging.getLogger(__name__)

# DEBUG: Informações úteis para diagnosticar problemas
# Use APENAS durante desenvolvimento/depuração
logger.debug(f"Consultando BD com query: SELECT * FROM users WHERE id={user_id}")

# INFO: Confirmação de que as coisas estão funcionando normalmente
# Use para eventos significativos mas esperados
logger.info(f"Usuário {user_id} fez login com sucesso")

# WARNING: Algo inesperado aconteceu ou pode indicar problema futuro
# Use quando algo não é erro ainda, mas requer atenção
logger.warning(f"Taxa de erro acima de 5%: {error_rate}%")

# ERROR: Um erro sério, uma função falhou
# Use quando a operação não pode ser completada
logger.error(f"Falha ao salvar usuário: {str(e)}", exc_info=True)

# CRITICAL: Erro muito sério, o programa pode não continuar
# Use raramente, quando o sistema está comprometido
logger.critical("Banco de dados indisponível, impossível continuar")

Evite antipadrões comuns

Um erro frequente é criar "logs mentirosos" — registros que não refletem o que realmente aconteceu. Também é comum logar informações sensíveis, como senhas ou tokens. E finalmente, muitos projetos sufocam o log com mensagens desnecessárias.

import logging
import re

logger = logging.getLogger(__name__)

# ❌ ERRADO: Sufocar com debug em produção
logger.debug(f"Iteração {i} do loop")  # Não faça isso em prod
logger.debug(f"Valor de x: {x}")       # Muito granular

# ✅ CORRETO: Log apenas de eventos significativos
logger.info("Processamento de arquivo iniciado")
logger.info(f"Linhas processadas: {total_linhas}")

# ❌ ERRADO: Logar dados sensíveis
usuario_payload = {"email": "user@example.com", "password": "abc123"}
logger.info(f"Recebido: {usuario_payload}")

# ✅ CORRETO: Sanitizar dados sensíveis
def sanitizar_payload(payload):
    payload_seguro = payload.copy()
    if 'password' in payload_seguro:
        payload_seguro['password'] = '***'
    return payload_seguro

logger.info(f"Recebido: {sanitizar_payload(usuario_payload)}")

# ❌ ERRADO: Mensagens vagas
logger.error("Falhou")

# ✅ CORRETO: Contexto suficiente para entender o problema
logger.error(
    "Falha ao processar pagamento",
    order_id=123,
    motivo="Gateway timeout após 30s",
    exc_info=True
)

Logging em aplicações web e assíncronas

Em aplicações que lidam com múltiplas requisições simultâneas, é crucial correlacionar logs de uma mesma requisição. Use request_id ou correlation_id para isso.

import structlog
import uuid
from fastapi import FastAPI, Request

app = FastAPI()

# Configurar structlog
structlog.configure(
    processors=[
        structlog.processors.JSONRenderer()
    ],
    context_class=dict,
    logger_factory=structlog.PrintLoggerFactory(),
)

log = structlog.get_logger()

@app.middleware("http")
async def adicionar_correlation_id(request: Request, call_next):
    # Gerar ou usar correlation_id existente
    correlation_id = request.headers.get("X-Correlation-ID", str(uuid.uuid4()))

    # Vincular ao contexto structlog
    contexto = structlog.contextvars.clear_contextvars()
    contexto.update(correlation_id=correlation_id)

    response = await call_next(request)
    return response

@app.get("/usuarios/{user_id}")
async def obter_usuario(user_id: int):
    bound_log = log.bind(user_id=user_id)

    bound_log.msg("Buscando usuário")
    # ... lógica ...
    bound_log.msg("Usuário encontrado", nome="João")

    return {"id": user_id, "nome": "João"}

# Cada requisição terá o mesmo correlation_id em todos os seus logs

Performance: Não calcule valores antes do log

Um erro comum é calcular valores antes de passá-los ao log, mesmo que o log possa ser ignorado. Use lazy evaluation quando possível.

import logging

logger = logging.getLogger(__name__)

# ❌ ERRADO: Calcula a string mesmo se debug está desativado
def processar_arquivo(dados_grandes):
    resumo = criar_resumo_custoso(dados_grandes)  # Custo alto!
    logger.debug(f"Dados processados: {resumo}")
    return dados_grandes

# ✅ CORRETO: Use %s com logging (mais eficiente)
logger.debug("Dados processados: %s", resumo)

# ✅ OU: Verifique o nível antes
if logger.isEnabledFor(logging.DEBUG):
    resumo = criar_resumo_custoso(dados_grandes)
    logger.debug(f"Dados processados: {resumo}")

# ✅ MELHOR: Com structlog, confie que o processador ignora levels
import structlog
log = structlog.get_logger()
log.debug("Processando", dados_grandes=dados_grandes)
# structlog otimiza internamente

Estruturar mensagens para análise

Quando seus logs vão para um sistema de análise (ELK, Datadog, etc.), a estrutura importa muito. Sempre use campos bem definidos e tipos consistentes.

import structlog
import json
from typing import Optional
from enum import Enum

class TipoEvento(str, Enum):
    LOGIN = "login"
    LOGOUT = "logout"
    ERRO_PAGAMENTO = "erro_pagamento"
    ACESSO_NEGADO = "acesso_negado"

structlog.configure(
    processors=[
        structlog.processors.JSONRenderer()
    ],
    context_class=dict,
    logger_factory=structlog.PrintLoggerFactory(),
)

log = structlog.get_logger()

def registrar_evento(
    tipo: TipoEvento,
    user_id: Optional[int] = None,
    motivo: Optional[str] = None,
    valor: Optional[float] = None,
):
    """
    Registra eventos de forma estruturada e consistente.
    Permite análise, alertas e correlação em ferramentas de observabilidade.
    """
    log.msg(
        "evento",
        event_type=tipo.value,
        user_id=user_id,
        motivo=motivo,
        valor=valor,
    )

# Uso
registrar_evento(TipoEvento.LOGIN, user_id=42)
registrar_evento(TipoEvento.ERRO_PAGAMENTO, user_id=42, valor=99.99, 
                 motivo="Cartão recusado")

Conclusão

Aprendemos neste artigo três lições fundamentais sobre logging profissional em Python. Primeiro, o módulo nativo logging oferece um sistema robusto e configurável que deve ser a base de qualquer aplicação séria — abandonar print() é um passo importante para a qualidade. Segundo, bibliotecas como structlog elevam o jogo ao oferecer contexto persistente e saída estruturada em JSON, essenciais para sistemas modernos de observabilidade. Terceiro, e mais importante, as boas práticas garantem que seus logs sejam úteis: use níveis corretos, evite dados sensíveis, mantenha correlação em requisições simultâneas, e estruture as mensagens para análise automatizada.

Referências


Artigos relacionados