DEV Community

Cover image for Debugando um incidente real - métricas, logs e traces juntos na prática
Rafael Dutra for apsis-cc

Posted on

Debugando um incidente real - métricas, logs e traces juntos na prática

1. Retomando: chegou a hora de usar a stack de verdade

Ao longo desta série, a stack cresceu peça por peça: métricas (artigos 2 e 3), logs (artigo 4), traces (artigo 5), tudo unificado em Docker Compose (artigo 6) e visualizado em dashboards (artigo 7). Este último artigo inverte o roteiro: em vez de adicionar mais uma peça, vamos quebrar a mini app PHP de propósito e usar a stack inteira — dashboard, logs e traces — para investigar o problema do zero, como em um incidente real.

2. Simulando o problema

No app.php construído no artigo 3, uma mudança pequena e deliberada introduz um bug de performance: uma fração dos pedidos passa a demorar muito mais que o normal, e uma fração menor passa a falhar de verdade.

// dentro do processamento do pedido, logo apos $state['queue_size']++
if (random_int(1, 100) <= 15) {
    // simula uma dependencia externa lenta (ex.: um servico de pagamento)
    usleep(random_int(2_000_000, 4_000_000)); // 2-4 segundos, bem acima do normal
}

if (random_int(1, 100) <= 5) {
    http_response_code(500);
    logToLoki("falha ao processar pedido: timeout no servico de pagamento", "error");
    $state['queue_size']--;
    writeState($stateFile, $state);
    echo "erro interno\n";
    exit;
}
Enter fullscreen mode Exit fullscreen mode

Essa mudança fica no ar, e a investigação a seguir segue exatamente o caminho que alguém sem acesso a este código-fonte teria: só olhando para o que a stack de observabilidade mostra.

3. Passo 1: o dashboard aponta o sintoma

Gerando tráfego contínuo contra a mini app PHP e observando o dashboard construído no artigo 7 (com a variável $app em php-app), dois painéis mudam de forma visível:

  • O painel de latência p50/p95/p99 mostra o p50 relativamente estável, mas o p95 e p99 disparando bem acima — o padrão clássico de "uma minoria de requisições muito mais lentas que a maioria", coerente com os 15% de chance de lentidão introduzidos no passo anterior.
  • O painel de volume de erros por minuto (baseado em count_over_time sobre logs com level="error") sai de zero e passa a mostrar uma taxa constante de erros.

Neste ponto, o dashboard já respondeu a primeira pergunta — "algo está errado, e é especificamente na mini app PHP" — mas não o "por quê". Essa é a fronteira natural entre o que métricas conseguem responder sozinhas e onde é preciso descer um nível.

4. Passo 2: os logs explicam o erro

Voltando ao painel de logs do dashboard (ou ao Explore, filtrando diretamente):

{app="php-app", level="error"}
Enter fullscreen mode Exit fullscreen mode

A mensagem falha ao processar pedido: timeout no servico de pagamento aparece repetida, associada aos horários em que o painel de erro subiu. Já é uma pista concreta — não é um erro genérico de PHP, é um erro específico de negócio, com uma causa nomeada no próprio texto do log (o "serviço de pagamento"). Mas o log sozinho não diz quanto tempo foi gasto antes do erro acontecer, nem se as requisições lentas (vistas no painel de latência) são o mesmo fenômeno que as requisições que falham, ou dois problemas diferentes acontecendo ao mesmo tempo.

5. Passo 3: os traces confirmam onde o tempo foi gasto

Com a instrumentação dos artigos 5 e 6, cada requisição gera um span process_order. Consultando os logs do coletor OpenTelemetry (ou, em uma stack com backend de tracing dedicado, navegando visualmente pela árvore de spans) durante o mesmo intervalo de tempo do pico visto no dashboard:

docker compose logs otel-collector --since 5m | grep -A 5 process_order
Enter fullscreen mode Exit fullscreen mode

Os spans capturados no período do incidente mostram uma duração (end_time - start_time) concentrada em dois grupos bem separados: a maioria na faixa de dezenas de milissegundos (comportamento normal) e um grupo secundário na faixa de 2 a 4 segundos — exatamente a faixa introduzida artificialmente na simulação. O atributo order.duration_ms (adicionado ao span no artigo 5) confirma numericamente essa distribuição bimodal em cada span individual, span a span, algo que nem o painel de latência agregada (que mostra percentis, não casos individuais) nem o log de erro (que só aparece nos 5% que efetivamente falham, não nos 15% que só ficam lentos) conseguiam mostrar isoladamente.

6. Juntando as três pontas

A investigação completa, remontada:

  1. Métricas apontaram que algo mudou e quando — p95/p99 subindo, taxa de erro saindo de zero — sem precisar que ninguém soubesse previamente que aquele problema existia (exatamente a definição de observabilidade do artigo 1: responder a uma pergunta não antecipada).
  2. Logs explicaram o quê estava falhando, com uma mensagem específica de negócio ("timeout no serviço de pagamento"), restrita rapidamente pelos labels app e level graças ao modelo de indexação do Loki (artigo 4).
  3. Traces confirmaram onde, dentro da requisição, o tempo estava de fato sendo gasto, com granularidade por requisição individual — não apenas em agregado — e conectaram as requisições lentas (visíveis só na cauda do histograma) às requisições que geravam log de erro.

Nenhum dos três pilares sozinho reconstrói essa história completa: métricas sem logs mostram que algo mudou, mas não por quê; logs sem métricas exigiriam vasculhar volume gigantesco de texto sem saber onde procurar primeiro; traces sem os outros dois não teriam sido acionados a tempo, já que ninguém estaria olhando spans individuais sem antes ver o dashboard disparar.

7. Conclusão da série

Ao longo desses oito artigos, esta série construiu uma stack de observabilidade completa a partir do zero: o que são métricas, logs e traces e por que nenhum substitui os outros dois; Prometheus coletando métricas via scraping de duas mini aplicações reais, em Python e PHP puros; Loki recebendo logs via API HTTP, com um modelo de indexação deliberadamente mais barato que ferramentas tradicionais; OpenTelemetry como padrão neutro para gerar traces, primeiro isolado, depois unificado via um coletor OTLP; dashboards no Grafana combinando PromQL e LogQL; e, neste último artigo, os três pilares trabalhando juntos para investigar um incidente simulado do sintoma até a causa raiz. A stack construída aqui é deliberadamente mínima — sem alta disponibilidade, sem retenção de longo prazo configurada, sem backend de tracing visual — mas os conceitos e o fluxo de investigação são exatamente os mesmos usados em stacks de observabilidade de produção, em qualquer escala.


Imagem de capa: Logo oficial do Prometheus — repositório prometheus/prometheus, licença Apache 2.0 (convertido para PNG via wsrv.nl)

Referências:

  1. OpenTelemetry — Observability Primer
  2. Google SRE Book — Monitoring Distributed Systems
  3. Prometheus — Querying Basics
  4. Grafana Loki — LogQL

Top comments (0)