DEV Community

O alerta que dizia Error: {}

O alerta que dizia Error: {}

Caiu um alerta avisando que uma integração tinha falhado. Fui ver o que era: Integration failed Error: {} Error: {}. Só isso. Duas chaves. O sistema avisou que algo quebrou e, no mesmo movimento, decidiu não contar o quê. E o pior é que o alerta funcionou. Disparou na hora certa, chegou onde devia, alguém leu. Cumpriu todas as etapas, menos a única que importava.

O reflexo aqui - e eu já fiz isso - é reprocessar o que falhou e tocar o dia. Deu certo, ninguém reclamou, bola pra frente. Só que tem uma conta que a gente não faz nessa hora: se o alerta não diz nada hoje, ele também não vai dizer nada da próxima vez. E vai ter próxima vez. Então vale parar e tratar o alerta vazio como o bug. Porque ele é.

Este texto tem duas partes. A primeira é por que isso acontece - e a resposta é mais irritante do que parece. A segunda é o tipo de bug que esse log costuma estar cobrindo, que no meu caso era um retry que eu jurava estar funcionando.

Por que a mensagem some

Cabe em duas linhas:

const err = new Error("timeout of 30000ms exceeded");
JSON.stringify(err); // '{}'

Não é bug do Node. Não é bug do seu logger. É a especificação da linguagem fazendo exatamente o que foi escrito pra fazer. JSON.stringify só serializa propriedades próprias e enumeráveis. E num Error, tanto message quanto stack são não-enumeráveis:

Object.keys(err); // []
Object.getOwnPropertyDescriptor(err, "message").enumerable; // false
Object.getOwnPropertyDescriptor(err, "stack").enumerable; // false

Object.keys num erro devolve array vazio. O objeto tem mensagem, tem stack trace, tem tudo - e do ponto de vista do JSON.stringify, está vazio.

Pausa: o que é "não-enumerável"? Toda propriedade em JavaScript carrega uma flag chamada enumerable, que responde uma pergunta só: "quando alguém percorrer as propriedades deste objeto, eu apareço na lista?" Não é sobre existir. É sobre aparecer quando alguém varre o objeto:

const user = { nome: "Ana" };
Object.defineProperty(user, "senha", {
  value: "123456",
  enumerable: false, // ← a única diferença
});

user.senha; // '123456' - existe e funciona normalmente
Object.keys(user); // ['nome'] - mas não aparece na lista
JSON.stringify(user); // '{"nome":"Ana"}'
"senha" in user; // true - e ainda assim está lá

A propriedade está no objeto. Ela só não se apresenta quando chamam a lista. Isso existe por um motivo razoável: se tudo fosse enumerável, um for...in qualquer listaria também toString, hasOwnProperty e toda a herança do objeto. Então a linguagem marca como não-enumerável o que é encanamento, não dado - e decidiu que message e stack são encanamento do Error.

O problema é quem segue essa regra:

vê enumeráveis vê não-enumeráveis
Object.keys()
for...in
JSON.stringify()
{...spread}
Object.getOwnPropertyNames()
acesso direto (err.message)

As quatro primeiras linhas explicam este artigo inteiro. E dá pra ver os dois mundos lado a lado no mesmo objeto:

Object.keys(err); // []
Object.getOwnPropertyNames(err); // ['stack', 'message']

Guarda essa tabela, porque ela volta a importar daqui a pouco.

O que torna isso especialmente cruel é que em todo lugar, menos no JSON, funciona. err.message te dá a mensagem. console.error(err) imprime o stack inteiro, bonitinho. Você testa no terminal, vê que está tudo lá, conclui que o log está bem. Aí vai pra produção, onde o log passa por JSON no caminho - e some. E some do jeito mais silencioso possível. Se virasse undefined, seu olho pegava. {} parece dado. Parece que tem alguma coisa ali.

Onde isso pega você

Quase ninguém escreve JSON.stringify(err) diretamente. O que a gente escreve é isto:

logger.error(
  JSON.stringify({
    message: "falha ao chamar serviço externo",
    orderId: order.id,
    provider: provider.name,
    error, // ← esse aqui
  })
);

Log estruturado, campos organizados, tudo certo. E o resultado é este:

JSON.stringify({ msg: "falhou", error: new Error("boom") });
// '{"msg":"falhou","error":{}}'

Repare: todo o resto serializou perfeitamente. O msg está lá, o orderId estaria lá, o provider também. O único campo que morreu foi justamente o que você abriria primeiro.

O caso pior é quando sobra alguma coisa

Se você usa axios - ou qualquer lib que pendura propriedades no erro - segura, que aqui piora:

const err = new Error("Request failed with status code 500");
err.code = "ERR_BAD_RESPONSE";
err.config = { url: "https://api.exemplo.com/pedidos" };

JSON.stringify(err);
// '{"code":"ERR_BAD_RESPONSE","config":{"url":"https://api.exemplo.com/pedidos"}}'

Olha o que aconteceu. code e config foram anexados depois que o erro nasceu - e atribuição normal (err.code = ...) cria a propriedade como enumerável, que é o padrão. Então elas sobrevivem. Já message veio de fábrica marcada como não-enumerável, e morre. Não é inconsistência da linguagem: é a mesma regra aplicada a duas propriedades que nasceram de jeitos diferentes.

Agora o log tem conteúdo. Tem código de erro, tem URL. Parece informativo. E não tem a mensagem. Isso é pior que o {} puro. O {} pelo menos grita que tem algo errado; esse aqui passa na sua frente e você segue em frente.

E antes que você pense "ah, mas eu uso classe de erro própria":

class AppError extends Error {
  constructor(message, code) {
    super(message);
    this.name = "AppError";
    this.code = code;
  }
}

JSON.stringify(new AppError("saldo insuficiente", "E_BALANCE"));
// '{"name":"AppError","code":"E_BALANCE"}'

Mesma história. name e code você atribuiu no construtor - sobrevivem. message veio do super() - morre. Você fica sabendo que foi um AppError de código E_BALANCE, e não fica sabendo que o saldo era insuficiente. Ou seja: praticamente todo erro de domínio que a gente escreve tem esse furo.

Spread e Object.assign não salvam

As duas primeiras coisas que a gente tenta:

JSON.stringify({ ...err }); // '{"code":"E_TIMEOUT"}'
JSON.stringify(Object.assign({}, err)); // '{"code":"E_TIMEOUT"}'

Os dois copiam só propriedades enumeráveis. Mesmo problema, mais teclas apertadas.

Se você usa Error.cause, ele vai junto

const inner = new Error("timeout of 30000ms exceeded");
const outer = new Error("falha ao processar pedido", { cause: inner });

JSON.stringify(outer);
// '{}'

Você encadeou os erros certinho pra não perder o contexto. A cadeia inteira evapora.

Como resolver

Serializando o erro na mão. A versão mínima:

const serializeError = (err) =>
  err instanceof Error
    ? { name: err.name, message: err.message, stack: err.stack }
    : String(err);

Aquele String(err) no final não é paranoia. Em JavaScript qualquer coisa pode ser lançada - uma string, um objeto de erro que veio da API de terceiro, um undefined. Se você assumir que sempre é Error, o dia em que não for você perde o log exatamente no incidente mais estranho. Que é justamente quando você mais precisava dele.

A versão que eu levaria pra produção também guarda as propriedades extras e a cadeia de causas:

const serializeError = (err) => {
  if (!(err instanceof Error)) return String(err);

  const out = {
    name: err.name,
    message: err.message,
    stack: err.stack,
  };

  // props que a lib pendurou (code, status, config...) - essas são enumeráveis
  for (const key of Object.keys(err)) out[key] = err[key];

  if (err.cause) out.cause = serializeError(err.cause);

  return out;
};

Agora sim:

const inner = new Error("timeout of 30000ms exceeded");
const outer = new Error("falha ao processar pedido", { cause: inner });
outer.code = "E_PEDIDO";

serializeError(outer);
// {
//   name: "Error",
//   message: "falha ao processar pedido",
//   stack: "Error: falha ao processar pedido\nat ...",
//   code: "E_PEDIDO",
//   cause: { name: "Error", message: "timeout of 30000ms exceeded", stack: "..." }
// }

Se você não confia em lembrar de chamar isso em todo log - eu não confio -, dá pra plugar globalmente com um replacer:

const replacer = (key, value) =>
  value instanceof Error ? serializeError(value) : value;

JSON.stringify({ msg: "falhou", error: err }, replacer);
// '{"msg":"falhou","error":{"name":"Error","message":"boom","stack":"..."}}'

Dá também pra definir um toJSON no seu erro de domínio, e aí o JSON.stringify passa a se comportar sozinho:

class AppError extends Error {
  toJSON() {
    return { name: this.name, message: this.message, stack: this.stack };
  }
}

JSON.stringify(new AppError("agora vai"));
// '{"name":"AppError","message":"agora vai","stack":"..."}'

Só que isso cobre os erros que você escreveu. O TypeError que o runtime lança e o erro que vem do axios continuam mudos. É complemento, não solução.

E se você usa pino ou winston: essas libs já vêm com serializer de erro (pino.stdSerializers.err, por exemplo). Vale conferir se está ativo e pra qual chave - costuma valer pra err, e um erro que você logou em error pode passar batido. É uma linha de config que resolve tudo isso. Se for o seu caso, você acabou de economizar uma tarde.

Beleza. Log consertado, mensagem aparecendo. Agora vem a parte que eu não esperava.

O retry que nunca aconteceu

Com o erro finalmente visível, o alerta seguinte veio assim:

timeout of 30000ms exceeded

Ótimo - agora dá pra investigar. Fui nos traces reconstruir a timeline, e o desenho que apareceu foi este (os tempos são ilustrativos; o que importa é o formato):

12:00:00.000 início da execução
12:00:00.050 chama a API externa → tentativa 1 do retry
12:00:30.000 timeout of 30000ms exceeded ← exatos 30s depois
12:00:30.001 "integration failed" ← 1 ms depois
12:00:30.080 "erro na chamada, tentativa 1/3" ← ...opa

Olha a última linha. O retry loga que a tentativa 1 falhou depois que o chamador já tinha desistido. Ele estava anunciando uma segunda tentativa que nunca ia acontecer.

A causa é a relação entre dois timeouts em saltos encadeados:

serviço A ──30s──▶ serviço B ──30s──▶ API externa

Os dois saltos com o mesmo timeout. E aqui está a pegadinha: os dois relógios começam juntos. Quando a API externa trava, a tentativa 1 estoura no limite - no mesmo instante em que o chamador lá de cima também estoura e derruba a conexão. O retry tinha maxRetries: 3 configurado, bonitinho, no lugar certo. E era decorativo. Não importava o número ali: a primeira tentativa consumia todo o orçamento de tempo do chamador. As tentativas 2 e 3 eram inalcançáveis por construção.

Esse é o tipo de bug que envelhece bem. Não aparece em dashboard nenhum: tem retry configurado, tem alerta disparando, tudo parece saudável. Só que o alerta chegava vazio - e ninguém tinha o menor motivo pra desconfiar do retry.

Se você guardar uma linha só deste texto, guarde esta:

tentativas × timeout_por_tentativa + delays < timeout de quem te chama

Se essa desigualdade não vale na sua stack, seu retry é enfeite.

E não, a correção não é aumentar o timeout

Foi a primeira coisa que me passou pela cabeça: dá mais tempo pro chamador, aí o retry cabe. Antes de mexer, fui olhar a distribuição real da chamada - coisa que qualquer APM entrega em dois cliques. O padrão que costuma aparecer em integração com API externa é este:

Métrica Tempo
p50 ~2s
p95 ~3s
p99 ~5s
max = o próprio timeout

Repare no formato, não nos números. 99% das chamadas legítimas terminam em poucos segundos. E aí tem um abismo entre o p99 e o máximo - não tem nada no meio do caminho. Aquele max não é uma chamada lenta: é uma chamada travada, cortada no teto.

Quando a distribuição tem essa cara, ela já respondeu a pergunta: ou a API responde rápido, ou ela trava de vez. Não existe meio-termo. E isso vira "aumentar o timeout" de cabeça pra baixo. Esperar mais não transforma falha em sucesso - só segura recurso por mais tempo numa requisição que já morreu. É literalmente o oposto do que um timeout existe pra fazer.

A correção é o contrário do instinto: encolher o orçamento de cada tentativa pra que todas caibam no teto que já existe. Com um chamador de 30s:

  • timeout por tentativa: 8s (~1,6× o p99 - folga sem exagero)
  • maxRetries: 3
  • delay entre tentativas: 2s
  • total = 3 × 8 + 2 × 2 = 28s < 30s do chamador ✓

Agora o retry funciona de verdade: tentativa 1 falha rápido, espera, tentativa 2 responde nos 2s de sempre (99% de chance), fluxo segue. E o melhor: nenhum timeout novo precisa ser criado. O default do framework continua lá, intacto. Só a chamada externa passa um timeout curto, sobrescrevendo pra ela mesma:

// em vez de mexer no timeout global do HttpModule
await this.http.post(url, body, { timeout: ATTEMPT_TIMEOUT_MS });

O que eu tirei disso

  • Log ruim não é dívida cosmética. É multiplicador do tempo de diagnóstico de todo incidente futuro naquela região do código. Um Error: {} pode segurar um bug estrutural por meses - e o custo não é o bug, é ninguém conseguir enxergar o bug.
  • Retry só é retry se o orçamento couber. Se o total do retry não é menor que o timeout de quem te chama, aquele maxRetries: 3 é enfeite de código. Dá pra conferir em cinco minutos, e a falha é silenciosa - ninguém vai te avisar.
  • Distribuição decide timeout, não intuição. Se o p99 e o max estão a duas ordens de grandeza de distância, você não tem chamada lenta: tem chamada travada. São problemas diferentes, e confundir os dois faz você aumentar exatamente o número que devia diminuir.

Cinco minutos pra checar na sua stack

  1. grep por JSON.stringify no código de log e de alerta. Todo objeto com erro dentro está mudo.
  2. Confere se o serializer de erro do seu logger está ativo - e pra qual chave.
  3. Soma o orçamento do seu retry (tentativas × timeout + delays) e compara com o timeout de quem chama.
  4. Olha o p99 e o max da sua chamada externa mais crítica. Muito distantes? Seu timeout provavelmente está calibrado pro caso errado.

Se você achar alguma dessas aí, me conta nos comentários. Tenho quase certeza de que não sou o único.

Todo o código deste artigo foi rodado e verificado em Node 20. Os tempos dos exemplos são ilustrativos: o que importa é o formato da distribuição.

Comments

No comments yet. Start the discussion.