Mesmo com volume baixo, o destino vai ficar lento em algum momento: rotação, disco do nó disputado, agente reiniciando. A defesa é garantir que a requisição nunca espere por ele e que a memória usada para absorver a lentidão tenha teto. O logger abaixo faz três coisas: coloca a linha em uma fila em memória e devolve na hora, escreve em lotes respeitando o retorno de write e o evento drain, e descarta linhas quando a fila passa do teto, com limites diferentes por nível e um resumo periódico do que foi perdido.
// logger.js
// A requisicao nunca espera o destino do log: a linha vai para uma fila em memoria
// com teto em bytes, e a escrita acontece em lotes, respeitando o backpressure do stream.
const NIVEIS = { debug: 20, info: 30, warn: 40, error: 50 };
export function criarLogger({
destino = process.stdout,
nivel = process.env.LOG_LEVEL || 'info',
limiteBytes = 8 * 1024 * 1024, // acima disso, debug e info sao descartados
limiteDuroBytes = 16 * 1024 * 1024, // acima disso, ate warn e error sao descartados
tamanhoLote = 64 * 1024,
intervaloResumoMs = 10_000,
} = {}) {
const minimo = NIVEIS[nivel] ?? NIVEIS.info;
const fila = [];
let bytesNaFila = 0;
let aguardandoDrain = false;
let agendado = false;
const descartadas = { debug: 0, info: 0, warn: 0, error: 0 };
function escreverLotes() {
agendado = false;
while (fila.length > 0 && !aguardandoDrain) {
let n = 0;
let bytes = 0;
while (n < fila.length && bytes < tamanhoLote) {
bytes += fila[n].bytes;
n += 1;
}
const lote = fila.splice(0, n);
bytesNaFila -= bytes;
// write() devolve false quando o buffer interno do stream passou do highWaterMark:
// paramos de empurrar e so voltamos no 'drain', em vez de acumular sem limite.
if (!destino.write(lote.map((l) => l.texto).join(''))) {
aguardandoDrain = true;
destino.once('drain', () => {
aguardandoDrain = false;
escreverLotes();
});
}
}
}
function agendar() {
if (agendado || aguardandoDrain) return;
agendado = true;
setImmediate(escreverLotes);
}
function enfileirar(texto, nomeNivel) {
const bytes = Buffer.byteLength(texto);
const teto = NIVEIS[nomeNivel] >= NIVEIS.warn ? limiteDuroBytes : limiteBytes;
if (bytesNaFila + bytes > teto) {
descartadas[nomeNivel] += 1;
return;
}
fila.push({ texto, bytes });
bytesNaFila += bytes;
agendar();
}
function registrar(nomeNivel, msg, campos) {
if (NIVEIS[nomeNivel] < minimo) return;
let texto;
try {
texto = JSON.stringify({ time: Date.now(), level: nomeNivel, msg, ...campos }) + '\n';
} catch (erro) {
texto = JSON.stringify({ time: Date.now(), level: nomeNivel, msg, erroSerializacao: erro.message }) + '\n';
}
enfileirar(texto, nomeNivel);
}
// Descarte silencioso e pior que descarte: a cada intervalo, uma linha diz quanto se perdeu.
const resumo = setInterval(() => {
const total = Object.values(descartadas).reduce((a, b) => a + b, 0);
if (total === 0) return;
const texto = JSON.stringify({ time: Date.now(), level: 'warn', msg: 'logs descartados', ...descartadas }) + '\n';
for (const chave of Object.keys(descartadas)) descartadas[chave] = 0;
fila.push({ texto, bytes: Buffer.byteLength(texto) });
bytesNaFila += Buffer.byteLength(texto);
agendar();
}, intervaloResumoMs);
resumo.unref();
return {
nivelAtivo: (nomeNivel) => NIVEIS[nomeNivel] >= minimo,
debug: (msg, campos) => registrar('debug', msg, campos),
info: (msg, campos) => registrar('info', msg, campos),
warn: (msg, campos) => registrar('warn', msg, campos),
error: (msg, campos) => registrar('error', msg, campos),
estado: () => ({ bytesNaFila, linhasNaFila: fila.length, bufferDoStream: destino.writableLength, descartadas: { ...descartadas } }),
// No desligamento: escreve o que restou e espera o stream confirmar, com prazo.
encerrar(prazoMs = 5_000) {
clearInterval(resumo);
return new Promise((resolve) => {
const limite = setTimeout(resolve, prazoMs);
const verificar = () => {
if (fila.length > 0 || aguardandoDrain) {
escreverLotes();
setTimeout(verificar, 10);
return;
}
destino.write('', () => {
clearTimeout(limite);
resolve();
});
};
verificar();
});
},
};
}
A política de descarte é a parte que mais exige decisão. Debug e info são descartados primeiro, porque são os mais volumosos e os menos necessários durante um incidente. Warn e error têm um limite duro maior, porque são justamente o que se quer ler depois. O que não pode acontecer é descarte silencioso: a linha "logs descartados", com a contagem por nível a cada 10 segundos, transforma a perda em fato observável e permite criar um alerta sobre ela. Uma lacuna nos logs sem essa linha parece ausência de evento; com ela, é uma lacuna explicada.
Esse logger resolve o caso assíncrono, mas não muda a natureza do destino. Se o fd 1 for um arquivo, cada write continua síncrono na thread principal, só que agora em lotes de 64 KB a cada volta do event loop em vez de uma syscall por linha, o que já reduz muito o custo. Quando o destino é inevitavelmente síncrono e lento, o passo seguinte é tirar a escrita da thread principal: o pino.transport, por exemplo, executa o destino em um worker thread e comunica as linhas por um buffer compartilhado. A mesma pergunta continua valendo nesse desenho: o que acontece quando o buffer entre as threads enche, e se essa perda fica visível.
| Desenho | Custo na thread principal | Teto de memória | Perda em destino lento | Quando usar |
|---|
| console.log ou destino síncrono | Serialização + syscall por linha | Nenhum consumo extra | Nenhuma; quem perde é a latência | Scripts, CLIs e jobs curtos |
| Stream assíncrono sem verificar write | Só serialização | Sem teto | Tudo, quando o processo morre por OOM | Nunca de propósito |
| Fila limitada com descarte por nível | Serialização + syscall por lote | Configurado em bytes | Debug e info primeiro, contados | Serviços HTTP e consumidores de fila |
| Worker thread (pino.transport) | Serialização + cópia para o buffer | Tamanho do buffer compartilhado | Depende da configuração do transporte | Destino síncrono ou caro, como arquivo ou rede |
| Envio direto pela rede ao backend | Serialização + cliente HTTP | Buffer do cliente | Alta em falha de rede | Raramente; prefira stdout e agente |