Bỏ qua để đến nội dung
Knowledge Hub

Debug theo giả thuyết với bộ công cụ Node.js và PostgreSQL Trung cấp

Thời gian đọc ước tính: 7 phút

Trang này trả lời: debug dưới áp lực thế nào cho có phương pháp, và mỗi câu hỏi thì dùng công cụ Node.js / PostgreSQL nào.

Effective Troubleshooting mô tả quy trình: problem report → triage → examine → diagnose → test/treat. Trong đó ta “lặp lại việc đặt giả thuyết về nguyên nhân và kiểm chứng giả thuyết”.

Đang tải diagram…

Quy tắc khi chạy vòng lặp:

  1. Hỏi “cái gì vừa thay đổi?” đầu tiên. Deploy, config, feature flag, traffic (campaign, bot), dependency (DB failover, nâng cấp thư viện, cert hết hạn). SRE book: thay đổi gần đây là “nơi bắt đầu hiệu quả”.
  2. Mỗi lần đổi một thứ. Đổi pool size và timeout cùng lúc mà hết lỗi, bạn không biết nên giữ thay đổi nào.
  3. Nghĩ tới ngựa trước ngựa vằn (“think of horses not zebras”). Deploy hỏng phổ biến hơn bug kernel.
  4. Tương quan không phải nhân quả. Hai đồ thị cùng tăng có thể cùng do một nguyên nhân thứ ba.
  5. Ghi cả kết quả âm. “Đã kiểm tra DB, không có lock wait” giúp người vào sau không đi lại đường cũ.
  6. Bug tái hiện được nhưng không biết commit nào gây ra? Dùng git bisect run — xem demo git bisect run.
Câu hỏi Công cụ Lệnh
Event loop có bị chặn không? monitorEventLoopDelay (xem bài event loop) Export p99/max ra metric; alert theo max, không theo trung bình
Hàm nào ăn CPU? CPU profile node --cpu-prof --cpu-prof-dir=/tmp/prof app.js (ghi file khi process thoát)
Debug process đang chạy Inspector node --inspect app.js (mặc định 127.0.0.1:9229); process đang chạy: kill -USR1 <pid>
Cái gì giữ memory? Heap snapshot node --heapsnapshot-signal=SIGUSR2 app.js rồi kill -USR2 <pid>; mở .heapsnapshot trong Chrome DevTools
Allocation đến từ đâu? Sampling heap profile node --heap-prof app.js (ghi khi thoát)
Toàn cảnh process lúc này Diagnostic report node --report-on-signal --report-exclude-env app.js rồi kill -USR2 <pid> (signal mặc định SIGUSR2)

Lưu ý khi dùng trên production:

  • Inspector không bao giờ bind ra IP public. Ai kết nối được tới cổng đó có thể chạy code tuỳ ý. Remote thì dùng SSH tunnel hoặc kubectl port-forward.
  • Heap snapshot chặn event loop trong lúc chụp và cần bộ nhớ khoảng gấp đôi heap. Pod có thể bị OOM kill; rút Pod khỏi load balancer trước khi chụp.
  • Report mặc định chứa biến môi trường, nơi thường có secret. Dùng --report-exclude-env (Node 22.13+ / 23.3+) trước khi gửi file cho ai.
  • Mỗi signal một việc. SIGUSR1 dành cho inspector, report mặc định dùng SIGUSR2. Bật cả report lẫn heap snapshot theo signal thì đổi một bên bằng --report-signal. Report theo signal không hỗ trợ trên Windows.
  • --cpu-prof chỉ ghi khi process thoát bình thường. Bị SIGKILL (OOMKilled) hoặc SIGTERM không có handler thì không có file — xem Lỗi hay gặp.
Câu hỏi Truy vấn / cấu hình
Ai đang chạy gì, chờ gì? SELECT pid, state, wait_event_type, wait_event, now() - xact_start AS xact_age, left(query, 80) FROM pg_stat_activity WHERE backend_type = 'client backend' ORDER BY xact_start;
Transaction treo giữ connection ... WHERE state = 'idle in transaction' AND xact_start < now() - interval '1 minute';
Ai chặn ai? SELECT pid, pg_blocking_pids(pid) AS blocked_by, left(query, 80) FROM pg_stat_activity WHERE cardinality(pg_blocking_pids(pid)) > 0;
Lock chi tiết pg_locks join pg_stat_activity theo pid (xem row-level locks)
Query nào chậm? log_min_duration_statement = '500ms' (mặc định -1 = tắt); pg_stat_statements nếu đã cài
Vì sao query chậm? EXPLAIN (ANALYZE, BUFFERS) ... — đọc theo bài EXPLAIN
Huỷ query / ngắt session pg_cancel_backend(pid) huỷ câu đang chạy; pg_terminate_backend(pid) ngắt cả session, rollback transaction — dùng cho idle in transaction

Hai cảnh báo:

  • EXPLAIN ANALYZE thực sự chạy câu lệnh. Với UPDATE/DELETE, bọc trong BEGIN; ... ROLLBACK;. Nó vẫn lấy lock và chạy hết thời gian của câu lệnh.
  • pg_blocking_pids cần truy cập độc quyền ngắn vào lock manager. Gọi liên tục có thể ảnh hưởng hiệu năng; chạy khi cần, đừng đặt trong vòng lặp giám sát dày.

Demo: bắt event loop bị chặn và ghi diagnostic report

Phần tiêu đề “Demo: bắt event loop bị chặn và ghi diagnostic report”

Hai script thuần Node trong examples/src/debugging/, chạy trên Node v24.17.0 (macOS).

Đang tải diagram…

Demo 1 — event-loop-watchdog.ts: mỗi 500 ms đọc histogram monitorEventLoopDelay. Ở giây 1,2 một handler chạy đồng bộ 400 ms. Khi max vượt 100 ms, script gọi process.report.writeReport() vào thư mục tạm, bật excludeEnv và excludeNetwork.

Terminal window
npx --prefix examples ts-node examples/src/debugging/event-loop-watchdog.ts
window 1: p50=11.0ms p99=13.7ms max=13.7ms ok
window 2: p50=11.0ms p99=11.8ms max=11.8ms ok
window 3: p50=11.0ms p99=402.7ms max=402.7ms ALERT: event loop bị chặn
Writing Node.js report to file: blocked-loop.json
Node.js report completed
report: <tmpdir>/diag-wqgGXN/blocked-loop.json
top-level keys: header, javascriptStack, javascriptHeap, nativeStack, resourceUsage, uvthreadResourceUsage, libuv, workers, userLimits, sharedObjects
header: {
event: 'JavaScript API',
trigger: 'API',
nodejsVersion: 'v24.17.0',
platform: 'darwin'
}
javascriptStack.message: Error: event loop delay max=403ms > 100ms
javascriptStack top frame: at Timeout._onTimeout (examples/src/debugging/event-loop-watchdog.ts:51:3)
heap used MB: 118.8
cpu user/kernel s: 1.08239 / 0.071247
libuv handles: async, async, timer, check, idle, prepare, check, async, timer, timer, loop
có environmentVariables trong file gốc? false
window 4: p50=11.0ms p99=11.1ms max=11.1ms ok
window 5: p50=11.0ms p99=11.1ms max=11.1ms ok

Đọc kết quả:

  • Phát hiện đúng: cửa sổ 3 có max 402,7 ms, khớp 400 ms bị chặn; p50 vẫn 11 ms (nền là chu kỳ lấy mẫu 10 ms).
  • Report không có environmentVariables nhờ excludeEnv; secret trong env không lọt vào file.
  • Stack trong report chỉ ra watchdog, không chỉ ra thủ phạm. Report được ghi sau khi block đã xong, nên buildInvoiceReportSync không còn trên stack. Heap 118 MB chủ yếu là ts-node.

Bài học: diagnostic report trả lời “process đang ở trạng thái nào” (heap, handle, CPU, phiên bản). Muốn biết hàm nào chặn loop, cần CPU profile.

Demo 2 — cpu-profile-demo.ts: chạy process con với --cpu-prof; handler render HTML hoá đơn nối chuỗi 1,5 triệu lần. Sau đó đọc file .cpuprofile và cộng self-time theo hàm.

Terminal window
npx --prefix examples ts-node examples/src/debugging/cpu-profile-demo.ts
html length 72388890
profile: CPU.<ts>.<pid>.0.001.cpuprofile (506 samples)
Top self-time:
300 ms 46.7% (garbage collector)
253 ms 39.3% escapeCell app.js:3
26 ms 4.0% renderInvoiceHtmlSync app.js:4
25 ms 3.9% RegExp: [<>&"]
20 ms 3.1% (anonymous) app.js:3
  • Profile chỉ đúng tên hàm và dòng: escapeCell chiếm 39% self-time.
  • Gần một nửa thời gian là garbage collector — dấu hiệu code tạo quá nhiều chuỗi tạm.
  • Trên production, thường mở file .cpuprofile trong Chrome DevTools thay vì tự cộng như script.

Tiếp theo: Giao tiếp khi ứng cứu.