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ác cả hai.
Chi phí
Cùng chương trình gọi write() 300.000 lần:
| Công cụ | µs mỗi lời gọi | Chậm hơn | Thấy được gì |
|---|---|---|---|
| Không theo dõi | 0,12 | 1× | — |
bpftrace |
0,24 | 2× | cả máy |
perf trace |
9,37 | 85× | cả máy |
strace -c |
49,06 | 446× | một cây tiến trình |
Chậm 2 lần, so với 446 lần của strace.
Lý do nằm ở kiến trúc. strace dừng tiến trình rồi đọc thanh ghi từ bên ngoài. eBPF 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 trong nhân. Không có tiến trình nào bị dừng, không có dữ liệu nào bị chép ra ngoài trong lúc chạy.
Nó thấy cả máy cùng lúc
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ủ, trong cùng một lần đo.
strace không làm được 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" 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.
Cái nó thấy mà công cụ khác không thấy
Đây là phần đá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. Và 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.
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.
Chỉ bằng cách ghi từng lần gọi vào một bảng phân phối — việc mà eBPF làm ngay trong nhân với chi phí không đáng kể — thì cái đuôi đó mới hiện ra.
Nói lại lần thứ hai vì nó 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 "trung bình 150 ns" thành một phân bố đầy đủ, và đuôi của phân bố mới là nơi sự cố sinh ra.
Đoạn mã tạo ra biểu đồ trên:
bpftrace -e '
kprobe:vfs_write { @t[tid] = nsecs; }
kretprobe:vfs_write /@t[tid]/ { @ns = hist(nsecs - @t[tid]); delete(@t[tid]); }
END { clear(@t); }'
Bốn dòng.
Bẫy tôi vấp: không có tracepoint nào
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 — như thể nhân không hỗ trợ gì.
Nguyên nhân: tracefs chưa được gắn.
mount -t tracefs none /sys/kernel/tracing
Sau lệnh đó, 2.955 sự kiện xuất hiện và mọi thứ chạy.
Thông báo lỗi "tracepoint not found" 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. Nếu bạn gặp nó trong container, kiểm tra ls /sys/kernel/tracing/available_events trước khi đi tìm nhân khác.
Ba điều kiện để eBPF chạy được:
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).
Bộ công cụ có sẵn
Không phải lúc nào cũng cần tự viết. bcc-tools có hơn 100 công cụ dựng sẵn:
| Công cụ | Trả lời câu hỏi |
|---|---|
execsnoop |
tiến trình nào vừa được tạo (bắt cả tiến trình sống vài mili giây) |
opensnoop |
ai đang mở tệp nào |
biolatency |
phân bố độ trễ ổ đĩa |
biosnoop |
từng thao tác đĩa kèm tiến trình gây ra |
tcpconnect, tcpretrans |
kết nối mới, gói phải gửi lại |
runqlat |
tiến trình chờ bao lâu để được lên CPU |
offcputime |
tiến trình ngủ ở đâu và bao lâu |
cachestat |
tỷ lệ trúng bộ đệm trang |
execsnoop giải quyết một lớp vấn đề mà không công cụ nào khác giải được: 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.
runqlat và offcputime bổ sung đúng chỗ mà phần 38 nói perf không thấy: thời gian không chạy trên CPU.
Giới hạn thật
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.
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 trên nhân 5.10 có thể 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à cách làm chậm cả máy.
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. Điều này làm eBPF an toàn nhưng cũng làm việc viết script phức tạp trở nên khó.
Thử ba mươi giây
Ba lệnh 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 những tiến trình bạn không biết là đang tồn tại, đó chính 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.
