Công cụ này chỉ chậm 2 lần thay vì 446 lần, thấy cả máy chứ không phải một tiến trình, và moi ra được lần gọi chậm gấp nghìn lần trung vị mà trung bình, p99 đều giấu

Hãy hình dung bạn muốn biết trong nhà mình ổ điện nào ngốn nhiều điện nhất. Cách của strace giống như: rút phích một thiết bị ra, cắm đồng hồ đo vào giữa, cắm lại, ghi số, rồi làm lại với thiết bị kế tiếp — mỗi lần đo là một lần ngắt dòng. Cách của eBPF thì khác hẳn: nó gắn một cảm biến tí hon vào ngay trong bảng điện, và từ đó đọc được dòng điện của mọi ổ cùng lúc mà không phải rút gì cả. Đó là toàn bộ câu chuyện của bài này, và con số đo được nói rõ khác biệt ấy lớn tới mức nào.

Phần 37 đo strace chậm 446 lần. Phần 38 đo perf gần như miễn phí nhưng chỉ thấy CPU. Bài này đo công cụ thứ ba, và nó không giống cả hai — không phải vì nó nhanh hơn, mà vì nó đứng ở một chỗ khác để nhìn.

Chi phí: 2 lần, không phải 446

Cùng chương trình gọi write() 300.000 lần:

Hai lần, so với bốn trăm bốn mươi sáu lần của strace. Chênh nhau hơn hai bậc độ lớn, và lý do nằm gọn ở chỗ mỗi công cụ đứng đâu để đo.

strace dừng tiến trình lại, rồi đọc thanh ghi từ bên ngoài — mỗi lời gọi hệ thống là một cú dừng-đọc-thả, hai lần chuyển ngữ cảnh. eBPF làm ngược lại: nó nạp chương trình của bạn vào chính nhân, chạy nó ngay tại điểm đo, và cập nhật một bảng nằm trong nhân. Không tiến trình nào bị dừng, không dữ liệu nào bị chép ra ngoài trong lúc chạy. Cái cảm biến ở ngay trong bảng điện, không phải cái đồng hồ cắm chen vào giữa.

Nó thấy cả máy trong một lần đo

Một dòng lệnh, đếm vfs_write theo tên tiến trình:

bpftrace -e 'kprobe:vfs_write { @[comm] = count(); }'

s                300.001        kube-apiserver        40
kubelet               17        kube-controller       16
etcd                  15        containerd             7
kube-proxy             2        metrics-server         1

Chương trình của tôi, và mọi tiến trình khác trên máy chủ, hiện ra trong cùng một lần đo. strace không làm nổi việc này — nó gắn vào một tiến trình cụ thể. Muốn biết "cái gì trên máy này đang ghi đĩa nhiều nhất" bằng strace thì phải gắn vào từng cái một, và mỗi lần gắn làm chậm 446 lần. Với eBPF, bạn hỏi cả máy một câu và trả lời về ngay.

Cái nó thấy mà công cụ khác mù hẳn

Đây mới là phần tôi thấy đáng giá nhất. Phân bố độ trễ của vfs_write, đơn vị nano giây:

[64, 128)          90.982  ██████████████████████
[128, 256)        206.748  ████████████████████████████████████████████████████
[256, 512)            620
[512, 1K)           1.278
[1K, 2K)              345
[2K, 4K)               68
[4K, 8K)              180
[8K, 16K)             134
[16K, 32K)             58
[32K, 64K)             15
[128K, 256K)            1

Trung vị nằm trong khoảng 128–256 ns. Nhưng nhìn xuống dòng cuối: có một lần gọi mất 128–256 micro giây — chậm gấp khoảng một nghìn lần phần còn lại.

Trung bình không thấy nó. Trung vị không thấy nó. Ngay cả p99 cũng không thấy — một trên ba trăm nghìn là phân vị 99,9997, nằm xa hơn cả p99 rất nhiều. Chỉ khi bạn ghi từng lần gọi vào một bảng phân phối — đúng cái việc eBPF làm ngay trong nhân với chi phí không đáng kể — thì cái đuôi đó mới lộ ra.

Tôi muốn nói lại lần nữa, vì đây là lý do tồn tại của cả công cụ: eBPF không đo nhanh hơn, nó đo được thứ khác. Nó biến một con số "trung bình 150 ns" thành cả một phân bố, và đuôi của phân bố mới là nơi sự cố thật sự sinh ra — cái request lâu lâu treo một nhịp, cái lần fsync xui xẻo, cái lock thỉnh thoảng kẹt.

Đoạn mã tạo ra biểu đồ trên, vỏn vẹn bốn dòng:

bpftrace -e '
kprobe:vfs_write    { @t[tid] = nsecs; }
kretprobe:vfs_write /@t[tid]/ { @ns = hist(nsecs - @t[tid]); delete(@t[tid]); }
END { clear(@t); }'

Cái bẫy tôi vấp: nhân "không hỗ trợ gì cả"

Lần chạy đầu tiên trong container, bpftrace báo:

ERROR: tracepoint not found: syscalls:sys_enter_write

Và bpftrace -l 'kprobe:*' trả về 0 dòng — nghe như nhân này chẳng hỗ trợ gì. Tôi suýt đi tìm một image nhân khác. May là dừng lại kịp, vì nguyên nhân thật nhỏ xíu: tracefs chưa được gắn.

mount -t tracefs none /sys/kernel/tracing

Sau đúng lệnh đó, 2.955 sự kiện xuất hiện và mọi thứ chạy. Thông báo lỗi gợi ý sai hoàn toàn — nó nghe như nhân thiếu tính năng, trong khi vấn đề chỉ là một điểm gắn kết chưa được mount. Nếu bạn gặp nó trong container, kiểm tra ls /sys/kernel/tracing/available_events trước đã, đừng vội đổ cho nhân.

Ba điều kiện để eBPF chạy được, kiểm nhanh:

ls /sys/kernel/btf/vmlinux                    # co BTF -> chuong trinh chay duoc tren nhieu nhan
ls /sys/kernel/tracing/available_events       # tracefs da gan
zgrep CONFIG_BPF_SYSCALL /proc/config.gz      # nhan bat eBPF

Trong container cần --privileged, hoặc tối thiểu CAP_BPF và CAP_PERFMON (nhân 5.8 trở lên).

Không phải lúc nào cũng tự viết

bcc-tools có sẵn hơn 100 công cụ dựng sẵn, phần lớn việc thường ngày đã có người viết hộ:

execsnoop giải một lớp vấn đề mà không công cụ nào khác giải nổi: tiến trình sống quá ngắn để ps hay top bắt kịp. Một script chạy mỗi giây và tồn tại 5 ms là vô hình với mọi công cụ lấy mẫu — nhưng execsnoop bắt nó ngay lúc nó sinh ra. Còn runqlat và offcputime lấp đúng chỗ mà phần 38 nói perf mù: thời gian không chạy trên CPU.

Giới hạn thật, nói thẳng

Cần quyền cao. eBPF là nạp mã vào nhân. Nó cần CAP_BPF hoặc root, và trên nhiều hệ thống được quản lý chặt thì bị chặn hẳn — đừng trông đợi chạy được nó trên máy chủ của người khác.

kprobe bám vào tên hàm của nhân, và tên đó đổi. Một script dùng kprobe:vfs_write chạy ngon trên nhân 5.10 có thể im lặng không chạy trên 6.1. Tracepoint ổn định hơn nhiều và nên ưu tiên khi có.

Chi phí không phải bằng 0. 2× trong phép đo ở trên. Với hàm được gọi hàng triệu lần mỗi giây, con số đó vẫn đáng cân nhắc — gắn kprobe vào một hàm nóng trong nhân là một cách làm chậm cả máy mà không ai ngờ.

Bộ kiểm tra từ chối nhiều thứ. Chương trình eBPF phải chứng minh được là nó dừng, không truy cập bộ nhớ ngoài phạm vi, và đủ nhỏ. Vòng lặp không giới hạn bị từ chối thẳng. Điều này làm eBPF an toàn khi chạy trong nhân, nhưng cũng khiến viết script phức tạp trở nên khó.

Mẫu số chung: đứng trong đường thực thi, đo tại chỗ

Cái ý tưởng cốt lõi của eBPF — thay vì dừng-và-nhìn-từ-ngoài thì nhúng đoạn đo vào bên trong nơi việc xảy ra — không riêng gì nhân Linux. Nó lặp lại ở mọi tầng.

Trong thế giới Java, đúng ranh giới này là JFR (Java Flight Recorder) so với các profiler chèn bytecode kiểu cũ. JFR gắn điểm đo ngay trong JVM, ghi sự kiện vào một vòng đệm trong bộ nhớ, overhead vài phần trăm và bật được ở production — đúng vai trò của eBPF ở đây. Còn công cụ chèn bytecode vào từng method thì làm chậm gấp bội và bóp méo chính hình dạng cái nó đo, giống hệt strace dừng-đọc-thả.

Trong Go, runtime/trace và pprof được xây thẳng vào runtime: điểm đo nằm ngay trong lịch trình goroutine và bộ cấp phát, ghi vào buffer nội bộ chứ không phải dừng tiến trình từ ngoài. Cùng một triết lý — đo nơi việc xảy ra, không phải quan sát từ một tiến trình khác.

Còn ở cơ sở dữ liệu, đây là khác biệt giữa việc chạy strace lên tiến trình Postgres (thấy syscall mà mù nghĩa) và bật pg_stat_statements / extension đo trong chính engine: phần đo nằm bên trong bộ thực thi câu lệnh, tính từng câu query theo thời gian và số lần gọi, chi phí thấp đủ để always-on. Và cái bài học về đuôi phân bố thì y nguyên: một câu query trung bình 2 ms nhưng thỉnh thoảng mất 2 giây sẽ biến mất khỏi mọi con số trung bình — chỉ histogram độ trễ (thứ pg_stat_statements mới thêm, hay auto_explain với ngưỡng) mới bắt được nó.

Mẫu số chung: công cụ đo tốt nhất thường không phải cái nhìn từ bên ngoài vào, mà là cái được nhúng vào ngay trong đường thực thi và ghi lại từng sự kiện thay vì tính trung bình. Đứng ngoài thì phải dừng-đọc-thả (đắt) và chỉ thấy một mục tiêu một lúc; đứng trong thì rẻ, thấy toàn cục, và giữ được cái đuôi — nơi sự cố thật sự trú ngụ. Nên câu hỏi đúng khi chọn công cụ quan sát không phải "nó chính xác cỡ nào" mà là "nó đứng trong hay ngoài đường thực thi, và nó cho tôi phân bố hay chỉ một con số trung bình" — vì cả chi phí lẫn cái bạn nhìn thấy đều do chỗ đứng ấy quyết định.

Muốn tự thấy cả ba điều — chi phí thấp, tầm nhìn cả máy, và cái đuôi mà trung bình giấu — ba lệnh dưới trả lời ba câu hỏi mà không công cụ truyền thống nào trả lời gọn được:

# 1. Tien trinh nao vua duoc tao? (bat ca cai song 5 ms)
bpftrace -e 'tracepoint:sched:sched_process_exec { printf("%s %s\n", comm, str(args.filename)); }'

# 2. Phan bo do tre cua o dia, khong phai trung binh
bpftrace -e 'kprobe:blk_account_io_start { @s[arg0] = nsecs; }
             kprobe:blk_account_io_done /@s[arg0]/ { @us = hist((nsecs-@s[arg0])/1000); delete(@s[arg0]); }'

# 3. Tien trinh nao doc ghi nhieu nhat, toan may
bpftrace -e 'kprobe:vfs_read,kprobe:vfs_write { @[comm, func] = count(); }'

Nhấn Ctrl-C để in kết quả. Nếu lệnh đầu tiên hiện ra những tiến trình bạn không hề biết là đang tồn tại trên máy mình, đó chính xác là loại thứ mà mọi công cụ lấy mẫu khác đã bỏ sót suốt thời gian qua.

Phần sau: bẫy khi đo — những sai lầm tôi đã mắc trong bốn mươi phần trước.