Depurar por evidência e revisar por risco

Caso real: o serviço que morria a cada 40 horas

Estudo de caso 13 min de leitura

Um vazamento de memória investigado do zero: o que os gráficos mostravam, as três hipóteses, o experimento que fechou o caso e a correção de duas linhas.

O worker de processamento de pedidos era reiniciado pelo orquestrador a cada 40 horas, mais ou menos. Ninguém tinha percebido: o reinício era automático, a fila era retomada, e nenhum pedido se perdia. Até o dia em que dois workers reiniciaram juntos no pico.

Ao final desta aula você consegue

Aplicar a tabela de hipóteses a um problema sem stack trace.
Ver como um sintoma "sem erro nenhum" é diagnosticado.
Reconhecer o padrão de acúmulo por referência retida.

O que se sabia

Uso de memória do processo subia de forma linear e constante, ~90 MB por hora.
Nenhum erro nos logs. Nenhuma exceção. O processo era morto, não quebrava.
Reiniciar zerava e o ciclo recomeçava idêntico.
O volume de jobs por hora era estável — o crescimento não acompanhava carga.
Node 18, worker consumindo uma fila, ~3 mil jobs/hora.

Crescimento linear e independente do volume é a assinatura mais informativa aqui. Se fosse cache sem limite, cresceria com a variedade dos dados. Se fosse carga, acompanharia o volume. Linear e constante aponta para algo que acontece uma vez por unidade de trabalho e nunca é desfeito.

A abertura da investigação

Não conclua a causa. Monte a tabela de hipóteses.

Sintoma: processo Node 18 (worker de fila) cresce ~90 MB/h de forma linear
e é morto por OOM a cada ~40h. Sem erro nos logs, sem exceção.
Reiniciar zera e o padrão se repete idêntico.

Dados: ~3 mil jobs/hora, volume estável. O crescimento NÃO acompanha
variação de carga — sobe igual em hora cheia e hora vazia.

Colunas: hipótese | a favor | contra | experimento mínimo | custo |
o que elimina se der negativo. Ordene por (elimina ÷ custo).

Você escreveu

[prompt acima]

A IA respondeu

H1 — Referência retida por listener não removido (alta)
A favor: crescimento linear por unidade de trabalho, independente de carga;
listeners acumulam um por job e retêm o closure inteiro.
Contra: normalmente o Node emite MaxListenersExceededWarning — o relato
não menciona esse aviso.
Experimento: logar emitter.listenerCount() a cada 100 jobs. Custo: 15 min.
Se crescer, é isso.

H2 — Cache ou Map global sem limite (média)
A favor: também produz crescimento monotônico.
Contra: cresceria com a VARIEDADE das chaves, não linearmente com o tempo;
em volume estável com dados repetidos, tenderia a estabilizar.
Experimento: logar .size dos Maps de módulo. Custo: 15 min.

H3 — Timer não limpo (média-baixa)
A favor: setInterval por job retém o callback.
Contra: costuma aparecer também como aumento de CPU, não relatado.
Experimento: contar handles ativos com process._getActiveHandles().length.
Custo: 10 min.

H4 — Vazamento em dependência nativa (baixa)
Contra: heap do processo cresce; vazamento nativo geralmente aparece em RSS
sem crescimento correspondente no heap. Confirmar qual métrica foi observada.
Experimento: comparar heapUsed com RSS. Custo: 5 min — FAÇA ESTE PRIMEIRO,
é o mais barato e separa dois mundos.

O que ler nessa resposta

O assistente reordenou por conta própria e apontou o experimento de 5 minutos como primeiro. Foi a instrução "elimina ÷ custo" funcionando.
A observação contra na H1 é honesta e correta: a ausência do aviso de listeners é evidência real contra a hipótese mais provável. Uma resposta ancorada teria omitido isso.
A distinção entre heapUsed e RSS na H4 é a diferença entre investigar JavaScript e investigar código nativo — dois caminhos completamente distintos.
Nenhuma correção foi proposta. A tabela é o entregável desta etapa.

Os experimentos, em ordem

Instrumentação temporária — 20 linhas, removidas depoisjavascript

let jobs = 0;

function diagnostico() {
  const m = process.memoryUsage();
  console.log(JSON.stringify({
    jobs,
    rssMB: Math.round(m.rss / 1048576),
    heapMB: Math.round(m.heapUsed / 1048576),
    handles: process._getActiveHandles().length,
    listenersPedido: eventos.listenerCount('pedido:processado'),
  }));
}

fila.on('job:done', () => { if (++jobs % 100 === 0) diagnostico(); });

A saída depois de duas horastext

{"jobs":100,  "rssMB":142, "heapMB":98,  "handles":8, "listenersPedido":103}
{"jobs":1000, "rssMB":168, "heapMB":124, "handles":8, "listenersPedido":1003}
{"jobs":3000, "rssMB":221, "heapMB":177, "handles":8, "listenersPedido":3003}
{"jobs":6000, "rssMB":301, "heapMB":257, "handles":8, "listenersPedido":6003}

Três leituras decidem o caso: heap acompanha RSS (elimina H4), handles constante (elimina H3), e listenersPedido igual ao número de jobs (confirma H1).

A causa

O código que vazava

async function processarPedido(job) {
  const contexto = await carregarContexto(job.pedidoId);

  eventos.on('pedido:processado', () => {
    metricas.registrar(contexto);        // ← retém o contexto inteiro
  });

  await executar(job, contexto);
  eventos.emit('pedido:processado');
}

Um listener novo por job, nunca removido. Cada um retém o contexto daquele pedido — e o contexto trazia os itens e o cliente. ~30 KB × 3 mil jobs/hora = os 90 MB/h observados.

A correção

async function processarPedido(job) {
  const contexto = await carregarContexto(job.pedidoId);

  eventos.once('pedido:processado', () => {
    metricas.registrar(contexto);
  });

  await executar(job, contexto);
  eventos.emit('pedido:processado');
}

once remove o listener após disparar. A memória passou a estabilizar em ~150 MB.

A diferença: Duas letras de diferença. Foram três horas de investigação para chegar a elas — e teriam sido três dias sem a tabela ordenada por custo.

Por que o aviso do Node não apareceu

A dúvida levantada na coluna "contra" da H1 tinha resposta: o projeto chamava setMaxListeners(0) na inicialização, herdado de um problema antigo. Isso desligou exatamente o aviso que teria denunciado o vazamento no primeiro dia.

Vale como lição separada: silenciar um aviso resolve o incômodo e apaga o sensor. Quando o alerta voltar a ser necessário, ele não estará lá.

O que trava a correção

Teste de regressão sem esperar 40 horasjavascript

test('nao acumula listeners entre jobs', async () => {
  const antes = eventos.listenerCount('pedido:processado');

  for (let i = 0; i < 50; i++) {
    await processarPedido({ pedidoId: i });
  }

  expect(eventos.listenerCount('pedido:processado')).toBe(antes);
});

O teste não mede memória — mede a causa. Testes de memória são lentos e instáveis; contar listeners é instantâneo e determinístico.

ArmadilhaVazamento não dá stack trace

Toda a rotina de depuração que depende de mensagem de erro é inútil aqui. Não há linha culpada, não há exceção, e o processo morre por decisão do sistema operacional ou do orquestrador — longe do código que causou.

Por isso a instrumentação vem antes da hipótese refinada: sem número, a conversa vira especulação sobre o que "poderia" estar acumulando.

Como perceber: Reinício periódico aceito como normal é quase sempre um vazamento que ninguém investigou.

Checagem antes de seguir

O experimento mais barato foi o primeiro.
A instrumentação produziu números, não impressões.
Cada número eliminou pelo menos uma hipótese.
A correção explica o mecanismo e a taxa observada.
O teste de regressão mede a causa, não o sintoma.

Em uma frase

Sem erro nos logs, a investigação começa por instrumentar e medir — hipótese sem número é conversa.

← Aula anterior Próxima aula →

Comentários e dúvidas

Inscreva-se grátis para comentar, tirar dúvidas, marcar seu progresso e emitir o certificado ao fim do curso.

Inscrever-se grátis com Google

Ainda não há comentários nesta aula.