Lỗi hay gặp khi log, debug, ứng cứu sự cố và viết postmortem Trung cấp

Trang này gom các lỗi dev hay mắc, chia bốn nhóm: log & lỗi, công cụ debug, lúc ứng cứu, postmortem. Hành vi code trong các cặp Node.js đã chạy thử trên Node v24.17.0; cặp PostgreSQL chạy trên PostgreSQL 17.

Nhóm	Lỗi
Log & lỗi	Log thiếu correlation ID · Log lỗi bằng nối chuỗi / JSON.stringify · Rethrow không cause
Công cụ debug	Alert theo trung bình · --cpu-prof không ra file · Report lộ env · Heap snapshot trên Pod đang chạy
PostgreSQL	EXPLAIN ANALYZE xoá thật · pg_cancel_backend cho session idle
Lúc ứng cứu	Restart mất bằng chứng · Hotfix mò liên tục · Status update thiếu thông tin
Postmortem	Đổ lỗi cá nhân · Action item không owner / hạn

Log và xử lý lỗi

Log không có correlation ID

✕ Hay gặp

async function checkout(orderId: string) {
  console.log('bắt đầu checkout');
  await callPayment(orderId);
  console.log('gọi payment timeout');
}
// Hai request song song → 4 dòng log xen kẽ, không biết dòng nào của request nào

✓ Nên viết

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: mỗi request chạy trong context riêng
app.use((req, _res, next) =>
  als.run({ requestId: req.get('x-request-id') ?? crypto.randomUUID() }, next));

// {"requestId":"req-a","msg":"bắt đầu checkout"}
// {"requestId":"req-b","msg":"bắt đầu checkout"}
// {"requestId":"req-b","msg":"gọi payment timeout"}
// {"requestId":"req-a","msg":"gọi payment timeout"}

Vì sao

• Lúc sự cố, log của hàng trăm request xen kẽ nhau. Không có ID thì không lọc được một request, và không nối được log sang service khác.
• AsyncLocalStorage giữ context qua await mà không phải truyền tham số qua mọi hàm. Chi tiết: Correlation ID.

Log lỗi bằng nối chuỗi hoặc JSON.stringify

✕ Hay gặp

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

✓ Nên viết

} catch (err) {
  // truyền nguyên object Error cho logger có serializer lỗi (vd pino, key `err`)
  logger.error({ err, orderId }, 'checkout failed');
  // hoặc tối thiểu: console.error(err) — in đủ stack và [cause]
}

Vì sao

• Nối chuỗi gọi err.toString(): chỉ còn Error: message, mất stack và cause.
• JSON.stringify(err) ra {} vì message, stack là thuộc tính non-enumerable. Log có dòng lỗi nhưng không có gì để điều tra.

Bắt lỗi rồi throw Error mới mà không gắn cause

✕ Hay gặp

try {
  await db.insert(order);
} catch (e) {
  throw new Error('Không tạo được đơn hàng');
}
// e.cause === undefined, stack không còn dấu vết của lỗi DB

✓ Nên viết

try {
  await db.insert(order);
} catch (e) {
  throw new Error('Không tạo được đơn hàng', { cause: e });
}
// Error: Không tạo được đơn hàng ... {
//   [cause]: Error: connect ECONNREFUSED 10.0.3.7:5432 at query (...)
// }

Vì sao

• Lỗi gốc (ECONNREFUSED, deadlock, timeout) mới là thứ nói lên nguyên nhân. Bọc mà không cause là xoá bằng chứng ngay trong code.
• Error option cause có sẵn từ Node 16.9; console.log/util.inspect in cả chuỗi [cause].

Công cụ debug

Alert event loop delay theo trung bình

✕ Hay gặp

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

✓ Nên viết

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

Vì sao

• Chạy thử: một lần chặn 400 ms trong cửa sổ 10 giây cho mean=10.8ms, max=400.3ms. Alert theo mean không bao giờ kêu.
• Trong 400 ms đó mọi request của process đều đứng chờ — đúng loại sự cố cần bắt.

Bật --cpu-prof rồi chờ Pod bị kill để lấy profile

✕ Hay gặp

node --cpu-prof --cpu-prof-dir=/tmp/prof app.js
# Pod bị OOMKilled (SIGKILL) hoặc kubectl delete pod (SIGTERM, app không có handler)
ls /tmp/prof    # trống

✓ Nên viết

// app thoát "bình thường" khi nhận SIGTERM → V8 kịp ghi .cpuprofile
process.on('SIGTERM', async () => {
  await new Promise((r) => server.close(r)); // graceful shutdown
  process.exit(0);
});

Vì sao

• Node ghi CPU profile trước khi process thoát. Chạy thử: kill -9 và kill -TERM không handler đều không để lại file; có handler gọi process.exit thì có.
• Pod bị OOMKilled thì không cứu được — tái hiện ở môi trường khác. Xem thêm graceful shutdown.

Ghi diagnostic report rồi gửi nguyên file vào kênh chat

✕ Hay gặp

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

✓ Nên viết

process.report.excludeEnv = true;      // hoặc chạy node --report-exclude-env
process.report.excludeNetwork = true;
process.report.writeReport('incident.json');

Vì sao

• Mặc định report chứa toàn bộ biến môi trường (chạy thử: excludeEnv mặc định false, report có khoá environmentVariables).
• Kênh incident có nhiều người, có bot, có lưu lịch sử — secret lộ ở đó là sự cố thứ hai.

Chụp heap snapshot trên Pod đang phục vụ traffic

✕ Thao tác hay gặp

kubectl exec api-7f9c -- kill -USR2 1   # --heapsnapshot-signal=SIGUSR2
# event loop đứng trong lúc chụp, memory tăng gấp đôi → OOMKilled giữa sự cố

✓ Thao tác nên làm

# 1. rút Pod khỏi Service: bỏ label mà selector dùng (ReplicaSet tạo Pod thay thế)
kubectl label pod api-7f9c app-
# 2. rồi mới chụp; hoặc tái hiện leak ở staging
kubectl exec api-7f9c -- kill -USR2 1

Vì sao

• Heap snapshot chặn event loop suốt lúc chụp và cần bộ nhớ khoảng gấp đôi heap.
• Pod đang nhận traffic sẽ timeout hàng loạt, hoặc bị OOM kill và mất luôn snapshot.

PostgreSQL

EXPLAIN ANALYZE một câu DELETE trên production

✕ Hay gặp

EXPLAIN ANALYZE DELETE FROM orders WHERE status = 'expired';
-- "chỉ xem plan thôi mà" → 1000 dòng đã bị xoá thật

✓ Nên viết

BEGIN;
EXPLAIN (ANALYZE, BUFFERS) DELETE FROM orders WHERE status = 'expired';
ROLLBACK;
-- dữ liệu còn nguyên

Vì sao

• ANALYZE thực sự chạy câu lệnh. Chạy thử trên PostgreSQL 17: không bọc thì count(*) còn 0, bọc BEGIN/ROLLBACK thì còn 1000.
• Kể cả khi rollback, câu lệnh vẫn lấy lock và chạy hết thời gian — đừng chạy lúc đang cao tải.

Dùng pg_cancel_backend cho session idle in transaction

✕ Hay gặp

SELECT pg_cancel_backend(pid) FROM pg_stat_activity
WHERE state = 'idle in transaction';
-- trả về true, nhưng session vẫn "idle in transaction", vẫn giữ connection và lock

✓ Nên viết

SELECT pg_terminate_backend(pid) FROM pg_stat_activity
WHERE state = 'idle in transaction'
  AND xact_start < now() - interval '1 minute';
-- session bị ngắt, transaction rollback; sau đó đặt idle_in_transaction_session_timeout

Vì sao

• pg_cancel_backend chỉ huỷ câu đang chạy; session idle không có câu nào để huỷ. Chạy thử: sau cancel, state vẫn là idle in transaction.
• Pool vẫn cạn, on-call tưởng đã xử lý xong — mất thêm chục phút.

Lúc ứng cứu

Restart trước, nghĩ sau, không lưu gì

✕ Thao tác hay gặp

kubectl rollout restart deploy/api
# p99 về bình thường... 3 giờ sau lại tăng. Heap, connection, lock lúc lỗi: mất hết

✓ Thao tác nên làm

# < 1 phút giữ bằng chứng, rồi mới 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

Vì sao

• Restart làm triệu chứng biến mất tạm thời và xoá trạng thái cần để tìm nguyên nhân.
• Sự cố quay lại, và bạn bắt đầu điều tra từ con số không.

Hotfix mò liên tục thay vì rollback hoặc tắt flag

✕ Diễn biến hay gặp

14:10 deploy v2.31.1 "try fix timeout"      → vẫn lỗi
14:25 deploy v2.31.2 "tăng pool size"       → vẫn lỗi
14:40 deploy v2.31.3 "revert pool, thêm log" → lỗi khác xuất hiện

✓ Diễn biến nên có

14:10 tắt flag invoice-export (hoặc rollback v2.31 → v2.30)  → p99 giảm
14:15 SLI ổn định, xác nhận nguyên nhân nằm trong v2.31
15:30 sửa có review + test, deploy lại khi bình tĩnh

Vì sao

• Mỗi lần hotfix là một thay đổi chưa test chồng lên hệ thống đang lỗi, mất 10-15 phút chờ pipeline.
• Nhiều thay đổi liên tiếp thì không biết cái nào có tác dụng. Rollback và flag là thao tác rẻ, đã biết trước kết quả.

Status update không có ảnh hưởng và giờ cập nhật kế tiếp

✕ Update hay gặp

Đang check, có vẻ do DB. Sẽ update sau.

✓ Update nên viết

[SEV2][14:35 UTC] Checkout chậm — ĐANG MITIGATE
Ảnh hưởng: ~30% request checkout > 2s từ 14:05 UTC. Không mất dữ liệu.
Đã làm: rollback api v2.31 → v2.30 lúc 14:31, p99 đang giảm.
Cập nhật kế tiếp: 15:00 UTC. IC: @an

Vì sao

• Thiếu ảnh hưởng thì support, sales, quản lý không biết có cần báo khách hay không.
• Thiếu giờ cập nhật kế tiếp thì mọi người nhắn hỏi IC liên tục, kéo IC khỏi việc điều phối.

Postmortem

Postmortem quy lỗi cho cá nhân

✕ Câu hay gặp

Root cause: An quên thêm index cho cột customer_id khi merge PR #812.

✓ Câu nên viết

Root cause: query lọc theo customer_id chạy seq scan trên bảng 40M dòng.
Yếu tố góp phần: review không có bước xem EXPLAIN cho query mới;
staging chỉ có 10k dòng nên không lộ vấn đề.

Vì sao

• Câu “An quên” không sửa được gì, và lần sau người trong cuộc sẽ im lặng — postmortem mất nguồn thông tin tốt nhất.
• Mô tả điều kiện hệ thống mới dẫn tới action item: dữ liệu staging, bước review, lint.

Action item mơ hồ, không owner, không hạn

✕ Action item hay gặp

- Cải thiện monitoring.
- Nhắc team cẩn thận hơn khi thêm query mới.
- Owner: Team backend.

✓ Action item nên viết

1. [detect]  Alert event loop delay max > 200ms trong 5 phút → on-call checkout
   Owner: @binh   Hạn: 2026-10-25   Ticket: OPS-412
2. [prevent] CI chạy EXPLAIN cho query mới trên dataset 1M dòng
   Owner: @an     Hạn: 2026-11-08   Ticket: OPS-413

Vì sao

• “Cẩn thận hơn” không kiểm chứng được và không thay đổi hệ thống; “team” không phải owner nên không ai làm.
• Theo SRE Workbook, action item không có quy trình theo dõi thường bị quên và sự cố lặp lại.

Sai lầm thường gặp

Chỉ viết postmortem cho sự cố lớn. Near-miss và sự cố nhỏ lặp lại là tín hiệu rẻ nhất về điểm yếu hệ thống. Viết postmortem ngắn cho chúng.

Tự kiểm tra

1. Rollback xong nhưng p99 không giảm. Điều đó nói gì về giả thuyết ban đầu, và bước tiếp theo là gì?
2. Vì sao diagnostic report trong Demo 1 không chỉ ra buildInvoiceReportSync? Công cụ nào chỉ ra được?
3. Latency tăng nhưng CPU thấp: bạn nhìn vào ba chỗ nào trước?
4. Viết lại câu “Do An quên thêm index” theo tinh thần blameless và đề xuất một action item loại prevent.

Quay lại: Tổng quan sự cố và postmortem.