Logging no Node.js e Express: logs estruturados, correlação e níveis

O que é logging estruturado e por que usar JSON

Logging estruturado é a prática de registrar eventos como objetos com campos bem definidos (em vez de frases soltas). Em Node.js/Express, o formato mais comum é JSON, porque facilita: busca e filtros (por requestId, level, route), agregação (contar erros por endpoint), correlação (seguir uma requisição ponta a ponta) e análise automática (dashboards, alertas).

Um log estruturado típico contém: timestamp, level, message e um bloco de contexto (metadados) como service, env, requestId, method, path, statusCode, latencyMs e, quando aplicável, traceId.

Níveis de log e quando usar cada um

Padronizar níveis evita ruído e melhora a triagem. Uma convenção prática:

• fatal: o processo não consegue continuar (ex.: falha ao subir dependência crítica).
• error: falha de uma operação (ex.: exceção, chamada externa retornou 500).
• warn: comportamento inesperado, mas recuperável (ex.: timeout intermitente, validação rejeitada em volume alto).
• info: eventos de negócio e ciclo de requisição (ex.: request finalizada, job iniciado).
• debug: detalhes para desenvolvimento/diagnóstico (ex.: payloads resumidos, decisões internas).
• trace: altíssimo volume, normalmente desabilitado em produção.

Regra prática: em produção, mantenha info e acima; habilite debug temporariamente para incidentes, com amostragem.

Campos padronizados: contrato do log

Defina um “contrato” de campos para todos os serviços. Isso reduz ambiguidade e permite consultas consistentes. Um conjunto mínimo recomendado:

Continue em nosso aplicativo e ...

• Ouça o áudio com a tela desligada
• Ganhe Certificado após a conclusão
• + de 5000 cursos para você explorar!

ou continue lendo abaixo...

Baixar o aplicativo

• timestamp: ISO 8601.
• level: string (info, warn, error...).
• message: descrição curta.
• service: nome do serviço (ex.: billing-api).
• env: ambiente (ex.: production, staging).
• requestId: id único por requisição HTTP.
• traceId: id de rastreamento distribuído (quando existir).
• method, path: dados da rota.
• statusCode: status da resposta.
• latencyMs: tempo total de resposta.
• error: objeto com detalhes (nome, mensagem, stack, código).

Passo a passo: logger JSON com contexto e níveis (TypeScript)

1) Criar um logger simples e estruturado

Abaixo está um logger minimalista que escreve JSON no stdout. Em produção, isso é suficiente para a maioria dos coletores de logs (que capturam stdout/stderr). O foco aqui é padronizar campos e permitir contexto.

type LogLevel = 'fatal' | 'error' | 'warn' | 'info' | 'debug' | 'trace';

const levelPriority: Record<LogLevel, number> = {
  fatal: 60,
  error: 50,
  warn: 40,
  info: 30,
  debug: 20,
  trace: 10,
};

export type LogContext = {
  service: string;
  env: string;
  requestId?: string;
  traceId?: string;
  method?: string;
  path?: string;
  statusCode?: number;
  latencyMs?: number;
  userId?: string;
  [key: string]: unknown;
};

export type LogError = {
  name?: string;
  message?: string;
  stack?: string;
  code?: string;
};

export class Logger {
  constructor(
    private base: Pick<LogContext, 'service' | 'env'>,
    private minLevel: LogLevel = 'info'
  ) {}

  child(extra: LogContext) {
    return new ChildLogger(this, extra);
  }

  log(level: LogLevel, message: string, ctx: LogContext = {}, err?: unknown) {
    if (levelPriority[level] < levelPriority[this.minLevel]) return;

    const error = err ? normalizeError(err) : undefined;

    const entry = {
      timestamp: new Date().toISOString(),
      level,
      message,
      ...this.base,
      ...ctx,
      ...(error ? { error } : {}),
    };

    const line = JSON.stringify(entry);

    if (levelPriority[level] >= levelPriority.error) {
      process.stderr.write(line + '\n');
    } else {
      process.stdout.write(line + '\n');
    }
  }

  info(message: string, ctx?: LogContext) { this.log('info', message, ctx); }
  warn(message: string, ctx?: LogContext) { this.log('warn', message, ctx); }
  error(message: string, ctx?: LogContext, err?: unknown) { this.log('error', message, ctx, err); }
  debug(message: string, ctx?: LogContext) { this.log('debug', message, ctx); }
}

class ChildLogger {
  constructor(private parent: Logger, private extra: LogContext) {}
  info(message: string, ctx: LogContext = {}) { this.parent.info(message, { ...this.extra, ...ctx }); }
  warn(message: string, ctx: LogContext = {}) { this.parent.warn(message, { ...this.extra, ...ctx }); }
  error(message: string, ctx: LogContext = {}, err?: unknown) { this.parent.error(message, { ...this.extra, ...ctx }, err); }
  debug(message: string, ctx: LogContext = {}) { this.parent.debug(message, { ...this.extra, ...ctx }); }
}

function normalizeError(err: unknown): LogError {
  if (err instanceof Error) {
    const anyErr = err as any;
    return {
      name: err.name,
      message: err.message,
      stack: err.stack,
      code: typeof anyErr.code === 'string' ? anyErr.code : undefined,
    };
  }
  return { message: String(err) };
}

Esse logger já entrega: JSON consistente, níveis, separação stdout/stderr e suporte a contexto via child().

2) Configurar base do serviço e nível mínimo por ambiente

import { Logger } from './logger';

const service = process.env.SERVICE_NAME ?? 'orders-api';
const env = process.env.NODE_ENV ?? 'development';

const minLevel = (env === 'production') ? 'info' : 'debug';

export const logger = new Logger({ service, env }, minLevel);

Correlação por requisição: requestId e traceId

Correlação é a capacidade de ligar todos os logs gerados durante uma requisição. O campo mais importante é requestId. Se você também usa tracing distribuído, inclua traceId (por exemplo, vindo de um header de trace).

Passo a passo: middleware de requestId + logger por request

O middleware abaixo: gera (ou reaproveita) um requestId, captura traceId se existir, cria um logger “filho” com contexto fixo e o disponibiliza em req.log.

import type { Request, Response, NextFunction } from 'express';
import crypto from 'crypto';
import { logger } from './logger-instance';

declare global {
  namespace Express {
    interface Request {
      requestId?: string;
      traceId?: string;
      log?: ReturnType<typeof logger.child>;
    }
  }
}

function getHeader(req: Request, name: string) {
  const v = req.header(name);
  return v && v.trim() ? v.trim() : undefined;
}

export function requestContextMiddleware(req: Request, res: Response, next: NextFunction) {
  const incomingRequestId = getHeader(req, 'x-request-id');
  const requestId = incomingRequestId ?? crypto.randomUUID();

  const traceId = getHeader(req, 'traceparent') ?? getHeader(req, 'x-trace-id');

  req.requestId = requestId;
  req.traceId = traceId;

  res.setHeader('x-request-id', requestId);

  req.log = logger.child({
    requestId,
    traceId,
    method: req.method,
    path: req.path,
  });

  next();
}

Boas práticas: sempre devolver x-request-id na resposta e aceitar um x-request-id de entrada para manter correlação entre serviços.

Integrando ao ciclo do Express: logs de início/fim e latência

Um padrão eficiente é registrar um log ao finalizar a resposta, com statusCode e latencyMs. Isso cria um “access log” estruturado, mais útil que o formato textual tradicional.

Passo a passo: middleware de medição de tempo e log de request finalizada

import type { Request, Response, NextFunction } from 'express';

export function httpLoggingMiddleware(req: Request, res: Response, next: NextFunction) {
  const start = process.hrtime.bigint();

  res.on('finish', () => {
    const end = process.hrtime.bigint();
    const latencyMs = Number(end - start) / 1_000_000;

    const statusCode = res.statusCode;
    const level = statusCode >= 500 ? 'error' : statusCode >= 400 ? 'warn' : 'info';

    req.log?.[level]('http_request_completed', {
      statusCode,
      latencyMs: Math.round(latencyMs * 100) / 100,
      contentLength: res.getHeader('content-length'),
      userAgent: req.header('user-agent'),
    });
  });

  next();
}

Detalhes importantes: finish dispara quando a resposta foi enviada; hrtime.bigint() é preciso e não depende de relógio do sistema. O nível do log pode variar conforme o statusCode.

Ordem de middlewares

Regra prática: primeiro contexto (requestId), depois logging HTTP, depois rotas.

import express from 'express';
import { requestContextMiddleware } from './request-context-middleware';
import { httpLoggingMiddleware } from './http-logging-middleware';

const app = express();

app.use(requestContextMiddleware);
app.use(httpLoggingMiddleware);

app.get('/health', (req, res) => {
  req.log?.debug('health_check');
  res.json({ ok: true });
});

Logs de erro ricos: capturando exceções com contexto

Para depuração, um log de erro precisa de: requestId, rota, status, e detalhes do erro (name, message, stack, e um code quando existir). Evite registrar o corpo completo da requisição sem sanitização.

Passo a passo: middleware de erro do Express com log estruturado

import type { Request, Response, NextFunction } from 'express';

export function errorHandler(err: unknown, req: Request, res: Response, next: NextFunction) {
  // Se headers já foram enviados, delegue para o handler padrão
  if (res.headersSent) return next(err);

  // Defina um status apropriado (exemplo simples)
  const statusCode = 500;

  req.log?.error('unhandled_error', {
    statusCode,
    route: req.route?.path,
  }, err);

  res.status(statusCode).json({
    error: 'internal_server_error',
    requestId: req.requestId,
  });
}

Esse padrão garante que o cliente receba o requestId para reportar o incidente, e você consiga localizar rapidamente os logs correlacionados.

Redução de ruído: o que logar (e o que não logar)

1) Redação de dados sensíveis (redaction)

Evite registrar segredos e dados pessoais. Em vez de “não logar nada”, aplique redação em campos conhecidos. Exemplo: mascarar authorization, cookie, password, token, cpf, cardNumber.

const SENSITIVE_KEYS = new Set([
  'authorization', 'cookie', 'set-cookie',
  'password', 'token', 'accessToken', 'refreshToken',
  'cpf', 'cardNumber', 'cvv'
]);

function redactObject(input: unknown): unknown {
  if (!input || typeof input !== 'object') return input;
  if (Array.isArray(input)) return input.map(redactObject);

  const obj = input as Record<string, unknown>;
  const out: Record<string, unknown> = {};

  for (const [k, v] of Object.entries(obj)) {
    if (SENSITIVE_KEYS.has(k.toLowerCase())) {
      out[k] = '[REDACTED]';
    } else {
      out[k] = redactObject(v);
    }
  }
  return out;
}

// Uso: req.log?.info('event', { headers: redactObject(req.headers) as any });

Prefira registrar apenas subconjuntos úteis (ex.: content-type, user-agent) em vez de todos os headers.

2) Amostragem (sampling) para logs de alto volume

Para endpoints muito acessados, você pode registrar apenas uma fração dos logs info (mantendo sempre warn/error). Isso reduz custo e melhora sinal/ruído.

function shouldSample(rate: number) {
  return Math.random() < rate;
}

// Exemplo no httpLoggingMiddleware:
// if (level === 'info' && !shouldSample(0.1)) return; // 10% dos info

Uma estratégia comum: 100% de error/warn, 10% de info em rotas barulhentas, 0% de debug em produção (exceto durante incidentes).

3) Evitar logs duplicados e “spam”

• Não registre o mesmo erro em múltiplas camadas sem acrescentar contexto novo.
• Evite logar em loops por item; agregue (ex.: “processados 500 itens”).
• Não logue payloads completos; prefira tamanhos, ids e contagens.

Medindo tempos: latência total e etapas internas

Além do latencyMs total, é útil medir etapas internas (ex.: chamada ao banco, chamada a serviço externo). Use timers com marcações e registre no final da requisição ou em logs debug amostrados.

Passo a passo: marcações de tempo por etapa

function createTimings() {
  const marks = new Map<string, bigint>();
  const start = process.hrtime.bigint();
  marks.set('start', start);

  return {
    mark(name: string) {
      marks.set(name, process.hrtime.bigint());
    },
    summary() {
      const out: Record<string, number> = {};
      const end = process.hrtime.bigint();
      const startMark = marks.get('start') ?? start;
      out.totalMs = Number(end - startMark) / 1_000_000;

      // Exemplo: se existirem marks específicas, calcule deltas
      const dbStart = marks.get('db_start');
      const dbEnd = marks.get('db_end');
      if (dbStart && dbEnd) out.dbMs = Number(dbEnd - dbStart) / 1_000_000;

      const httpStart = marks.get('http_start');
      const httpEnd = marks.get('http_end');
      if (httpStart && httpEnd) out.externalHttpMs = Number(httpEnd - httpStart) / 1_000_000;

      // Arredondamento
      for (const k of Object.keys(out)) out[k] = Math.round(out[k] * 100) / 100;
      return out;
    }
  };
}

// Uso em uma rota:
// const t = createTimings();
// t.mark('db_start'); await query(); t.mark('db_end');
// req.log?.debug('timings', t.summary() as any);

Quando um endpoint ficar lento, esses campos ajudam a separar “latência do app” vs “latência externa”.

Exemplos de logs e como interpretar para depuração

Exemplo 1: requisição normal

{"timestamp":"2026-01-26T10:12:30.120Z","level":"info","message":"http_request_completed","service":"orders-api","env":"production","requestId":"8b2b6a0e-8b1a-4c1b-9d2a-2f3f8c1c9f3a","method":"GET","path":"/orders/123","statusCode":200,"latencyMs":34.21,"contentLength":"512","userAgent":"curl/8.5.0"}

Leitura rápida: sucesso (200), latência baixa (34ms). Para investigar uma reclamação do cliente, peça o requestId e filtre por ele para ver todos os eventos correlacionados.

Exemplo 2: erro 500 com stack e correlação

{"timestamp":"2026-01-26T10:13:02.901Z","level":"error","message":"unhandled_error","service":"orders-api","env":"production","requestId":"c1b7c3a2-0c2c-4b2a-9e2c-9e6b2a7e1a11","traceId":"00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01","method":"POST","path":"/orders","statusCode":500,"error":{"name":"TypeError","message":"Cannot read properties of undefined (reading 'id')","stack":"TypeError: Cannot read properties..."}}

Como depurar: filtre por requestId e procure logs anteriores (ex.: validação, chamadas externas). O traceId ajuda a seguir a requisição em outros serviços (se existirem). O message e o stack indicam o ponto de falha.

Exemplo 3: lentidão intermitente (latência alta)

{"timestamp":"2026-01-26T10:14:10.010Z","level":"warn","message":"http_request_completed","service":"orders-api","env":"production","requestId":"f2a9c9b0-2b0f-4d1b-9b2a-1c2d3e4f5a6b","method":"GET","path":"/orders/123","statusCode":200,"latencyMs":1850.77}

Interpretação: não é erro (200), mas a latência está alta. Próximos passos: habilitar temporariamente logs debug amostrados com timings por etapa (dbMs, externalHttpMs) para identificar o gargalo. Se a latência variar por path, agregue por rota.

Exemplo 4: ruído por dados sensíveis (o que evitar)

{"timestamp":"2026-01-26T10:15:00.000Z","level":"info","message":"login_attempt","service":"orders-api","env":"production","requestId":"...","email":"user@example.com","password":"123456"}

Problema: vazamento de credenciais. Correção: aplicar redação e registrar apenas o necessário (ex.: domínio do email, resultado, motivo). Exemplo melhor:

{"timestamp":"2026-01-26T10:15:00.000Z","level":"info","message":"login_attempt","service":"orders-api","env":"production","requestId":"...","emailDomain":"example.com","result":"failed","reason":"invalid_credentials"}

Checklist rápido para investigar problemas comuns