import pino, { Logger } from 'pino';
import { AsyncLocalStorage } from 'node:async_hooks';
export interface Store {
requestId: string;
logger: Logger;
}
export const als = new AsyncLocalStorage<Store>();
export const baseLogger = pino({
level: process.env.LOG_LEVEL ?? 'info',
timestamp: pino.stdTimeFunctions.isoTime,
redact: {
paths: ['req.headers.authorization', 'req.headers.cookie'],
censor: '[redacted]',
},
});
export function log(): Logger {
const store = als.getStore();
return store ? store.logger : baseLogger;
}
import { randomUUID } from 'node:crypto';
import { Request, Response, NextFunction } from 'express';
import { als, baseLogger } from './logger';
export function requestContext(req: Request, res: Response, next: NextFunction): void {
const incoming = req.header('x-request-id');
const requestId = incoming && incoming.trim() !== '' ? incoming : randomUUID();
res.setHeader('x-request-id', requestId);
const logger = baseLogger.child({ requestId });
als.run({ requestId, logger }, () => next());
}
export function requestLogger(req: Request, res: Response, next: NextFunction): void {
const start = process.hrtime.bigint();
const store = als.getStore();
res.on('finish', () => {
const durationMs = Number(process.hrtime.bigint() - start) / 1e6;
const logger = store ? store.logger : baseLogger;
logger.info(
{
method: req.method,
path: req.originalUrl,
status: res.statusCode,
durationMs: Number(durationMs.toFixed(2)),
},
'request completed',
);
});
next();
}
import express, { Request, Response, NextFunction } from 'express';
import { requestContext, requestLogger } from './requestContext';
import { log } from './logger';
export const app = express();
app.use(express.json());
app.use(requestContext);
app.use(requestLogger);
app.get('/orders/:id', async (req: Request, res: Response) => {
log().info({ orderId: req.params.id }, 'fetching order');
const order = await fetchOrder(req.params.id);
if (!order) {
log().warn({ orderId: req.params.id }, 'order not found');
return res.status(404).json({ error: 'not_found' });
}
log().debug({ orderId: order.id, total: order.total }, 'order resolved');
return res.json(order);
});
app.use((err: Error, _req: Request, res: Response, _next: NextFunction) => {
log().error({ err }, 'unhandled error');
res.status(500).json({ error: 'internal_error' });
});
async function fetchOrder(id: string): Promise<{ id: string; total: number } | null> {
if (id === '0') return null;
return { id, total: 4200 };
}
This snippet wires a per-request correlation ID through an Express application and attaches a child logger to every log line so that all output for a single request can be grouped after the fact. The core problem it solves is that in a concurrent server, log lines from different in-flight requests interleave; without a shared identifier there is no reliable way to reconstruct what happened during one request. The approach uses Node's AsyncLocalStorage so the logger and request ID follow the async call chain without being threaded through every function argument.
In logger.ts, a base pino instance is created with ISO timestamps and a redaction rule so authorization headers never reach the logs. An AsyncLocalStorage holds a Store containing a requestId and a bound logger. The exported log() helper returns the request-scoped logger when called inside a request, and falls back to the base logger otherwise, which keeps startup and background code working without a store.
In requestContext.ts, the requestContext middleware reads an incoming x-request-id header or mints a fresh UUID with randomUUID(). Honoring an inbound ID lets an upstream gateway or another service propagate its own correlation ID, so a trace spans multiple hops. It echoes the ID back on the response header and creates a child logger bound to that ID via pino.child(), then runs the rest of the pipeline inside als.run() so downstream handlers observe the store.
The requestLogger middleware records a monotonic start time with process.hrtime.bigint() and logs a single completion line on the response finish event, including method, path, status, and duration in milliseconds. Logging once on completion rather than per line keeps volume low while still capturing latency.
In app.ts, ordering matters: requestContext must run before requestLogger and before any route so the store exists. The /orders/:id route calls log() with no plumbing and still emits lines tagged with the correct requestId. The error handler also uses log(), so failures are correlated too. The main trade-off is that AsyncLocalStorage adds slight overhead and requires discipline to never capture the logger outside its async scope.
Related snips
package api
import (
"net/http"
"runtime/debug"
)Expose build metadata for debugging deploys
use tracing::{info, instrument};
#[instrument]
fn process_request(user_id: u64) {
info!(user_id, "Processing request");
// Work happens heretracing for structured logging and distributed tracing
import { randomBytes, createHash } from "crypto";
import jwt from "jsonwebtoken";
import { RefreshTokenStore } from "./store";
const ACCESS_SECRET = process.env.ACCESS_SECRET!;
const ACCESS_TTL = "15m";JWT access + refresh token rotation (conceptual)
# Grafana provisioning: datasources
# /etc/grafana/provisioning/datasources/prometheus.yml
apiVersion: 1
datasources:
- name: Prometheus
type: prometheusGrafana dashboards as code with JSON provisioning
import React from "react";
type FallbackProps = {
error: Error;
reset: () => void;
};React Error Boundary + error reporting hook
import type { IncomingMessage, ServerResponse } from "http";
const MIN_BYTES = 1024;
const INCOMPRESSIBLE = /^(image|video|audio)\/|application\/(zip|gzip|x-brotli|pdf|octet-stream)/i;Response compression (only when it helps)
Share this code
Here's the card — post it anywhere.
