Common mistakes when logging, debugging, responding to incidents and writing postmortems Intermediate

This page collects the mistakes developers commonly make, in four groups: logs & errors, debugging tools, during response, postmortems. The code behavior in the Node.js pairs was tested on Node v24.17.0; the PostgreSQL pairs ran on PostgreSQL 17.

Group	Mistakes
Logs & errors	Logs without a correlation ID · Logging errors via string concatenation / JSON.stringify · Rethrowing without cause
Debugging tools	Alerting on averages · --cpu-prof produces no file · Report leaks env · Heap snapshot on a live pod
PostgreSQL	EXPLAIN ANALYZE really deletes · pg_cancel_backend on an idle session
During response	Restart destroys evidence · Repeated guesswork hotfixes · Status update missing information
Postmortem	Blaming individuals · Action items without owner / deadline

Logging and error handling

Logs without a correlation ID

✕ Common

async function checkout(orderId: string) {
  console.log('starting checkout');
  await callPayment(orderId);
  console.log('payment call timed out');
}
// Two parallel requests → 4 interleaved log lines, no way to tell which line belongs to which request

✓ Prefer

import { AsyncLocalStorage } from 'node:async_hooks';

const als = new AsyncLocalStorage<{ requestId: string }>();
const log = (msg: string) =>
  console.log(JSON.stringify({ requestId: als.getStore()?.requestId, msg }));

// middleware: each request runs in its own context
app.use((req, _res, next) =>
  als.run({ requestId: req.get('x-request-id') ?? crypto.randomUUID() }, next));

// {"requestId":"req-a","msg":"starting checkout"}
// {"requestId":"req-b","msg":"starting checkout"}
// {"requestId":"req-b","msg":"payment call timed out"}
// {"requestId":"req-a","msg":"payment call timed out"}

Why

• During an incident, logs from hundreds of requests interleave. Without an ID you cannot filter one request, nor connect its logs to another service.
• AsyncLocalStorage keeps context across await without passing a parameter through every function. Details: Correlation ID.

Logging errors via string concatenation or JSON.stringify

✕ Common

} catch (err) {
  logger.error('checkout failed: ' + err);          // "checkout failed: Error: boom"
  logger.error(JSON.stringify({ orderId, err }));   // {"orderId":"o1","err":{}}
}

✓ Prefer

} catch (err) {
  // pass the Error object itself to a logger with an error serializer (e.g. pino, key `err`)
  logger.error({ err, orderId }, 'checkout failed');
  // or at minimum: console.error(err) — prints the full stack and [cause]
}

Why

• Concatenation calls err.toString(): only Error: message remains, stack and cause are lost.
• JSON.stringify(err) yields {} because message and stack are non-enumerable properties. The log has an error line but nothing to investigate.

Catching an error and throwing a new Error without a cause

✕ Common

try {
  await db.insert(order);
} catch (e) {
  throw new Error('Could not create order');
}
// e.cause === undefined, the stack has no trace of the DB error

✓ Prefer

try {
  await db.insert(order);
} catch (e) {
  throw new Error('Could not create order', { cause: e });
}
// Error: Could not create order ... {
//   [cause]: Error: connect ECONNREFUSED 10.0.3.7:5432 at query (...)
// }

Why

• The original error (ECONNREFUSED, deadlock, timeout) is what reveals the cause. Wrapping without cause destroys evidence right in the code.
• The Error option cause exists since Node 16.9; console.log/util.inspect print the whole [cause] chain.

Debugging tools

Alerting on average event loop delay

✕ Common

const h = monitorEventLoopDelay({ resolution: 10 });
h.enable();
setInterval(() => {
  metrics.gauge('eventloop_delay_ms', h.mean / 1e6); // alert when > 100
  h.reset();
}, 10_000);

✓ Prefer

setInterval(() => {
  metrics.gauge('eventloop_delay_p99_ms', h.percentile(99) / 1e6);
  metrics.gauge('eventloop_delay_max_ms', h.max / 1e6); // alert on max
  h.reset();
}, 10_000);

Why

• Tested: a single 400 ms block in a 10-second window gives mean=10.8ms, max=400.3ms. An alert on the mean never fires.
• For those 400 ms, every request in the process is stalled — exactly the kind of incident you need to catch.

Enabling --cpu-prof and waiting for the pod to be killed to get a profile

✕ Common

node --cpu-prof --cpu-prof-dir=/tmp/prof app.js
# Pod gets OOMKilled (SIGKILL) or kubectl delete pod (SIGTERM, app has no handler)
ls /tmp/prof    # empty

✓ Prefer

// the app exits "normally" on SIGTERM → V8 gets to write the .cpuprofile
process.on('SIGTERM', async () => {
  await new Promise((r) => server.close(r)); // graceful shutdown
  process.exit(0);
});

Why

• Node writes the CPU profile before the process exits. Tested: kill -9 and kill -TERM without a handler both leave no file; with a handler that calls process.exit, the file is there.
• An OOMKilled pod cannot be saved — reproduce it in another environment. See also graceful shutdown.

Writing a diagnostic report and posting the whole file in the chat channel

✕ Common

process.report.writeReport('incident.json');
// the file has "environmentVariables": { "DATABASE_URL": "postgres://...", "STRIPE_KEY": ... }

✓ Prefer

process.report.excludeEnv = true;      // or run node --report-exclude-env
process.report.excludeNetwork = true;
process.report.writeReport('incident.json');

Why

• By default the report contains every environment variable (tested: excludeEnv defaults to false, and the report has an environmentVariables key).
• The incident channel has many people, bots and saved history — a secret leaked there is a second incident.

Taking a heap snapshot on a pod that is serving traffic

✕ Common action

kubectl exec api-7f9c -- kill -USR2 1   # --heapsnapshot-signal=SIGUSR2
# the event loop stalls during the snapshot, memory doubles → OOMKilled mid-incident

✓ Action to take

# 1. take the pod out of the Service: remove the label the selector uses (the ReplicaSet creates a replacement)
kubectl label pod api-7f9c app-
# 2. only then snapshot; or reproduce the leak in staging
kubectl exec api-7f9c -- kill -USR2 1

Why

• A heap snapshot blocks the event loop for the whole capture and needs roughly twice the heap in memory.
• A pod receiving traffic will time out en masse, or get OOM killed and lose the snapshot too.

PostgreSQL

EXPLAIN ANALYZE on a DELETE in production

✕ Common

EXPLAIN ANALYZE DELETE FROM orders WHERE status = 'expired';
-- "just looking at the plan" → 1000 rows actually deleted

✓ Prefer

BEGIN;
EXPLAIN (ANALYZE, BUFFERS) DELETE FROM orders WHERE status = 'expired';
ROLLBACK;
-- data intact

Why

• ANALYZE actually executes the statement. Tested on PostgreSQL 17: unwrapped, count(*) drops to 0; wrapped in BEGIN/ROLLBACK, it stays at 1000.
• Even with a rollback, the statement still takes locks and runs for its full duration — do not run it under peak load.

Using pg_cancel_backend on an idle in transaction session

✕ Common

SELECT pg_cancel_backend(pid) FROM pg_stat_activity
WHERE state = 'idle in transaction';
-- returns true, but the session is still "idle in transaction", still holding the connection and locks

✓ Prefer

SELECT pg_terminate_backend(pid) FROM pg_stat_activity
WHERE state = 'idle in transaction'
  AND xact_start < now() - interval '1 minute';
-- session killed, transaction rolled back; then set idle_in_transaction_session_timeout

Why

• pg_cancel_backend only cancels the running statement; an idle session has nothing to cancel. Tested: after the cancel, state is still idle in transaction.
• The pool stays exhausted, on-call thinks it is handled — another ten minutes lost.

During response

Restart first, think later, save nothing

✕ Common action

kubectl rollout restart deploy/api
# p99 back to normal... 3 hours later it climbs again. Heap, connections, locks at failure time: all gone

✓ Action to take

# < 1 minute to preserve evidence, then mitigate
kubectl exec api-7f9c -- kill -USR2 1          # node --report-on-signal --report-exclude-env
psql -c "\copy (SELECT * FROM pg_stat_activity) TO 'activity-1405.csv' CSV HEADER"
kubectl get deploy/api -o jsonpath='{.spec.template.spec.containers[0].image}'
kubectl rollout restart deploy/api

Why

• A restart makes the symptoms go away temporarily and wipes the state you need to find the cause.
• The incident comes back, and you start investigating from zero.

Repeated guesswork hotfixes instead of rolling back or turning off a flag

✕ Common sequence

14:10 deploy v2.31.1 "try fix timeout"      → still failing
14:25 deploy v2.31.2 "increase pool size"   → still failing
14:40 deploy v2.31.3 "revert pool, add logs" → a different error appears

✓ Sequence to aim for

14:10 turn off flag invoice-export (or roll back v2.31 → v2.30)  → p99 drops
14:15 SLI stable, cause confirmed to be in v2.31
15:30 fix with review + tests, redeploy calmly

Why

• Each hotfix is an untested change stacked on a failing system, with 10-15 minutes of waiting for the pipeline.
• With many consecutive changes you cannot tell which one worked. Rollbacks and flags are cheap operations with known outcomes.

Status update without impact or next update time

✕ Common update

Checking, looks like the DB. Will update later.

✓ Update to write

[SEV2][14:35 UTC] Checkout slow — MITIGATING
Impact: ~30% of checkout requests > 2s since 14:05 UTC. No data loss.
Done: rolled back api v2.31 → v2.30 at 14:31, p99 is dropping.
Next update: 15:00 UTC. IC: @an

Why

• Without the impact, support, sales and management do not know whether to notify customers.
• Without the next update time, everyone keeps messaging the IC, pulling the IC away from coordinating.

Postmortem

A postmortem that blames an individual

✕ Common sentence

Root cause: An forgot to add an index on customer_id when merging PR #812.

✓ Sentence to write

Root cause: the query filtering by customer_id ran a seq scan on a 40M-row table.
Contributing factors: review had no step to look at EXPLAIN for new queries;
staging only has 10k rows, so the problem did not show.

Why

• “An forgot” fixes nothing, and next time the people involved will stay quiet — the postmortem loses its best source of information.
• Describing system conditions is what leads to action items: staging data, review steps, lint.

Vague action items with no owner and no deadline

✕ Common action items

- Improve monitoring.
- Remind the team to be more careful when adding new queries.
- Owner: Backend team.

✓ Action items to write

1. [detect]  Alert event loop delay max > 200ms for 5 minutes → checkout on-call
   Owner: @binh   Due: 2026-10-25   Ticket: OPS-412
2. [prevent] CI runs EXPLAIN for new queries on a 1M-row dataset
   Owner: @an     Due: 2026-11-08   Ticket: OPS-413

Why

• “Be more careful” is not verifiable and does not change the system; “the team” is not an owner, so nobody does it.
• Per the SRE Workbook, action items without a tracking process are often forgotten and the incident recurs.

Common pitfall

Writing postmortems only for major incidents. Near-misses and recurring small incidents are the cheapest signals about system weaknesses. Write short postmortems for them.

Self-check

1. You rolled back but p99 did not drop. What does that say about the initial hypothesis, and what is the next step?
2. Why did the diagnostic report in Demo 1 not point at buildInvoiceReportSync? Which tool would?
3. Latency is up but CPU is low: which three places do you look at first?
4. Rewrite the sentence “Because An forgot to add an index” in a blameless spirit and propose a prevent action item.

Back to: Incidents and postmortems overview.