Bạn có một service chậm dưới tải. CPU profile cho thấy... không có gì đặc biệt — không hàm nào ngốn CPU. Nhưng nó vẫn chậm. Vì sao? Rất có thể vì tranh chấp khóa: các goroutine dành phần lớn thời gian chờ mutex, không phải chạy. CPU profile mù trước điều này (goroutine chờ không dùng CPU). Công cụ đúng là mutex profile — nó đo chính xác thời gian goroutine bị chặn bởi khóa. Bài này đo thật và chỉ cách tìm ra khóa nghẽn.

Bật mutex profile

Mutex profile tắt mặc định (vì có chi phí). Bật bằng một dòng:

runtime.SetMutexProfileFraction(1)
// 0 = tắt (mặc định)
// 1 = ghi MỌI sự kiện chặn (chi tiết nhất, tốn hơn)
// n = lấy mẫu 1/n sự kiện (nhẹ hơn cho production)

Với production, dùng n lớn (ví dụ 100) để giảm chi phí; với debug cục bộ, dùng 1 để thấy đầy đủ.

Ảnh chụp đoạn mã Go nền tối minh hoạ đo tranh chấp khoá bằng mutex profile, benchmark cho biết chậm nhưng không cho biết khóa nào là nút thắt mutex profile đo thời gian goroutine phải chờ khóa, một bật mutex profile runtime.SetMutexProfileFraction 1 0 tắt mặc định 1 ghi mọi sự kiện chặn chi tiết tốn hơn n lấy mẫu 1 trên n sự kiện nhẹ hơn cho production, hai ghi profile ra file f bằng os.Create mutex.pprof pprof.Lookup mutex WriteTo f 0 f.Close hoặc benchmark go test bench dấu chấm mutexprofile mutex.pprof hoặc HTTP import net http pprof debug pprof mutex, ba phân tích go tool pprof top unit ms mutex.pprof Type delay bằng tổng thời gian các goroutine chờ khóa hàm nào có delay lớn khóa của nó là nút thắt tranh chấp go tool pprof http 8080 mutex.pprof xem đồ thị lửa flame mutex profile đo tranh chấp thời gian chờ khác CPU profile thời gian chạy một khóa tranh chấp cao không tốn CPU nhưng làm goroutine chờ CPU profile không thấy, bốn sửa tranh chấp sau khi tìm ra sharding chia 1 khóa N khóa mỗi shard riêng atomic RWMutex đọc nhiều atomic.Pointer hoặc RWMutex giảm vùng khóa giữ khóa ngắn nhất có thể ít việc trong critical section copy-on-write đọc không khóa bài atomic.Pointer

Hình 1: Mutex profile. Bật bằng SetMutexProfileFraction, ghi bằng pprof.Lookup("mutex"), phân tích bằng go tool pprof, và cách sửa tranh chấp.

Ghi và phân tích

Ghi profile ra file (hoặc dùng -mutexprofile với go test, hoặc HTTP /debug/pprof/mutex):

f, _ := os.Create("mutex.pprof")
pprof.Lookup("mutex").WriteTo(f, 0)
f.Close()

Phân tích bằng go tool pprof -top -unit=ms mutex.pprof. Loại profile là delay — tổng thời gian các goroutine chờ khóa. Hàm nào có delay lớn → khóa của nó là nút thắt.

Đo thật: 20,8 giây chờ ở một khóa

Cho 10 goroutine tranh một mutex nóng (giữ khóa 10µs mỗi lần), và một goroutine dùng mutex nguội:

Ảnh chụp bảng kết quả đo thật nền tối mutex profile chỉ ra 20,8 giây chờ ở khóa nóng go run cộng go tool pprof top unit ms Go 1.23 arm64 10 core 10 goroutine tranh 1 mutex, output go tool pprof top mutex.pprof Type delay tổng thời gian goroutine chờ khóa Showing nodes accounting for 20863.73ms 100% of total flat flat% cum cum% 20863.73ms 100% 20863.73ms 100% sync Mutex Unlock 0 0% 20863.73ms 100% main.main.func1 goroutine mutex nóng 20,8 giây tổng thời gian chờ cộng dồn 10 goroutine tranh muNong trong vài giây thực 100% quy về func1 đúng goroutine giữ mutex nóng mutex nguội muNguoi không xuất hiện bị drop vì tranh chấp không đáng kể, vì sao mutex profile khác CPU profile CPU profile thời gian chạy goroutine đang làm việc mutex profile thời gian chờ khóa goroutine bị chặn không dùng CPU khóa tranh chấp cao goroutine chờ nhiều CPU thấp CPU profile không thấy chỉ mutex profile bắt được, quy trình tìm và sửa tranh chấp 1 SetMutexProfileFraction 1 hoặc mutexprofile 2 pprof top tìm hàm có delay lớn nhất 3 hàm đó dùng khóa nào đó là nút thắt 4 sửa sharding atomic RWMutex giảm vùng khóa, cốt lõi mutex profile đo tổng thời gian goroutine chờ khóa contention bật runtime.SetMutexProfileFraction 1 mutexprofile đo thật 20,8s chờ 100% ở khóa nóng khóa nguội bị drop khác CPU đo chờ khóa bị chặn không phải chạy sửa sharding atomic RWMutex giảm vùng khóa

Hình 2: go tool pprof -top cho Type: delay = 20.863ms (20,8 giây) tổng thời gian chờ, 100% quy về main.main.func1 (goroutine mutex nóng). Mutex nguội không xuất hiện.

Output cho 20.863ms = 20,8 giây tổng thời gian chờ (cộng dồn 10 goroutine tranh khóa trong vài giây thực), và 100% quy về main.main.func1 — đúng goroutine giữ mutex nóng. Mutex nguội (muNguoi) không xuất hiện trong profile vì tranh chấp không đáng kể (bị drop). Profile chỉ thẳng vào thủ phạm.

Vì sao mutex profile khác CPU profile

Đây là điểm cốt lõi:

  • CPU profile: đo thời gian chạy — goroutine đang làm việc thật.
  • Mutex profile: đo thời gian chờ khóa — goroutine bị chặn, không dùng CPU.

Một khóa tranh chấp cao khiến goroutine chờ nhiều mà CPU thấp — CPU profile không thấy gì, chỉ mutex profile bắt được. Đây là lý do khi service "chậm mà CPU không cao", mutex profile (và block profile — họ hàng của nó) là công cụ đầu tiên nên xem.

Ứng dụng thực tế

Chẩn đoán "chậm mà CPU thấp". Khi throughput không tăng dù thêm core, hoặc độ trễ cao mà CPU nhàn, gần như chắc là tranh chấp khóa (hoặc I/O). Bật mutex profile để xác nhận và tìm khóa cụ thể — đừng đoán.

Bật -mutexprofile trong benchmark. go test -bench . -mutexprofile mutex.pprof cho profile tranh chấp của benchmark. Rất hữu ích khi so hai cài đặt: xem cái nào tranh chấp ít hơn, không chỉ nhanh hơn trung bình.

Đặt endpoint pprof trên production. Import _ "net/http/pprof" mở /debug/pprof/mutex. Với SetMutexProfileFraction(100) (lấy mẫu nhẹ), bạn có thể lấy mutex profile từ production đang chạy để tìm nút thắt thật dưới tải thật — an toàn hơn nhiều so với tái hiện cục bộ.

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

Mutex profile có chi phí — chọn fraction cẩn thận. SetMutexProfileFraction(1) ghi mọi sự kiện chặn, tốn thêm CPU và bộ nhớ. Trên production dùng giá trị lớn (100–1000) để lấy mẫu nhẹ; số liệu vẫn đủ tìm nút thắt lớn. Đừng để fraction=1 chạy production lâu dài.

Profile chỉ thấy tranh chấp đã xảy ra. Mutex profile ghi các sự kiện chặn thật trong lần chạy đó. Nếu tải test không tạo ra tranh chấp giống production, profile bỏ sót. Như mọi profiling, chạy trên tải đại diện — hoặc lấy từ production.

Tìm được khóa nghẽn mới là nửa việc. Profile chỉ ra khóa nào tranh chấp, không chỉ cách sửa. Các hướng sửa (đã học ở loạt bài trước): sharding (chia một khóa thành N khóa theo shard), atomic/RWMutex cho đọc-nhiều, copy-on-write với atomic.Pointer, hoặc đơn giản là giảm vùng khóa (giữ khóa ngắn nhất có thể, ít việc trong critical section). Chọn theo mẫu truy cập.

Ba ý mang về

  1. Mutex profile đo tổng thời gian goroutine CHỜ khóa (tranh chấp), thứ CPU profile không thấy: đo thật, 10 goroutine tranh một mutex nóng tích lũy 20,8 giây chờ, 100% quy về đúng khóa đó, còn mutex nguội bị loại khỏi profile vì tranh chấp không đáng kể.
  2. Bật bằng runtime.SetMutexProfileFraction(1) (hoặc -mutexprofile/HTTP), phân tích bằng go tool pprof: loại profile là delay, hàm có delay lớn nhất chỉ ra khóa nghẽn — dùng fraction lớn (100+) cho production để lấy mẫu nhẹ.
  3. Mutex profile là công cụ số một cho "chậm mà CPU thấp": khóa tranh chấp cao làm goroutine chờ (không dùng CPU) nên CPU profile mù — sau khi tìm ra khóa, sửa bằng sharding, atomic/RWMutex, copy-on-write, hoặc giảm vùng khóa; nhưng profile phải chạy trên tải đại diện mới bắt đúng tranh chấp.

Phần sau ta chuyển sang một chủ đề nền tảng khác của Go nâng cao — phản chiếu kiểu lúc chạy: Phần sau mổ xẻ package reflect — Type và Value, cách kiểm và thao tác giá trị mà không biết kiểu lúc biên dịch, và chi phí thật của reflection.