Hình dung blocked thread checker như một cái máy báo khói được chỉnh chỉ kêu khi có đám cháy thật to: nó sẽ hú khi cả gian phòng bốc lửa, nhưng đứng im trong khi khói đã dày tới mức mọi người ho sặc sụa. Vặn cho nhạy hơn thì nó lại rú lên với từng làn khói nấu ăn. Vert.x có sẵn một luồng chuyên đi canh xem event loop có bị chặn không — nghe như đúng thứ cần sau phần trước. Bài này đo xem nó thật sự bắt được gì, và vì sao cái ngưỡng của nó là cả vấn đề.
Bốn tham số mặc định
maxEventLoopExecuteTime = 2000 ms
maxWorkerExecuteTime = 60000 ms
blockedThreadCheckInterval = 1000 ms
warningExceptionTime = 5000 ms
Đọc dòng đầu trước khi đọc tiếp: hai giây. Một handler phải giữ event loop hai giây liền thì mới bị coi là có vấn đề.
Cái nó không thấy
Phần trước đo được rằng 16 kết nối gọi một handler ngủ 50 ms làm thông lượng của mọi người khác sập từ 95 424 xuống 9 979 req/s. Chạy lại đúng tải đó với cấu hình mặc định rồi đếm log:
số cảnh báo 'has been blocked': 0
Đây là chỗ hiểu nhầm chết người: blocked thread checker không phải công cụ đo hiệu năng. Nó là công cụ bắt sự cố nặng — một vòng lặp vô hạn, một lời gọi mạng không có phép chờ, một deadlock. Thứ làm hỏng thông lượng hằng ngày nằm hoàn toàn dưới tầm nhìn của nó.
Cái nó thấy
Cho một handler ngủ 7 giây với cấu hình mặc định:
các mốc cảnh báo (ms): 2152, 3156, 4156, 5161, 6161
Cảnh báo đầu tiên ở khoảng 2,1 giây — đúng bằng ngưỡng cộng một chu kỳ kiểm tra — rồi lặp lại mỗi giây cho tới khi luồng được giải phóng. Với block 3 giây thì chỉ có đúng một dòng, nói "bị chặn 2 863 ms".
Stack trace chỉ đúng dòng đang chặn
Phần có giá trị nhất của cảnh báo không phải con số mà là thứ đi kèm nó:
WARN io.vertx.core.impl.BlockedThreadChecker -- Thread Thread[vert.x-eventloop-thread-5,5,main]
has been blocked for 2863 ms
io.vertx.core.VertxException: Thread blocked
at java.base/java.lang.Thread.sleep0(Native Method)
at java.base/java.lang.Thread.sleep(Thread.java:509)
...
Nó chụp ngăn xếp của chính luồng đang bị chặn, tại thời điểm bị chặn. Trong mã thật, dòng đó sẽ chỉ thẳng vào lời gọi JDBC hay readAllBytes mà bạn quên. Đây là lý do đáng để cấu hình nó cho tử tế thay vì tắt đi.
Hạ ngưỡng: đúng nhưng không dùng được như vậy
Đặt ngưỡng 20 ms, chu kỳ kiểm 100 ms, rồi chạy lại đúng tải 50 ms ở trên:
số cảnh báo trong 6 giây tải: 568
Gần 95 cảnh báo mỗi giây. Nó bắt được đúng thứ cần bắt — và ngập log tới mức không ai đọc nổi. Đây chính là lý do cảnh báo của blocked thread checker hay bị bỏ qua: ở mặc định nó im lặng vô ích, hạ xuống thì nó ồn vô ích.
Nên đặt thế nào
Đặt ngưỡng theo ngân sách độ trễ, không theo con số đẹp. Nếu SLA của bạn là p99 dưới 200 ms thì một lần chặn 100 ms đã là nửa ngân sách. Ngưỡng 100–200 ms bắt được thứ đáng bắt mà chưa ngập log.
Đừng để chu kỳ kiểm quá nhỏ. Luồng canh chạy liên tục; chu kỳ 100 ms nghĩa là nó thức dậy mười lần mỗi giây để duyệt mọi event loop. Giữ nó ở 500–1 000 ms trên sản xuất.
Bật ở môi trường phát triển và kiểm thử với ngưỡng thấp. Đó là chỗ 568 cảnh báo là tin tốt: bạn tìm ra chỗ chặn trước khi nó lên sản xuất, và stack trace chỉ thẳng vào dòng mã.
Đừng dùng nó làm cảnh báo chính. Tín hiệu đáng tin để biết event loop có đang khoẻ hay không là độ trễ đuôi — p95 và p99 của chính endpoint đó. Bảng ở phần trước cho thấy p50 nhảy từ 4,6 lên 54 ms trong khi checker không nói gì; con số nào phát hiện sớm hơn thì đã rõ.
new VertxOptions()
.setMaxEventLoopExecuteTime(150)
.setMaxEventLoopExecuteTimeUnit(TimeUnit.MILLISECONDS)
.setBlockedThreadCheckInterval(500);
Nhớ đặt cả đơn vị: mặc định của setMaxEventLoopExecuteTime là nano giây, nên truyền 150 mà quên dòng thứ hai là bạn vừa đặt ngưỡng 150 nano giây và sẽ có cảnh báo cho mọi thứ.
Muốn biết ngay ứng dụng của mình đang bị chặn thế nào thì đếm thẳng trong log:
# dem xem ung dung cua ban dang bi chan bao nhieu lan
grep -c "has been blocked" app.log
grep -m1 -A5 "has been blocked" app.log
Số đếm bằng 0 không có nghĩa là không có gì chặn — nó chỉ có nghĩa là không có gì chặn quá hai giây. Còn dòng stack trace ở lệnh thứ hai là chỗ nhanh nhất để biết phải sửa ở đâu.
Mẫu số chung
Mọi cảnh báo dựa trên ngưỡng đều sống trên một lưỡi dao: đặt cao để bắt thảm hoạ thì mù trước sự suy giảm mãn tính (bỏ sót); đặt thấp để bắt cái nhỏ thì chết đuối trong nhiễu — và một cảnh báo bị chết đuối thì y hệt như không có cảnh báo nào, vì con người sẽ tập bỏ qua nó (đúng cái "alert fatigue" mà mọi đội trực đều biết). Lời giải không phải một con số ma thuật mà là gắn ngưỡng vào một ngân sách thật (SLA độ trễ), và tách vai theo môi trường: nhạy-và-ồn ở dev/test — nơi 568 cảnh báo là tin vui vì bắt lỗi trước khi lên sản xuất — còn trầm-và-chỉ-thảm-hoạ ở production. Cùng bài toán với ngưỡng cảnh báo đĩa, CPU, hàng đợi ở khắp nơi.
Điều thứ hai, và là cái gốc: hãy cảnh báo trên triệu chứng người dùng thật sự cảm thấy, đừng cảnh báo trên một đại lượng nội bộ tiện đo. Công cụ này im lặng khi mất 90% thông lượng vì nó đo "luồng có kẹt quá 2 giây không" — một đại lượng nội bộ chỉ nảy khi cực đoan — trong khi thứ người dùng chịu là độ trễ đuôi (p95/p99), và chính p50/p99 mới báo động sớm. Đây là tinh thần của golden signals / cảnh báo theo triệu chứng trong SRE: đo cái ở rìa hệ thống nơi người dùng chạm vào, không đo cái proxy bên trong. Nhưng đừng vứt cái công cụ nội bộ đi — dùng đúng việc của nó: checker là một máy chẩn đoán tuyệt vời (cái stack trace chỉ thẳng dòng mã chặn) chứ không phải một cái chuông báo. Chuông thì để cho p99; stack trace thì để cho lúc đã biết có chuyện và cần tìm chỗ sửa.
Bài sau: worker verticle và executeBlocking — ba cách chạy đúng những đoạn mã chặn mà phần trước liệt kê.
