Errors, Logging and Graceful Shutdown

In the last lesson we built an API in Express and Fastify and saw how a central error handler turns a thrown error into a clean 4xx or 5xx response. That covers errors inside a request. This lesson covers the rest: errors that escape, bugs that corrupt your process, logs you can search at 3 a.m., and the moment your server is told to stop (every deploy does this).

We will run real experiments for all of it. We will see what Node does with an unhandled promise rejection, write JSON logs with pino, and then do the most satisfying test in this series: send SIGTERM to a server in the middle of a slow request, and prove with curl that the request still finishes.

This lesson pairs well with Backend Lesson 4 (operational vs programmer errors) and Backend Lesson 5 (logging and observability). Next comes Concurrency.

Words used in this lesson

• An operational error is a problem that can happen in a correct program: a file is missing, a network call times out, a user sends bad input.
• A programmer error is a bug in the code: reading a property of undefined, calling a function with the wrong arguments.
• An exception is an error thrown with throw. If nobody catches it, it goes up the call stack.
• An unhandled rejection is a promise that failed and had no .catch or try/catch waiting for it.
• Structured logging means each log line is a JSON object with named fields, not a free sentence.
• A log level says how serious a line is (info, warn, error) so you can filter.
• A request id (or correlation id) is a unique value attached to all log lines of one request.
• Redaction means hiding secrets (passwords, tokens) in logs before they are written.
• A signal is a small message the operating system sends to a process, like SIGTERM ("please stop") or SIGKILL ("stop now, no questions").
• Graceful shutdown means stopping new work, finishing the work in progress, closing resources, then exiting.
• In-flight request is a request the server has accepted but not yet answered.
• A health check is a small URL that tells a load balancer or orchestrator whether the app is alive and ready.
• Liveness asks "is the process stuck or dead?". Readiness asks "can it take traffic right now?".
• An exit code is the number a process returns when it ends. 0 means success, anything else means failure.

Two kinds of errors

Not every error deserves the same reaction. The nodebestpractices guide puts this as one of its top rules: tell operational errors apart from programmer errors. Here is the difference with two real examples I ran.

import { readFile } from "node:fs/promises";// 1. Operational error: expected, handle ittry { await readFile("/nope/missing.txt"); }catch (err) { console.log("operational:", err.code, "|", err.syscall, "|", err.message); }// 2. Programmer error: a bugtry { const user = undefined; user.name; }catch (err) { console.log("programmer:", err.name, "|", err.message); }

operational: ENOENT | open | ENOENT: no such file or directory, open '/nope/missing.txt'programmer: TypeError | Cannot read properties of undefined (reading 'name')

The first is part of normal life. Files go missing. You catch it and answer with a 404 or a default. The program is still healthy.

The second is a bug. Some code assumed a value exists, and it does not. The program is now in a state the author did not plan for. You cannot safely guess what else is broken.

Useful fields on Node errors

Operational errors from Node have a code string (like ENOENT, ECONNREFUSED, ETIMEDOUT). Check err.code, not the message text. Messages change between versions; codes are stable.

When you re-throw, keep the original with cause:

try {  try { JSON.parse("{bad"); }  catch (e) { throw new Error("config file invalid", { cause: e }); }} catch (e) {  console.log(e.message, "<- caused by:", e.cause.name);}

config file invalid <- caused by: SyntaxError

Your log now shows both the friendly message and the original reason.

A custom error class

For the HTTP layer, give your expected errors a class and a status. We used this in lesson 5:

class HttpError extends Error {  constructor(status, message, options) {    super(message, options);    this.name = "HttpError";    this.status = status;    this.expose = true;      // safe to show the message to the client  }}

The central error handler then asks one question: "is this an HttpError?" If yes, answer with its status and message. If not, treat it as unknown: log it fully, answer with a generic 500. The nodebestpractices guide also says to handle errors in one central place (not in every middleware), so logging, metrics and the "should we crash?" decision all live together.

What escapes: try/catch has limits

try/catch only catches errors that are thrown while its block is running. Async code that fails later is outside it. I ran this:

try {  setTimeout(() => { throw new Error("late"); }, 10);  console.log("try block finished, no error seen");} catch {  console.log("never printed");}process.on("uncaughtException", (err, origin) => {  console.log("uncaughtException:", err.message, "| origin:", origin);});

try block finished, no error seenuncaughtException: late | origin: uncaughtException

The try block ended long before the timer fired. When the callback threw, nobody was waiting, so Node reported an uncaught exception. With async/await this problem mostly goes away, because await brings the failure back into your try/catch. But the problem returns in these places:

• Callbacks and timers (as above).
• A promise you start and do not await (a "floating" promise).
• Event emitters that emit 'error' with no listener.

An unhandled rejection kills the process (since Node 15)

console.log("start");Promise.reject(new Error("nobody handled me"));setTimeout(() => console.log("this line never prints"), 100);

startfile:///tmp/.../e2.mjs:2Promise.reject(new Error("nobody handled me"));               ^Error: nobody handled me    at file:///tmp/.../e2.mjs:2:16    ...exit code: 1

The default mode (throw) turns an unhandled rejection into an uncaught exception. The process crashes with exit code 1 and never reaches the timer. In old Node versions this was only a warning, and I can force that old behaviour with a flag, to see the difference:

$ node --unhandled-rejections=warn e2.mjsstart(node:3676) UnhandledPromiseRejectionWarning: Error: nobody handled me    at ...

I do not recommend warn mode in production. Crashing loudly is better than a half-working server.

You can listen, but know what you are doing

process.on("unhandledRejection", (reason) => {  console.log("unhandledRejection handler:", reason.message);});Promise.reject(new Error("seen by handler"));setTimeout(() => console.log("process kept running"), 50);

unhandledRejection handler: seen by handlerprocess kept running

Adding the listener changes the behaviour: Node no longer crashes. That is dangerous if all you do is print a line. The accepted pattern is to log the error and then exit:

process.on("uncaughtException", (err) => {  console.log("logging and exiting:", err.message);  process.exit(1);});setTimeout(() => { throw new Error("bug in timer"); }, 10);setTimeout(() => console.log("not reached"), 500);

logging and exiting: bug in timerexit: 1

The EventEmitter 'error' trap

An EventEmitter that emits an event named 'error' with no listener throws that error:

import { EventEmitter } from "node:events";const e = new EventEmitter();e.emit("error", new Error("emitter error with no listener"));

file:///tmp/.../e5.mjs:3e.emit("error", new Error("emitter error with no listener"));                ^Error: emitter error with no listenerexit: 1

Streams, sockets, HTTP servers and many libraries are emitters. Always add an 'error' listener to the ones you create (or use stream.pipeline, which does it for you).

Structured logging with pino

console.log("user 7 failed to pay") is fine on day one. On day 100 you will want to ask "show me every error for user 7 on the pay route in the last hour". You cannot do that reliably with free text. Structured logs fix it: each line is one JSON object.

The nodebestpractices guide recommends a mature logger such as pino or Winston, writing to stdout and leaving the routing to the infrastructure. Pino is also the logger that Fastify uses internally (the Fastify docs say so). Here is a short tour. I used npm install pino.

import pino from "pino";const log = pino({ redact: ["password", "req.headers.authorization"], base: { service: "orders" } });log.info("server started");log.info({ port: 3000 }, "listening");log.debug("hidden at default level");log.warn({ userId: 7 }, "slow query");log.error(new Error("db down"), "query failed");const reqLog = log.child({ requestId: "r-123" });reqLog.info({ route: "/pay" }, "payment started");reqLog.info({ password: "hunter2", user: "ada" }, "login attempt");

{"level":30,"time":1791743991481,"service":"orders","msg":"server started"}{"level":30,"time":1791743991482,"service":"orders","port":3000,"msg":"listening"}{"level":40,"time":1791743991482,"service":"orders","userId":7,"msg":"slow query"}{"level":50,"time":1791743991482,"service":"orders","err":{"type":"Error","message":"db down","stack":"Error: db down\n    at ..."},"msg":"query failed"}{"level":30,"time":1791743991483,"service":"orders","requestId":"r-123","route":"/pay","msg":"payment started"}{"level":30,"time":1791743991483,"service":"orders","requestId":"r-123","password":"[Redacted]","user":"ada","msg":"login attempt"}

What each part showed:

• Levels are numbers. info is 30, warn 40, error 50. The full table I printed from pino().levels.values is trace 10, debug 20, info 30, warn 40, error 50, fatal 60. The debug line did not appear, because the default level is info. You raise or lower the level with an option or an environment variable.
• Context goes in an object, the message is a string. log.info({ port: 3000 }, "listening"). The object keys become searchable fields.
• Errors are serialised under err, with type, message and stack. Pass the error object itself, not err.message.
• Child loggers carry extra fields automatically. Every line from reqLog has requestId.
• Redaction replaced the password with [Redacted]. I also tested a nested path, req.headers.authorization, and it was hidden too, while accept was kept.
• The time is a Unix time in milliseconds, which is cheap to write. Tools can turn it into a date.

Searching the logs

Because every line is JSON, any tool can filter. Here is a tiny filter I ran with plain Node, keeping only lines that have a requestId:

r-123 payment startedr-123 login attempt

In real systems the log aggregator (Datadog, Loki, CloudWatch, and others) does the same filtering for you, using the field names.

Pretty output for development only

Raw JSON is hard to read on a laptop. The pino-pretty tool reads JSON lines and prints them nicely. You pipe into it, you do not run it inside production code:

$ node log1.mjs | npx pino-pretty[18:39:51.567] INFO: server started    service: "orders"[18:39:51.567] INFO: listening    service: "orders"    port: 3000[18:39:51.567] WARN: slow query    service: "orders"    userId: 7

Logging in Fastify and Express

Fastify turns pino on with one option, and gives every request a logger with the request id attached:

const app = Fastify({ logger: true });app.get("/hi", async (req) => { req.log.info({ step: "inside handler" }, "working"); return { ok: true }; });

{"level":30,"reqId":"req-1","req":{"method":"GET","url":"/hi","host":"localhost:80","remoteAddress":"127.0.0.1"},"msg":"incoming request"}{"level":30,"reqId":"req-1","step":"inside handler","msg":"working"}{"level":30,"reqId":"req-1","res":{"statusCode":200},"responseTime":4.62,"msg":"request completed"}

All three lines share reqId: "req-1". That is how you rebuild the story of one request from thousands of lines. (The Fastify docs say logging is off by default, and logger: true uses level info.) For Express, you add a request-logging middleware, for example the pino-http package. I did not run pino-http in this lesson, so I only mention it. With plain pino you can write the same thing yourself: a middleware that creates req.log = log.child({ requestId }) and calls next().

What to log, and what never

• Log: request id, route, status, duration, user id (not the whole user), error type and stack, upstream call durations.
• Do not log: passwords, tokens, API keys, full credit-card numbers, personal data you do not need. Use redact as a safety net, but do not rely on it as your only protection. For the bigger picture see Security Lesson 8.
• One event, one line. Avoid building a sentence from five variables. Use fields.

Health checks: liveness and readiness

A load balancer or orchestrator needs a cheap way to ask your app "are you OK?". Two URLs are common:

• /health (liveness): returns 200 if the process is running and the event loop is responding. If this fails, the platform restarts the process.
• /ready (readiness): returns 200 only if the app can take traffic now: database connected, caches warm, and not shutting down. If this fails, the platform stops sending requests but does not kill the app.

Keep liveness checks light. A liveness check that queries the database can restart your whole fleet when the database is slow, which makes things worse. We will use readiness in the next section: when shutdown starts, /ready begins to return 503 so the load balancer stops sending new requests.

Graceful shutdown

Servers are stopped all the time: deploys, scaling down, a crash loop, a manual restart. Containers are created and destroyed daily (the nodebestpractices guide says shutting down containers is a frequent, routine event, and lists handling SIGTERM as the fix). A platform usually stops a process in two steps:

1. Send SIGTERM: "please finish up and exit".
2. After a grace period (often tens of seconds, depends on the platform), send SIGKILL: the process is destroyed instantly. It cannot be caught.

Your program gets between those two moments to clean up. If you do nothing, Node's default for SIGTERM is to exit at once. I checked: a script with no handler, sent SIGTERM, ended with code null signal SIGTERM, meaning it was simply killed by the signal.

The bad way

First the broken version, so you can see the harm. This server has a slow route (3 seconds, pretending to be a slow database call). On SIGTERM it calls process.exit(0) immediately.

const server = http.createServer(async (req, res) => {  if (req.url === "/health") return res.end("ok\n");  await new Promise(r => setTimeout(r, 3000));   // pretend: slow DB call  res.end("order saved\n");});server.listen(4000, () => console.log("up, pid", process.pid));process.on("SIGTERM", () => { console.log("SIGTERM -> exit now"); process.exit(0); });

I started it, sent a request with curl, and after one second sent kill -TERM <pid>:

curl result:curl: (52) Empty reply from serverserver log:up, pid 4016SIGTERM -> exit now

The client got nothing. The order was in progress and the process vanished. If this were a payment, the user would not know if it worked. This is what happens on every deploy to a server with no shutdown code.

The good way

The plan, in order:

1. Set a flag shuttingDown = true. Readiness now says "not ready".
2. Stop accepting new connections: server.close().
3. Let in-flight requests finish. server.close waits for them: its callback runs once every connection has ended.
4. Close idle keep-alive connections right away so they do not hold the server open.
5. Close other resources (database pool, queue consumers).
6. Exit with 0.
7. A safety timer: if all this takes too long, exit with 1 anyway. Do not hang forever.

import http from "node:http";let shuttingDown = false;const server = http.createServer(async (req, res) => {  if (req.url === "/health") {    res.statusCode = shuttingDown ? 503 : 200;    return res.end(shuttingDown ? "shutting down\n" : "ok\n");  }  console.log("request started");  await new Promise(r => setTimeout(r, 3000));   // pretend: slow DB call  res.setHeader("Connection", shuttingDown ? "close" : "keep-alive");  res.end("order saved\n");  console.log("request finished");});server.listen(4000, () => console.log("up, pid", process.pid));function shutdown(signal) {  if (shuttingDown) return;                  // ignore a second signal  shuttingDown = true;  console.log(`${signal} received: stop accepting, wait for in-flight requests`);  server.close((err) => {                    // runs when every connection has ended    console.log("all connections closed, exiting", err ?? "");    process.exit(err ? 1 : 0);  });  server.closeIdleConnections();             // drop idle keep-alive sockets now  setTimeout(() => {                         // safety net    console.log("timeout, forcing exit");    process.exit(1);  }, 10_000).unref();}process.on("SIGTERM", () => shutdown("SIGTERM"));process.on("SIGINT", () => shutdown("SIGINT"));

The test. One terminal ran the server. In another I started curl (a 3 second request), waited 1 second, sent SIGTERM, then tried a new request while the first was still running:

sending SIGTERM at 1snew request during shutdown:curl: (7) Failed to connect to localhost port 4000 after 0 ms: Couldn't connect to server(exit 7)in-flight curl result:order saved[curl: HTTP 200 after 3.006189s]server log:up, pid 4146request startedSIGTERM received: stop accepting, wait for in-flight requestsrequest finishedall connections closed, exiting

Read the three results:

• The in-flight request finished normally: HTTP 200 after 3.006 seconds. The kill happened at about 1 second, so the process stayed alive two more seconds just for it.
• The new request was refused at once ("couldn't connect"), because server.close() stopped the listening socket. A load balancer in front would simply send that user to another instance.
• The server exited by itself with code 0, after the last connection closed.

That is the whole trick. It is about 20 lines.

The Fastify version

Fastify wraps the same idea in app.close(). It stops listening, waits for in-flight requests, and runs onClose hooks, which is where you close the database.

const app = Fastify({ logger: true });app.get("/slow", async () => { await new Promise(r => setTimeout(r, 2000)); return { saved: true }; });app.addHook("onClose", async () => { app.log.info("closing db pool here"); });const stop = async (sig) => {  app.log.info({ sig }, "shutting down");  await app.close();  app.log.info("bye");  process.exit(0);};process.on("SIGTERM", () => stop("SIGTERM"));await app.listen({ port: 4001 });

I called /slow and sent SIGTERM 0.7 seconds later:

{"saved":true} [HTTP 200 2.011244s]{"level":30,"sig":"SIGTERM","msg":"shutting down"}{"level":30,"msg":"closing db pool here"}{"level":30,"msg":"bye"}{"level":30,"reqId":"req-1","res":{"statusCode":200},"responseTime":2007.14,"msg":"request completed"}

The client got its answer after 2.01 seconds, and the onClose hook ran. One odd detail: in this run the "request completed" log line appeared after "bye" in the file, even though the reply had been sent first. I did not dig into why (the logger writes asynchronously). It is a reminder to flush logs before exiting on important paths.

What else belongs in shutdown

• Stop background work: timers (clearInterval), queue consumers, cron jobs.
• Close the database pool and other clients, after the HTTP server has stopped taking requests.
• Flush logs (pino can write asynchronously when you use a destination with sync: false).
• Exit codes: 0 when it went well, non-zero when the timeout hit or a cleanup failed.

Exit codes cheat sheet

(On Linux, a shell reports a process that was killed by a signal as 128 + signal. The Node docs describe the same formula for the default SIGINT and SIGTERM handlers. In my own test the parent saw code null signal SIGTERM, which is how Node's child_process reports a signal death.)

Note also process.exitCode = 2. It sets the code but lets the process end naturally, so pending work finishes. process.exit(2) ends immediately. When in doubt, prefer exitCode.

Putting it together: a checklist for the error path

1. One HttpError class for expected errors, with status and a safe message.
2. One central error handler: log with full detail, respond with a safe message.
3. process.on("uncaughtException") and unhandledRejection: log, start shutdown, exit non-zero.
4. Every emitter has an 'error' listener; use pipeline for streams.
5. JSON logs on stdout with pino, a request id on every line, secrets redacted.
6. /health (light) and /ready (goes 503 while shutting down).
7. SIGTERM handler: stop accepting, finish in-flight, close resources, exit, with a safety timer.
8. Tested with curl and kill, the way we did here.

Try it

1. Run the "bad" shutdown server and the "good" one. Use kill -TERM during a slow request. Compare what curl prints.
2. Remove the safety setTimeout and make one request that never ends (a handler that never calls res.end). What happens to the shutdown? Add the timer back and call server.closeAllConnections() inside it.
3. Write pino code that logs a login with a token field and make sure the token is redacted.
4. Make a Promise that rejects with no handler and run it with the default flags, then with --unhandled-rejections=warn. Compare the exit code.
5. Add /ready to the good server so it returns 503 as soon as shutdown starts. Test with curl in a loop.

Answers

1. Bad: curl: (52) Empty reply from server. Good: the body order saved and HTTP 200 after about 3 seconds.
2. server.close keeps waiting for the stuck connection (I ran it: the callback had not fired after 2 seconds, and fired only after I called closeAllConnections()), so the callback never runs on its own and the process never exits on its own. With the timer, after the grace period you call server.closeAllConnections() and process.exit(1), which ends it.
3. pino({ redact: ["token"] }), then log.info({ token: "abc" }, "login") prints "token":"[Redacted]".
4. Default: crash, exit code 1. With warn: a warning is printed, the program continues, exit code 0 (in my test the timer line still ran).
5. A flag shuttingDown set at the start of shutdown() and a route that returns shuttingDown ? 503 : 200. Note: once server.close() runs, new connections are refused; in real life a load balancer with a readiness check stops sending traffic a moment before, which is why many teams also wait a few seconds between "not ready" and server.close().

Interview questions

Key takeaways

• Operational errors are expected and handled. Programmer errors are bugs: log them, shut down and restart.
• try/catch does not cover callbacks and floating promises. Since Node 15 an unhandled rejection crashes the process by default, and that is usually what you want.
• Use uncaughtException and unhandledRejection listeners only to log and exit, never to carry on.
• Emitters with no 'error' listener throw. Use pipeline for streams.
• Write JSON logs with pino to stdout: levels, fields, child loggers with a request id, and redaction for secrets. Pretty-print only in development.
• Health checks: keep liveness light, make readiness reflect "can I take traffic now", including during shutdown.
• Graceful shutdown: flag, server.close(), finish in-flight work, close resources, exit, with a safety timer. I proved with curl and kill that a 3 second request finished with HTTP 200.
• Prefer process.exitCode to process.exit() unless you really mean "stop now".

What's next

Next: Concurrency: Promises, Worker Threads, Clusters and Child Processes. We will see why Promise.all on 30 requests can break a fragile API, how a small concurrency limiter fixes it, and why one CPU-heavy request freezes everyone else until we move it to a worker thread. Everything is timed. Practise now: add the shutdown code to the server you built in lesson 5, then test it with curl and kill.