Guides

Request logging

One completion event per request, with a diagnostic context, for Next.js and Express.

A web server left to itself logs several lines per request, none of which says how it went. Serilog.AspNetCore's answer — one completion event per request, with the method, the path, the status, the elapsed time, and whatever the handler wanted recorded — is what @unhingged/logit/next and @unhingged/logit/express do.

HTTP GET /api/orders responded 200 in 17.2100 ms OrderCount=12 UserId=u_7

The template is HTTP {RequestMethod} {RequestPath} responded {StatusCode} in {Elapsed:0.0000} ms — the same as Serilog's — exported as REQUEST_COMPLETION_TEMPLATE. The event's source is http.

What happens per request#

  1. A request id is resolved: x-request-id, then Vercel's x-vercel-id, then a UUID.
  2. A scope opens: RequestId, RequestMethod and RequestPath become ambient — every event logged by anyone during the request carries them — and a fresh diagnostic context is attached.
  3. The handler runs. Anything it logs is inside the scope; anything it diagnosticContext.set()s is collected.
  4. When the response is done, one completion event is written at error if the handler threw or returned 5xx, info otherwise, carrying the collected diagnostics as properties.

Next.js#

import { withLogging } from '@unhingged/logit/next';

export const GET = withLogging(async (request) => { … });          // route handlers
export default withLogging(async (request) => NextResponse.next()); // middleware

The wrapper takes (request: Request, ...args) and returns the handler's response. A thrown error is logged with the request's facts and rethrown; redirect() and notFound() complete with 307 / 404. Errors Next catches elsewhere (renders, actions) go through createOnRequestError() — see Next.js.

Express#

import { requestLogger, errorLogger } from '@unhingged/logit/express';

app.use(requestLogger({ responseHeader: 'x-request-id' }));
…
app.use(errorLogger());

requestLogger completes on the response's finish (or close), sets req.log — a logger bound to the request id — and writes the id back as a response header. errorLogger logs an error that reached it and passes it on.

Options#

Both adapters take RequestLoggingOptions:

OptionDefaultNote
loggerthe global log
messageTemplateREQUEST_COMPLETION_TEMPLATEholes bind in order: method, path, status, elapsed
getLevel(status, elapsedMs, error)error for an error or a 5xx, else infoe.g. warn for 4xx, debug for static assets
enrich(set, request, response)—Serilog's EnrichDiagnosticContext: add properties to the completion event from the request — the host, the user agent, the user
ignore(request)—skip health checks and assets entirely: no scope, no event
requestIdHeader['x-request-id', 'x-vercel-id']a header name or a list
generateRequestId()crypto.randomUUID()
source'http'the SourceContext of the completion event

Express adds responseHeader (default 'x-request-id', false to skip) and stripQuery (default true: RequestPath is the path without the query string).

requestLogger({
  getLevel: (status, elapsed, error) => (error || status >= 500 ? 'error' : status >= 400 ? 'warn' : elapsed > 2000 ? 'warn' : 'info'),
  enrich: (set, req) => {
    set('UserAgent', req.headers.get?.('user-agent') ?? req.headers['user-agent']);
  },
  ignore: (req) => req.path === '/health' || req.path.startsWith('/_next/static'),
});

The diagnostic context#

diagnosticContext.set(name, value) from anywhere inside the request — a service three calls down, a middleware, a data loader — puts a property on that request's completion event. It is IDiagnosticContext from Serilog.AspNetCore: fewer events, each saying more.

import { diagnosticContext } from '@unhingged/logit';

async function loadOrders(user: User) {
  const orders = await db.orders.findMany({ where: { userId: user.id } });
  diagnosticContext.set('UserId', user.id);
  diagnosticContext.set('OrderCount', orders.length);
  return orders;
}

Outside a request scope set does nothing; diagnosticContext.active is true inside one. Values are captured with @ — objects come through structurally. In @unhingged/logit/next the same object is also exported as requestDiagnostics.

Your own framework#

The scope is reusable. LogContext.runScope(props, fn) opens a scope with a diagnostic context; the adapters are small wrappers over the shared runRequestScope in the package. For a server with no adapter yet — Fastify, Hono, Koa are on the roadmap — open the scope in a hook:

import { LogContext, log } from '@unhingged/logit';

app.addHook('onRequest', (req, reply, done) => {
  LogContext.runScope({ RequestId: req.id, RequestMethod: req.method, RequestPath: req.url }, () => done());
});
app.addHook('onResponse', (req, reply, done) => {
  log.forSource('http').info('HTTP {RequestMethod} {RequestPath} responded {StatusCode} in {Elapsed:0.0000} ms', req.method, req.url, reply.statusCode, reply.elapsedTime);
  done();
});