Cover do episódio 101: Como aprendi sobre logging depois de não conseguir debugar em produção
#10116 de setembro, 20193 min leituraCódigo na PráticaS3 · 2018–2019

Como aprendi sobre logging depois de não conseguir debugar em produção

O bug estava em produção. Não tinha como reproduzir localmente. Não tinha log nenhum. Aprendi da pior forma possível que observabilidade não é opcional.

LoggingObservabilidadeDebugProdução

O sistema estava quebrando em produção.

Não sempre — só às vezes. Com certos clientes. Num intervalo que parecia aleatório.

Tentei reproduzir local. Não consegui. Tentei com os dados do cliente de teste. Não acontecia.

O código estava em produção sem nenhum log. Sem nenhuma mensagem estruturada. A única coisa que eu tinha eram os prints de erro que o próprio Python gerava quando a exceção não era tratada — stack trace puro no stderr de um servidor que eu não tinha acesso direto.

O cliente abria ticket. Eu ficava cego.


Isso acontece com frequência no começo da carreira porque logging parece burocrático quando você está escrevendo o código.

Você sabe o que o código faz. Você pode rodar local. Você pode usar o debugger. Para quê adicionar linhas de log?

Para quando você não puder rodar local. Para quando o bug só acontece em produção com dado real. Para quando for meia-noite e você precisar entender o que aconteceu sem conseguir conectar um debugger no servidor de produção.


O que mudou na minha abordagem:

import logging

logger = logging.getLogger(__name__)

def process_lead(lead_data: dict) -> dict:
    logger.info("processing lead", extra={"lead_id": lead_data.get("id"), "source": lead_data.get("source")})
    
    try:
        result = transform_fields(lead_data)
        logger.debug("fields transformed", extra={"output_keys": list(result.keys())})
        return result
    except KeyError as e:
        logger.error("missing required field", extra={"field": str(e), "lead_id": lead_data.get("id")})
        raise

Não é complexo. É a diferença entre "algo falhou" e "o lead com ID 4821 vindo do source 'crm-api' falhou porque o campo 'email' estava ausente".

Com o segundo, você tem direção. Com o primeiro, você tem nada.


Os três níveis que aprendi a usar:

  • DEBUG — o que você quer saber enquanto desenvolve (entra em produção em nível INFO ou acima, não gera ruído)
  • INFO — o que importa registrar sobre o fluxo normal (request chegou, processamento concluído, resultado enviado)
  • ERROR — o que falhou, com contexto suficiente para investigar

A regra prática: se você adicionaria um print temporário para entender o código, aquilo deveria ser um DEBUG permanente. Em vez de tirar o print depois de debugar, converte para logger.debug e mantém.


O bug de setembro de 2019 era um campo opcional do CRM que às vezes vinha como null e às vezes não vinha na resposta. O código assumia que sempre estava lá.

Se eu tivesse logado o payload completo na entrada com nível DEBUG, teria resolvido em 20 minutos. Levou três dias de conversa com o cliente tentando reproduzir o cenário.

Log não é debug — é memória do sistema. E sistema sem memória é sistema cego.