Ở bài trước ta đo speedup và thấy 10 lõi hiếm khi cho 10 lần. Câu hỏi kế tiếp rất thực tế: khi một chương trình đa luồng chậm hơn kỳ vọng, làm sao tìm ra điểm nghẽn? Công cụ tự nhiên là profiler. Nhưng profiler — nhất là loại "phẳng" xếp hạng hàm theo thời gian CPU — có một cách chỉ sai chỗ rất tinh vi với code đồng thời, đủ để bạn tối ưu nhầm hàm hàng tuần liền mà chương trình không nhanh lên chút nào. Tôi dựng một chương trình có nút thắt đồng bộ rõ ràng, đo các tín hiệu mà một profiler thật cung cấp, và chỉ ra tín hiệu nào nói đúng sự thật — trong container gcc:13 (8 luồng, 10 lõi, ARM).
Profiler phẳng chỉ sai chỗ
Một profiler phẳng (flat/self-time) hoạt động bằng cách lấy mẫu con trỏ lệnh nhiều lần mỗi giây, rồi thống kê xem CPU đang ở hàm nào. Kết quả là một bảng xếp hạng "hàm nào ngốn nhiều thời gian CPU nhất". Với code một luồng, đây là vàng: hàm đầu bảng thường đúng là chỗ cần tối ưu.
Với code đa luồng, nó có hai lỗ hổng chết người. Thứ nhất: một luồng đang chờ khóa thì không chạy — nó bị nhân treo trong futex, không tiêu CPU, nên không bị lấy mẫu như code của bạn. Thời gian chờ khóa — thứ có thể chiếm phần lớn wall-clock — gần như vô hình trong hồ sơ phẳng. Thứ hai, hệ quả trực tiếp: hàm chạy bên trong vùng găng (critical section) là thứ duy nhất đang thực sự chạy khi những luồng khác nằm chờ, nên nó nổi lên "nóng" nhất — và bạn bị dụ đi tối ưu chính nó, trong khi vấn đề thật là sự chờ đợi mà nó gây ra cho bảy luồng kia.
Để đọc đúng điểm nghẽn đồng bộ, cần hai tín hiệu khác: (1) tỉ số CPU tổng trên wall-clock — bằng "số lõi hiệu quả" đang chạy; nếu nó thấp hơn số luồng nhiều, các luồng đang chờ chứ không thiếu CPU. Và (2) thời gian chờ khóa trên wall — cao nghĩa là nút thắt là đồng bộ, không phải bản thân hàm.
Đo: hai tín hiệu thật
Tôi cho 8 luồng làm cùng một tổng lượng việc, mỗi vòng gồm phần việc ngoài khóa (song song thật) và một phần nhỏ bên trong một khóa. Chạy hai cấu hình: [A] một khóa chung cho cả 8 luồng, và [B] mỗi luồng một khóa riêng (không tranh chấp). CPU tổng lấy từ getrusage (cộng thời gian mọi lõi), thời gian chờ khóa đo bằng clock_gettime bao quanh pthread_mutex_lock:
tín hiệu | [A] khóa chung | [B] khóa riêng
wall (cùng tổng việc) | 0,652 s | 0,081 s (nhanh 8×)
CPU tổng (u+s, getrusage) | 0,830 s | 0,624 s
song song hiệu quả=CPU/wall | 1,27 lõi | 7,71 lõi
chờ khóa / wall (mỗi luồng) | 81% | 1%
self-time hàm work() | 0,036 s (nóng) | 0,038 s (nóng)
Đọc cấu hình [A]: 8 luồng, 10 lõi, mà song song hiệu quả chỉ 1,27 lõi. Đây là cờ đỏ lớn nhất — bạn xin 8 luồng chạy song song, thực tế chỉ hơn một lõi làm việc tại mỗi thời điểm. Cùng lúc, mỗi luồng dành 81% wall-clock chỉ để chờ khóa. Nút thắt hiện ra rõ mồn một: các luồng xếp hàng trước một khóa chung, tuần tự hóa gần như hoàn toàn, đúng cái lock convoy ta đã đo.
Bây giờ [B] — cùng tổng việc, chỉ đổi khóa chung thành khóa riêng: wall giảm còn 0,081 s, nhanh 8 lần, song song hiệu quả vọt lên 7,71 lõi, chờ khóa chỉ còn 1%. Không một dòng nào của hàm tính toán thay đổi.
Một lần tôi đo hớ: hàm "nóng" lại vô can
Tôi vào đo với hai niềm tin rất phổ biến. Thứ nhất: "hàm nóng nhất trong profiler là chỗ cần tối ưu". Thứ hai: "CPU bận thì nghĩa là thiếu CPU — cần thuật toán nhanh hơn hoặc thêm lõi". Phép đo đa luồng phá cả hai.
Nhìn dòng cuối bảng: trong cả hai cấu hình, hàm work() có self-time gần như y hệt (0,036 và 0,038 s) và trong cả hai nó là hàm nóng nhất hồ sơ phẳng — vì nó là nơi duy nhất CPU thực sự chạy code của tôi. Một profiler phẳng sẽ chỉ vào work() ở cả [A] lẫn [B] và nói "tối ưu tôi đi". Nhưng ở [A], work() hoàn toàn vô can: nó chỉ chạy 0,036 s mỗi luồng, trong khi mỗi luồng mất 0,526 s (81% của 0,652 s) chỉ để chờ. Nếu tôi nghe theo profiler phẳng và mài giũa work() cho nhanh gấp đôi, [A] gần như không nhúc nhích — vì thời gian không nằm trong work(), mà nằm trong sự chờ đợi mà cái khóa chung tạo ra. Thứ thật sự sửa được [A] là tách khóa ([B]) — và nó cho nhanh 8 lần mà không đụng một chữ vào work().
Cái bẫy thứ hai cũng lộ: ở [A], CPU tổng (0,830 s) chỉ nhỉnh hơn wall (0,652 s) một chút. Một người nhìn "CPU đang bận" có thể kết luận "chương trình CPU-bound, cần tối ưu tính toán". Sai — tỉ số CPU/wall = 1,27 tiết lộ rằng phần lớn thời gian không có lõi nào làm việc; chúng đang ngủ chờ khóa. CPU bận không bằng thiếu CPU; thấp so với số luồng nghĩa là đang chờ.
Bài học đo lường: với đa luồng, đừng đọc profiler bằng câu hỏi "hàm nào nóng"; đọc bằng câu hỏi "song song hiệu quả bao nhiêu, và thời gian chờ nằm ở đâu". Hàm nóng nhất trong hồ sơ phẳng thường là nạn nhân — nó là code duy nhất còn chạy được — chứ không phải thủ phạm. Thủ phạm (chờ khóa) trốn khỏi hồ sơ phẳng vì nó không tiêu CPU. Đây cũng là lý do các profiler đồng thời tốt (như "off-CPU profiling", hay đo lock contention riêng) tồn tại: chúng đo cả thời gian không chạy, thứ mà lấy mẫu con trỏ lệnh bỏ sót.
Vì sao điều này quan trọng khi lập trình
Hệ quả đầu tiên: đo song song hiệu quả (CPU tổng / wall) trước khi tin bất kỳ bảng xếp hạng hàm nào. Đây là một phép chia rẻ tiền — getrusage cho CPU tổng, đồng hồ treo tường cho wall — nhưng nó trả lời câu quan trọng nhất: chương trình có thật sự chạy song song không? Nếu bạn có N luồng mà tỉ số chỉ ra 1-2 lõi hiệu quả, thì dù profiler chỉ hàm nào, vấn đề thật là các luồng đang chờ nhau — hãy đi tìm khóa, tranh chấp, hoặc false sharing.
Hệ quả thứ hai: khi nghi ngờ đồng bộ, đo trực tiếp thời gian chờ khóa. Bao clock_gettime quanh chỗ lấy khóa (hoặc dùng công cụ đo lock contention của nền tảng) và xem mỗi luồng dành bao nhiêu phần trăm wall để chờ. 81% như [A] là bản án rõ ràng cho một khóa quá to hoặc quá chung; cách chữa là thu nhỏ vùng găng hoặc tách khóa/sharding, không phải tối ưu code bên trong khóa.
Hệ quả thứ ba là tinh thần đo lường: hàm nóng nhất không phải lúc nào cũng là thủ phạm — đọc đúng tín hiệu mới thấy nút thắt. Con số mang theo: một profiler phẳng xếp hạng hàm theo self-time, nhưng luồng đang CHỜ khóa không chạy nên thời gian chờ vô hình — đo được 8 luồng mà song song hiệu quả chỉ 1,27 lõi (CPU 0,830s / wall 0,652s) vì mỗi luồng chờ khóa chung 81% wall, trong khi hàm work() 'nóng' nhất chỉ chạy 0,036s và hoàn toàn vô can; tách khóa riêng cho cùng tổng việc -> wall 0,081s (nhanh 8×), song song hiệu quả 7,71 lõi, mà work() Y HỆT. Đọc đúng là nhìn CPU/wall và thời gian chờ, đúng tinh thần đo lường vi mô đúng cách — không tin ngay hàm đầu bảng.
Thử ba mươi giây
Lần tới khi một chương trình đa luồng chậm và bạn định mở profiler, hãy làm một phép tính rẻ tiền trước: lấy tổng thời gian CPU (trên Linux, time ./prog cho bạn user+sys) chia cho thời gian thực (real). Nếu chương trình dùng 8 luồng mà tỉ số đó chỉ ra ~1-2, thì dù bảng xếp hạng hàm chỉ vào đâu, sự thật là các luồng đang chờ nhau — và câu hỏi đúng không phải "hàm nào chậm" mà "chúng chờ ở đâu". Ba mươi giây với phép chia CPU-trên-wall đó bắt được điều mà một giờ nhìn bảng self-time có thể bỏ lỡ hoàn toàn: với đồng thời, thời gian đắt nhất thường là thời gian không chạy, và đó chính là thứ một profiler phẳng không thấy.
