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
Cần đọc trước
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.
Vòng lặp giả thuyết
Phần tiêu đề “Vòng lặp giả thuyết”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:
- 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ả”.
- 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.
- 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.
- 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.
- 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ũ.
- 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.
Bộ công cụ Node.js
Phần tiêu đề “Bộ công cụ Node.js”| 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.
SIGUSR1dành cho inspector, report mặc định dùngSIGUSR2. 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-profchỉ ghi khi process thoát bình thường. BịSIGKILL(OOMKilled) hoặcSIGTERMkhông có handler thì không có file — xem Lỗi hay gặp.
Bộ công cụ PostgreSQL
Phần tiêu đề “Bộ công cụ PostgreSQL”| 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 ANALYZEthực sự chạy câu lệnh. VớiUPDATE/DELETE, bọc trongBEGIN; ... ROLLBACK;. Nó vẫn lấy lock và chạy hết thời gian của câu lệnh.pg_blocking_pidscầ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.
npx --prefix examples ts-node examples/src/debugging/event-loop-watchdog.tswindow 1: p50=11.0ms p99=13.7ms max=13.7ms okwindow 2: p50=11.0ms p99=11.8ms max=11.8ms okwindow 3: p50=11.0ms p99=402.7ms max=402.7ms ALERT: event loop bị chặn
Writing Node.js report to file: blocked-loop.jsonNode.js report completed
report: <tmpdir>/diag-wqgGXN/blocked-loop.jsontop-level keys: header, javascriptStack, javascriptHeap, nativeStack, resourceUsage, uvthreadResourceUsage, libuv, workers, userLimits, sharedObjectsheader: { event: 'JavaScript API', trigger: 'API', nodejsVersion: 'v24.17.0', platform: 'darwin'}javascriptStack.message: Error: event loop delay max=403ms > 100msjavascriptStack top frame: at Timeout._onTimeout (examples/src/debugging/event-loop-watchdog.ts:51:3)heap used MB: 118.8cpu user/kernel s: 1.08239 / 0.071247libuv handles: async, async, timer, check, idle, prepare, check, async, timer, timer, loopcó environmentVariables trong file gốc? falsewindow 4: p50=11.0ms p99=11.1ms max=11.1ms okwindow 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ó
max402,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ó
environmentVariablesnhờ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
buildInvoiceReportSynckhô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.
npx --prefix examples ts-node examples/src/debugging/cpu-profile-demo.tshtml 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:
escapeCellchiế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
.cpuprofiletrong Chrome DevTools thay vì tự cộng như script.
Tiếp theo: Giao tiếp khi ứng cứu.