Log and shut down

A service in production has to do two things well that a demo never needs. It has to explain what happened after the fact, and it has to stop without cutting requests in half. Logs cover the first. Graceful shutdown covers the second.

One line per request, as JSON

The logger from the middleware lesson printed a string. Make it structured instead, so a log tool can filter by field:

export function logger(req, res, next) {
  const start = performance.now()
  res.on('finish', () => {
    console.log(JSON.stringify({
      time: new Date().toISOString(),
      requestId: req.id,
      method: req.method,
      path: req.path,
      status: res.statusCode,
      ms: Math.round(performance.now() - start),
      userId: req.session?.userId ?? null,
    }))
  })
  next()
}

A request now leaves a line like this:

{"time":"2026-09-07T09:14:02.118Z","requestId":"3f1c…","method":"POST","path":"/api/notes","status":201,"ms":12,"userId":7}

Notice what is not in there. No body, no headers, no query string. Bodies contain passwords on the login route and note text everywhere else. Headers contain the session cookie. If you need a field from the body for debugging, log that one field, and decide it on purpose.

The requestId is the thread that ties this line to the error handler’s log entry and to the id the user saw on the error page. Three places, one id, one search.

Stop accepting, finish what you have, exit

When your host deploys a new version, it sends SIGTERM to the old process and waits a bit, often thirty seconds, before killing it. If you ignore the signal, in-flight requests die with the process. If you exit immediately, same result. The right sequence is in src/server.js:

const server = app.listen(config.port)

process.on('SIGTERM', () => {
  console.log(JSON.stringify({ event: 'shutdown', reason: 'SIGTERM' }))

  server.close(async () => {
    await db.end()
    process.exit(0)
  })

  server.closeIdleConnections()

  setTimeout(() => {
    console.error(JSON.stringify({ event: 'shutdown-timeout' }))
    process.exit(1)
  }, 10000).unref()
})

server.close() stops the listener, so new connections are refused, but lets requests already in progress finish. When the last one is done, the callback runs, we close the database pool, and exit cleanly.

closeIdleConnections() handles keep-alive sockets that are open but not doing anything. Without it, a browser holding an idle connection can keep the process alive until the host kills it.

The timer is the safety net. If a request is stuck, we don’t wait forever. Ten seconds is under the usual grace period. unref() means the timer itself won’t keep the process alive once everything else is done.

Prove it with a slow request

Add a temporary route that waits three seconds, then run the sequence:

curl http://localhost:3000/slow &
sleep 1
kill -TERM $(pgrep -f 'node src/server.js')
curl -i http://localhost:3000/

The first curl still prints its response after three seconds. The last one fails with Connection refused, because the listener closed the moment the signal arrived. The log shows the shutdown event, then the slow request’s line with its status, then the process is gone.

Try this on your project: replace server.close() with a bare process.exit(0), repeat the steps, and watch the first curl die with Empty reply from server. That’s what your users see on every deploy without graceful shutdown.