Logs que não mentem: wide events e um evento por request
TL;DR - Um evento rico por request (wide event) com contexto de negócio, em vez de N linhas; tail sampling para custo controlado. Referência: Logging Sucks.
Já perdi tempo grepando em log pra descobrir por que um checkout falhou ou por que o p99 subiu de madrugada. O problema não é só volume: os logs foram pensados para escrever, não para consultar. Um request passa por vários serviços, banco, cache, fila, e o que sobra são dezenas de linhas por request, cada uma com um pedacinho de contexto. Quando dá problema, falta justamente o contexto reunido.
A virada: “o que aconteceu” em vez de “o que o código fez”
O site Logging Sucks (Boris Tane) condensa bem a mudança de mentalidade. Em vez de logar “o que meu código fez”, logar “o que aconteceu com este request”. Em vez de várias linhas por hop, um único evento largo (wide event) por serviço, com tudo que pode importar pra debug:
request_id,trace_id, método, path, status, duração- usuário (id, plano, LTV), carrinho, pagamento
- erro (tipo, código, retriable), feature flags
Um evento por request como registro canônico do que aconteceu.
flowchart TB
subgraph antigo[" Modelo antigo "]
R[Request] --> L1[log 1]
R --> L2[log 2]
R --> L3[log N...]
end
subgraph wide[" Wide event "]
R2[Request] --> E[1 evento rico]
end
Buscar por user_id ou request_id devolve um único registro com dimensões suficientes pra entender o caso. Não é mais busca em texto; é query em dados estruturados. Alta cardinalidade (user_id, request_id) e alta dimensionalidade (muitos campos) é o que torna o log útil. OpenTelemetry ajuda no transporte e no trace, mas não decide o que logar nem injeta contexto de negócio; isso continua sendo decisão de instrumentação.
Na prática: construir o evento e controlar custo
Eu construo o evento ao longo do request: o middleware inicia com request_id, method, path, service etc.; o handler enriquece com user, cart, payment, error. No final, emito uma vez.
Para não explodir custo, uso tail sampling: guardar 100% de erros e de requests lentos (acima do p99) e amostrar o resto (por exemplo 5%). O que importa fica guardado e a conta fica previsível.
Caso real: ETL em Python
Apliquei isso numa pipeline ETL em Python que escala até 20 instâncias com múltiplas threads. Antes, cada execução (por exemplo da tabela CADIVEND) gerava várias linhas:
[2025-11-18T14:32:01.123Z] run_id=etl_8f7a2b3c table=CADIVEND thread_id=worker-3 status=running etapa=início
[2025-11-18T14:32:03.123Z] run_id=etl_8f7a2b3c table=CADIVEND thread_id=worker-3 status=running etapa=session_open duration_stage_ms=2000
[2025-11-18T14:32:04.123Z] run_id=etl_8f7a2b3c table=CADIVEND thread_id=worker-3 status=running etapa=read_parquet parquet_count=25 duration_stage_ms=1000
[2025-11-18T14:32:42.123Z] run_id=etl_8f7a2b3c table=CADIVEND thread_id=worker-3 status=running etapa=write_iceberg duration_stage_ms=38000
[2025-11-18T14:32:43.123Z] run_id=etl_8f7a2b3c table=CADIVEND thread_id=worker-3 status=running etapa=session_close duration_stage_ms=1000
[2025-11-18T14:32:46.123Z] run_id=etl_8f7a2b3c table=CADIVEND status=success etapa=finalizado duration_ms=45000
Se falhasse no meio, apareciam os passos até ali. Com 20 instâncias e várias threads, o volume explodia e ficava chato filtrar sucesso vs erro e achar a tabela ou o job que quebrou.
Mudei para um único log por execução: um evento com tabela, instância, thread_id, duração total, duração por etapa (sessão, leitura parquet, escrita Iceberg, fechamento), quantidade de parquets lidos, status (success/failed) e, em caso de erro, etapa que falhou e mensagem. Uma linha por run. Reduziu bastante a quantidade de logs, facilitou monitorar erros e sucessos (um filtro por status e por tabela resolve) e o debug ganhou um único registro com todo o contexto daquela execução.
Exemplo: evento em sucesso
{
"timestamp": "2025-11-18T14:32:01.123Z",
"run_id": "etl_8f7a2b3c",
"table": "CADIVEND",
"instance_id": "i-0a1b2c3d",
"thread_id": "worker-3",
"status": "success",
"duration_ms": 45000,
"stages_ms": {
"session_open": 2000,
"read_parquet": 1000,
"write_iceberg": 38000,
"session_close": 1000
},
"parquet_count": 25
}
Exemplo: evento em falha (ex.: escrita Iceberg)
{
"timestamp": "2025-11-18T14:35:22.456Z",
"run_id": "etl_9x8w7v6u",
"table": "CADIVEND",
"instance_id": "i-0a1b2c3d",
"thread_id": "worker-7",
"status": "failed",
"failed_stage": "write_iceberg",
"duration_ms": 23000,
"stages_ms": {
"session_open": 2000,
"read_parquet": 1000,
"write_iceberg": 20000
},
"parquet_count": 25,
"error": {
"type": "CommitFailedException",
"message": "Conflict with concurrent commit",
"retriable": true
}
}
O que levar daqui
- Um evento rico por request (ou por unidade de trabalho) em vez de N linhas fragmentadas.
- Contexto de negócio no evento: user, cart, payment, tabela ETL, etapa. Não só request_id e status.
- Tail sampling para manter custo sob controle: 100% de erros e lentos, amostra do resto.
- Query estruturada: buscar por
user_id,request_id,table,statuse ter um único registro com o que importa.
Log que não mente é log que você consegue usar.