Khi một request HTTP đi qua ba dịch vụ, trace id theo nó suốt chặng đường vì mọi thư viện HTTP đều biết chuyện đó. Qua broker thì không. Bài này đo chỗ ngữ cảnh bị đứt và chi phí nối lại.

Ngăn xếp lời gọi đứt ở chỗ gửi

Đặt trace id vào MDC ở bên gửi, rồi đọc ở listener:

bên gửi   : MDC[traceId] = trace-abc-123
bên nhận  : MDC[traceId] = null | header = null

Cả hai đều null. Lý do hiển nhiên khi nói ra: listener chạy trên luồng khác, trong tiến trình khác, có thể trên máy khác. MDC là biến cục bộ luồng; nó không có cách nào đi theo một mảng byte qua socket.

Hệ quả thực tế: log của bên gửi và bên nhận không nối được với nhau. Khi một đơn hàng xử lý sai, bạn có hai đống log rời rạc và chỉ còn cách khớp theo thời gian — cách gỡ lỗi tệ nhất, và nó tệ nhất đúng vào lúc hệ thống đang tải cao, khi có hàng nghìn thông điệp trong cùng một giây.

Gắn vào header rồi khôi phục

Thông điệp có sẵn chỗ để chở dữ liệu kèm — phần 7 đã mổ bảng header. Bên gửi dùng MessagePostProcessor:

MessagePostProcessor ganTrace = m -> {
    String id = MDC.get("traceId");
    if (id != null) m.getMessageProperties().setHeader("traceId", id);
    return m;
};

tpl.convertAndSend("don-moi", don, ganTrace);

Bên nhận khôi phục vào MDC, và nhớ xoá đi sau khi xong:

@RabbitListener(queues = "don-moi")
public void nhan(Message m) {
    Object id = m.getMessageProperties().getHeaders().get("traceId");
    if (id != null) MDC.put("traceId", id.toString());
    try {
        xuLy(m);
    } finally {
        MDC.remove("traceId");     // bắt buộc
    }
}
bên nhận  : MDC[traceId] = trace-abc-123

Giờ hai đống log nối lại được bằng một lệnh grep.

Cái giá: 10%

20 000 thông điệp, có và không có post-processor, hâm nóng trước, trung vị 3 lượt:

Thông lượng
Không gắn gì 373 839 msg/s
Có gắn header traceId 338 314 msg/s (90%)

Mất 10% thông lượng cho khả năng gỡ lỗi xuyên dịch vụ. Với gần như mọi hệ thống, đó là món hời — nhưng đáng biết con số, vì nó không phải bằng không như nhiều người vẫn nghĩ về "chỉ thêm một header".

Ba chi tiết hay bỏ sót

Phải MDC.remove trong finally. Luồng consumer được tái dùng cho thông điệp tiếp theo. Quên xoá thì thông điệp sau thừa hưởng trace id của thông điệp trước — và loại log sai đó tệ hơn không có log, vì nó dẫn người gỡ lỗi đi đúng hướng… nhầm.

Chuỗi trong header quay về không phải String. Phần 7 đo được rằng client Java trả LongString; header.equals("abc") cho false trong khi in ra vẫn thấy abc. Luôn .toString() như đoạn mã trên.

Dùng tên header chuẩn. traceparent theo W3C Trace Context thay vì traceId tự đặt — để các công cụ truy vết nhận ra mà không cần cấu hình thêm, và để dịch vụ viết bằng ngôn ngữ khác hiểu được. Đây là hợp đồng giữa các dịch vụ, cùng loại với tên logic của __TypeId__phần 26.

Còn cách tự động thì sao

Spring Boot hiện đại có sẵn cơ chế quan sát cho RabbitTemplate và listener container, và khi có thư viện truy vết trong classpath thì việc truyền ngữ cảnh diễn ra tự động — không cần post-processor viết tay. Tôi không đo phần đó trong bài này nên không đưa ra con số nào; nếu bạn đã có hệ truy vết phân tán, hãy bật nó và kiểm tra bằng chính phép thử ở đầu bài: gửi một thông điệp, xem bên nhận có đọc được trace id không.

Cách thủ công ở trên vẫn đáng biết, vì nó cho thấy chính xác thứ đang xảy ra bên dưới — và vì nó chạy được ở bất kỳ đâu, kể cả trong một dịch vụ nhỏ không có hạ tầng quan sát nào.

Bài sau: sang chặng vận hành — hàng đợi phình to, bộ nhớ broker, và chuyện gì xảy ra khi một triệu thông điệp nằm chờ.

Thử ba mươi giây

# thong diep trong hang doi co mang trace id khong
curl -su guest:guest -X POST 'localhost:15672/api/queues/%2F/<ten>/get' \
  -H 'Content-Type: application/json' \
  -d '{"count":3,"ackmode":"ack_requeue_true","encoding":"auto"}' \
  | jq '.[].properties.headers'

Không thấy traceId hay traceparent nghĩa là mọi thông điệp trong hàng đợi đó đang là ngõ cụt cho việc gỡ lỗi — biết nó đến từ đâu là chuyện của may mắn.