Node.js e Logging – Parte 7: Apresentando o ID de Correlação

Depois de remover informações confidenciais no último artigo, adicionamos agora um dado importante: o ID de correlação. Não quero presumir que você possa classificar esse termo. É por isso que começamos com um bloco teórico antes da implementação. Porque uma coisa é certa: o ID de correlação ajuda na depuração. Em sistemas distribuídos com microsserviços, é a única chance de entender o que está acontecendo.

1. Que problema o ID de correlação resolve?
2. Como o cls-rtracer nos ajuda?
3. Adição em EnvVarService: nome do cabeçalho Correlation-ID
4. Criação de um middleware Express
5. Integração em nosso aplicativo expresso

Antes de começarmos, dê uma olhada nos artigos anteriores desta série. Você pode encontrar os links na visão geral da série de artigos.

1. Qual problema o ID de correlação resolve?

O problema

No desenvolvimento backend moderno, trabalhamos principalmente com sistemas distribuídos (microsserviços), comunicação assíncrona (filas, eventos), processamento paralelo (threads, trabalhadores), bem como balanceadores de carga e novas tentativas.

Uma única solicitação de usuário é gerada muitas solicitações técnicas em vários serviços. Sem um identificador adicional, os logs são misturados no tempo, não podem ser atribuídos entre serviços e são difíceis de depurar.

Perguntas como estas tornam-se difíceis de responder:

• Por que esta solicitação falhou?
• Onde foi que o tempo foi perdido?
• Qual serviço desencadeou o erro?

A solução

Um ID de correlação é aquele ID único e aleatório (por exemplo, um UUID), que é gerado ou adotado para cada consulta técnica e transportado com cada chamada subseqüente torna-se.

Suas características típicas são:

• o mesmo para todos os logs da mesma solicitação
• transportado via cabeçalho HTTP, cabeçalho da mensagem, contexto
• independentemente de sessões, IDs de usuário ou IDs de banco de dados.

O ID de correlação forma assim a base para soluções de rastreamento e observabilidade, como OpenTelemetry, Jaeger ou Zipkin. Às vezes você o encontra com um nome diferente, como Trace-ID ou Request-ID.

2. Como o cls-rtracer nos ajuda?

Agora que sabemos o que é o ID de correlação e por que precisamos dele, rapidamente fica claro por que precisamos de um middleware Express: Se não recebermos um ID de correlação, queremos criar um novo ID de correlação na borda do sistema – em nosso caso, no endpoint HTTP.

Para a implementação utilizamos o pacote NPM cls-rtracer. O pacote nos oferece duas funcionalidades:

• Um Express-Middlewareque queremos configurar usando opções. Isso por si só não justifica o uso do pacote NPM, pois construí-lo sozinho exigiria menos esforço.
• O pacote NPM também inclui armazenamento e gerenciamento do ID de correlação em AsyncLocalStoragepara que por um lado tenhamos acesso a ele a qualquer momento e por outro lado cada execução assíncrona receba seu próprio ID de correlação. O último é relevante porque usamos um ID de correlação diferente para cada chamada HTTP potencialmente executada ao mesmo tempo.

Perigo: Com esta utilização temos um impacto no desempenho que é particularmente relevante para sistemas com cargas elevadas. O máximo de solicitações por segundo que nosso aplicativo Express pode processar está diminuindo.

Estou firmemente convencido de que, especialmente em tais situações (alta carga), o rastreamento claro usando um ID de correlação é essencial para rastrear erros nos logs. Porque quando ocorre um erro, ele ocorre sob carga, enquanto centenas de processos paralelos produzem resultados nos logs.

Uma solicitação Perplexity com o prompt a seguir resulta na afirmação de que uma perda de desempenho de 5 a 15% pode ser esperada. Tolerável em cenários com hospedagem com escala horizontal. Se você quiser fazer sua própria pesquisa, aqui está minha sugestão como ponto de partida.

I use cls-rtracer with AsyncLocalStorage in my Node.js Express application. What is the performance impact for requests per second due to the usage of this?

3. Adição em EnvVarService: nome do cabeçalho Correlation-ID

Para o middleware Express precisamos de um nome de cabeçalho no qual o ID de correlação seja transmitido. A prática de incluir seus próprios nomes de cabeçalho foi adotada a partir de protocolos históricos como o email RFC 822 x- para começar. Isso evita colisões de nomes com cabeçalhos padronizados. Eu sempre uso o nome do ID de correlação x-correlation-id. O ajuste no EnvVarService fica assim:

// Change in the zod schema
const schema = z.object({  
  LOG_LEVEL: withDevDefault(z.enum(LogLevels), LogLevels.DEBUG),  
  LOG_FORMAT: withDevDefault(z.enum(LogFormats), LogFormats.PLAIN),  
  LOG_CORRELATION_ID_HEADER: withDevDefault(z.string().min(1), 'x-correlation-id'),  
})

// Update in the return statement for all logging values
return {  
  logLevel: parsed.data.LOG_LEVEL,  
  logFormat: parsed.data.LOG_FORMAT,  
  logCorrelationIdHeader: parsed.data.LOG_CORRELATION_ID_HEADER,  
}

Não se esqueça de incluir uma atualização apropriada para os testes setupTestEnvVars.ts a ser realizado. O mesmo em .env.dist e .env.

4. Criando um middleware Express

Criamos o middleware expresso no arquivo /src/services/correlationId/CorrelationIdMiddleware.ts. Acessamos o novo valor de EnvVarService e o usamos na função auxiliar que cls-rtracer nos fornece.

import { expressMiddleware } from 'cls-rtracer'  
import { v4 as uuidv4 } from 'uuid'  
import type { Router } from 'express'  
import EnvVarService from '@/services/EnvVarService'  

export default function CorrelationIdMiddleware (app: Router) {  
  const middleware = expressMiddleware({  
    // Respect request header flag (default: false).  
    // If set to true, the middleware/plugin will always use a value from
    // the specified header (if the value is present).
    useHeader: true,  
    // Add request id to response header (default: false).  
    // If set to true, the middleware/plugin will add the request id to the specified
    // header. Use the headerName option to specify the header name.
    echoHeader: true,  
    // Request/response header name, case-insensitive (default: 'X-Request-Id'). 
    // Used if useHeader/echoHeader is set to true.
    headerName: EnvVarService.logging.logCorrelationIdHeader,  
    // A custom function to generate your request IDs (default: UUID v1).  
    requestIdFactory: uuidv4,  
  })  
  app.use(middleware)  
}

5. Integração em nosso aplicativo expresso

A última etapa é integrá-lo ao aplicativo Express. Defini a chamada de forma análoga à integração das rotas TSOA geradas dinamicamente.

const app = express()
CorrelationIdMiddleware(app)
RegisterRoutes(app)
// other app configuration

Podemos verificar a implementação como parte de um teste:

it('should validate correlation-id is present in response headers', async () => {  
  // act  
  const {headers} = await agent.get('/entities')  

  // assert  
  expect(headers('x-correlation-id')).toBeDefined()  
})

Conclusão

Com esta etapa, criamos um alicerce essencial para a exploração madeireira profissional. Entretanto, nosso trabalho anterior só nos ajuda na medida em que o ID de correlação está disponível para cada chamada HTTP. Ele ainda não foi encontrado nos logs e teríamos que integrá-lo laboriosamente em cada instrução de log. Esta não é uma abordagem aceitável. É por isso que no próximo artigo iremos garantir que nosso LogService faça este trabalho: Cada instrução de log é automaticamente complementada com a propriedade.