Bài trước đã dùng GODEBUG=gctrace=1 để đo thời gian dừng GC. Nhưng mỗi dòng gctrace chứa cả chục con số, và nếu không biết đọc thì nó chỉ là mớ số vô nghĩa. Đây là công cụ chẩn đoán GC mạnh nhất mà không cần cài gì thêm — chỉ một biến môi trường. Bài này giải mã từng trường trên một dòng thật, rồi chỉ ba dấu hiệu bạn đọc được ngay để biết GC có vấn đề hay không.

Giải mã một dòng gctrace

Lấy một dòng thật từ container Go 1.23:

gc 7 @0.085s 9%: 0.004+11+0.026 ms clock, 0.045+0.009/33/64+0.26 ms cpu, 113->121->100 MB, 133 MB goal, 0 MB stacks, 0 MB globals, 10 P

Ảnh chụp bảng giải mã nền tối đọc GODEBUG gctrace 1 từng trường, dòng gc 7 at 0.085s 9 phần trăm 0.004 cộng 11 cộng 0.026 ms clock 0.045 cộng 0.009 chia 33 chia 64 cộng 0.26 ms cpu 113 tới 121 tới 100 MB 133 MB goal 0 MB stacks 0 MB globals 10 P, gc 7 chu kỳ GC thứ 7 kể từ khi chương trình chạy, at 0.085s thời điểm bắt đầu chu kỳ này 85 ms sau khi khởi động, 9 phần trăm phần trăm tổng CPU dành cho GC tính từ đầu chương trình, 0.004 cộng 11 cộng 0.026 thời gian tường wall 3 pha STW kết thúc quét cộng mark đồng thời cộng STW kết thúc mark chỉ 0.004 và 0.026 ms là dừng chương trình 11 ms mark chạy song song, ms cpu thời gian CPU gộp mọi P 3 pha giữa 0.009 chia 33 chia 64 bằng assist chia worker nền chia idle mark, 113 tới 121 tới 100 heap MB lúc bắt đầu GC tới lúc kết thúc GC tới heap sống sau quét, 133 MB goal ngưỡng heap kích hoạt GC lần sau heap chạm 133 MB chạy GC, 0 MB stacks bộ nhớ stack goroutine được quét, 0 MB globals bộ nhớ biến toàn cục, 10 P số processor logic GOMAXPROCS

Hình 1: Giải mã từng trường của một dòng gctrace. Màu sắc ứng với vị trí trên dòng — thời gian ba pha, heap trước-đỉnh-sau, ngưỡng goal, và số P.

Đọc lần lượt:

  • gc 7: đây là chu kỳ GC thứ 7 kể từ khi chương trình khởi động.
  • @0.085s: chu kỳ này bắt đầu ở mốc 85 ms. So sánh mốc này giữa các dòng cho biết GC chạy dày hay thưa.
  • 9%: tổng cộng 9% CPU đã dành cho GC tính từ đầu chương trình. Con số cộng dồn, không phải của riêng chu kỳ này.
  • 0.004+11+0.026 ms clock: thời gian tường (wall-clock) của ba pha — STW kết thúc quét (0,004) + mark đồng thời (11) + STW kết thúc mark (0,026). Chỉ hai số đầu-cuối là dừng chương trình; 11 ms ở giữa chạy song song.
  • 0.045+0.009/33/64+0.26 ms cpu: thời gian CPU (cộng trên mọi P) của ba pha. Ba số ở giữa (0.009/33/64) tách pha mark thành: thời gian assist (goroutine phải phụ giúp GC khi cấp phát quá nhanh) / worker nền chuyên trách / idle (mark tranh thủ lúc P rảnh).
  • 113->121->100 MB: heap lúc bắt đầu GC (113) → lúc kết thúc GC (121, vì chương trình vẫn cấp phát trong pha mark) → heap sống sau khi quét bỏ rác (100). Số thứ ba là quan trọng nhất.
  • 133 MB goal: ngưỡng heap kích hoạt GC lần sau — khi heap chạm 133 MB, GC tiếp theo sẽ chạy.
  • 0 MB stacks, 0 MB globals: bộ nhớ stack goroutine và biến toàn cục được quét.
  • 10 P: số processor logic (GOMAXPROCS).

Ba dấu hiệu đọc được ngay

Bạn không cần hiểu hết mọi trường để chẩn đoán. Ba con số này nói gần hết:

Ảnh chụp bảng kết quả đo thật nền tối chẩn đoán từ gctrace Go 1.23 arm64, gc 4 at 0.017s 9 phần trăm 0.003 cộng 3.4 cộng 0.025 ms clock 21 tới 24 tới 22 MB 25 MB goal, gc 5 at 0.031s 38 tới 40 tới 37 MB 45 MB goal, gc 6 at 0.050s 64 tới 70 tới 66 MB 75 MB goal, gc 7 at 0.085s 113 tới 121 tới 100 MB 133 MB goal, ba dấu hiệu đọc được ngay, 1 tần suất at 0.017 tới 0.031 tới 0.050 tới 0.085 khoảng cách giãn ra heap lớn dần GC chạy thưa hơn bình thường nếu at time sát nhau liên tục GC quá dày thường do cấp phát nhiều, 2 heap sống số thứ 3 22 tới 37 tới 66 tới 100 MB tăng đều heap sống phình nếu tăng mãi không giảm nghi rò bộ nhớ, 3 goal luôn khoảng 2 lần heap sống 100 MB sống tới 133 goal mặc định GOGC 100 GC sẽ chạy khi heap chạm goal

Hình 2: Ba dấu hiệu — (1) tần suất từ mốc @time, (2) heap sống (số thứ ba) có tăng mãi không, (3) goal gấp đôi heap sống. Đọc chuỗi dòng gctrace cho bức tranh xu hướng.

1. Tần suất GC — từ mốc @time. Khoảng cách giữa các dòng: @0.017 → 0.031 → 0.050 → 0.085. Ở đây khoảng cách giãn ra (14ms, 19ms, 35ms) — bình thường, vì heap lớn dần nên GC chạy thưa hơn. Nếu các mốc @time sát nhau liên tục (vài ms một lần), GC đang chạy quá dày — thường do chương trình cấp phát rác quá nhanh.

2. Heap sống có phình không — số thứ ba của heap. 22 → 37 → 66 → 100 MB: đây là lượng bộ nhớ thật sự sống sau mỗi lần quét. Nếu con số này tăng mãi không bao giờ giảm qua thời gian dài, đó là dấu hiệu kinh điển của rò bộ nhớ — có gì đó giữ tham chiếu không thả. (Ở đây nó tăng vì chương trình đang dựng cấu trúc lớn dần, không phải rò.)

3. Ngưỡng goal — mặc định gấp đôi heap sống. 100 MB sống → 133 MB goal. Với GOGC=100 (mặc định), Go đặt goal ≈ 2× heap sống: GC lần sau chạy khi heap tăng gấp đôi. Đây là "van điều tiết" — bài sau sẽ mổ xẻ cách GOGC điều khiển nó.

Ứng dụng thực tế

Bật gctrace tạm thời trên production để chẩn đoán. Khi nghi GC gây vấn đề, chạy dịch vụ với GODEBUG=gctrace=1 một lúc và gom log. Không cần công cụ ngoài, không sửa code. Xem tần suất và heap sống là biết ngay GC có phải thủ phạm không.

Số STW dài là cờ đỏ độ trễ. Nếu số đầu hoặc cuối của phần clock (STW) lên tới nhiều mili-giây (thay vì vài chục micro-giây), có vấn đề — thường do quá nhiều goroutine (quét stack lâu) hoặc heap khổng lồ. Đây là con số cần theo dõi cho dịch vụ nhạy độ trễ.

Cột % cao nghĩa là GC ngốn CPU. Nếu phần trăm CPU dành cho GC (số sau @time) lên 20-30%+, chương trình đang tốn phần lớn CPU để gom rác — dấu hiệu nên giảm cấp phát (các bài tái dùng buffer, sync.Pool) hoặc chỉnh GOGC.

Đánh đổi cần cân nhắc

gctrace tốn chi phí I/O — chỉ bật khi cần. Mỗi chu kỳ GC in một dòng ra stderr; với GC dày, đó là nhiều dòng mỗi giây, tốn I/O và làm nhiễu log. Bật để chẩn đoán rồi tắt, đừng để chạy thường trực trên production.

gctrace là ảnh chụp thô, không thay được profiling. Nó cho xu hướng heap và thời gian GC, nhưng không cho biết cái gì cấp phát (hàm nào, kiểu nào). Để tìm nguồn rác, cần heap profiling (pprof) — chủ đề sau. gctrace trả lời "GC có vấn đề không", pprof trả lời "vì sao".

Con số phụ thuộc workload và thời điểm. Một dòng gctrace đơn lẻ ít ý nghĩa; phải đọc chuỗi dòng để thấy xu hướng. Heap sống dao động lên xuống là bình thường; chỉ xu hướng tăng đơn điệu dài hạn mới đáng lo.

Ba ý mang về

  1. Mỗi dòng gctrace kể một chu kỳ GC với các trường cố định: chu kỳ, mốc thời gian, %CPU, thời gian ba pha (STW + mark đồng thời + STW), heap trước-đỉnh-sau, ngưỡng goal, stacks/globals, số P — số STW ở phần clock là thời gian dừng chương trình.
  2. Ba dấu hiệu chẩn đoán nhanh: tần suất từ mốc @time (sát nhau = GC quá dày), heap sống (số thứ ba) tăng mãi = nghi rò bộ nhớ, và goal gấp đôi heap sống (mặc định GOGC=100).
  3. gctrace là chẩn đoán không cần công cụ: bật GODEBUG=gctrace=1 tạm thời để biết GC có phải thủ phạm — nhưng nó chỉ cho xu hướng, cần pprof để tìm nguồn rác cụ thể; STW dài và %CPU cao là hai cờ đỏ chính.

Phần sau ta mổ xẻ chính con số goal vừa nhắc và cách điều khiển nó: Phần sau đo GC pacing và biến GOGC — cách nó đánh đổi giữa tần suất GC và dung lượng bộ nhớ, và GOMEMLIMIT bổ trợ thế nào.