Add request IDs and structured logs

A user writes in: “I tried to save a book and got an error.” That sentence is all you get. A good log lets you find that one request in a minute. A bad log gives you thousands of Error: something failed lines.

A useful log answers four questions: which request failed, where, how long it took, and what the server decided. The tool that ties the answers together is a request ID, one random string that travels with the request through every log line and back to the client.

Assign an ID to every request

Hono has middleware for this:

import { requestId } from 'hono/request-id'

app.use(requestId())

It reads an incoming X-Request-Id header if there is one, or generates a UUID. It stores the value in c.get('requestId') and echoes it in the response header. Request /books with curl -i and you’ll see x-request-id: 3d8e5f2a-9b1c-4e7d-8a6f-0c2b4d6e8f1a.

Accepting the incoming header is useful when a proxy already assigned one. It’s also a hole if you trust it blindly: someone sends a 10 KB header full of newlines and your log gets a forged entry. Hono’s middleware replaces IDs that are too long or contain unexpected characters. Keep that default.

Log one object per request

Plain text logs are for humans. Structured logs, one JSON object per line, are for the tools that search them. Write one line when the request completes:

app.use(async (c, next) => {
  const start = performance.now()
  await next()
  console.log(JSON.stringify({
    requestId: c.get('requestId'),
    method: c.req.method,
    route: c.req.routePath,
    status: c.res.status,
    ms: Math.round(performance.now() - start)
  }))
})

Because the timer wraps await next(), it measures the whole request, middleware included. And because onError turns exceptions into responses before control comes back here, this line is written even when a handler throws.

A completed request prints:

{"requestId":"3d8e5f2a-9b1c-4e7d-8a6f-0c2b4d6e8f1a","method":"GET","route":"/books/:id","status":404,"ms":2}

Notice route is /books/:id, the template, not /books/8f1c2a3e.... A raw URL can carry a query string with someone’s name or email in it. The template tells you which handler ran without recording personal data.

Log errors once, with the same ID

Update the onError handler from the errors lesson so the client and the server share the ID:

app.onError((err, c) => {
  console.error(JSON.stringify({ requestId: c.get('requestId'), error: err.name, stack: err.stack }))
  return problem(c, 500, 'Something went wrong', { requestId: c.get('requestId') })
})

The stack goes to the server log. The client gets a generic message plus the ID. When the user pastes that ID into her bug report, you grep for it and land on both lines.

What never goes in a log

Authorization headers, cookies, passwords, tokens, full request bodies. If you log headers, keep an allowlist and redact everything else. Book titles are harmless, but the same middleware will one day sit in front of a route that accepts email addresses.

Add the two middlewares, then make a route throw on purpose. Send the request with curl, copy the x-request-id from the response, and find both log lines with it. If you needed a title or a token to find them, the logging isn’t done.