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ì.
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ứ.
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ê.
Thử ba mươi giây
# 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.
