关于c:kprobelf-高延迟内核函数定位分析工具

1.kprobe-lf 是什么

kprobe-lf 是一款基于 kprobe 和中断定时器的高提早函数定位剖析工具

kprobe-lf 能够定位剖析大多数内核函数，当设置提早足够小时也能够察看失常提早函数的堆栈

1.1 为什么叫 kprobe-lf

因为这款工具有两个重要的设置，一个是 LATENCY，一个是 FUNCTION，简称 LF

1.2 适配问题

目前在内核 4.15.0，5.4.54，5.13.0 上进行了测试，这几个版本都能够适配

2. 如何应用

git clone https://github.com/1978629634/kprobe_lf.git
cd kprobe_lf
bash start.sh -f [FUNCTION_NAME] -l [LATENCY_TIME]

运行脚本之后应用 ctrl + c 进行获取 log，并且生成火焰图

脚本启动之后会在当前目录生成三个文件

1. lf.log 是函数运行前堆栈
2. lf.svg 是火焰图
3. lf.graph 是火焰图原始文件

3. 为什么须要 kprobe-lf

3.1 找到高提早首恶

kprobe-lf 能够定位超时函数并将它的运行堆栈制作成火焰图

比方咱们遇到软中断提早过长的问题时能够设置函数为__do_softirq, 设置提早为 1000us，定位剖析超时软中断

root@cluster1-worker1:~/kprobe_lf# bash start.sh -f __do_softirq -l 1000
FUNCTION: __do_softirq, LATENCY_TIME: 1000 us (>=100us)
find kprobe_lf.ko
insmod kprobe_lf.ko
save log to lf.log, ctrl + c to stop

取得到超时__do_softirq 运行时火焰图和超时__do_softirq 运行前堆栈如下

运行时火焰图：

运行前堆栈：

__do_softirq cpu:2 PID:0 COMMAND:swapper/2 LATENCY:5978us
     __do_softirq+0x1/0x2dc
     irq_exit+0xd5/0xe0
     smp_apic_timer_interrupt+0x74/0x130
     apic_timer_interrupt+0xf/0x20
     native_safe_halt+0xe/0x10
     default_idle+0x1c/0x140
     do_idle+0x1aa/0x250
     cpu_startup_entry+0x19/0x20
     start_secondary+0x162/0x1c0
     secondary_startup_64+0xa4/0xb0
...

通过 LATENCY 咱们能够晓得超时软中断提早高达 6ms

通过火焰图咱们能够看到所有的高提早软中断都是在运行 estimation_timer（IPVS BUG）

很快就能够定位到首恶函数

3.2 内核性能剖析

在咱们对内核作性能剖析的状况下，有时想剖析批改一个参数对内核的性能影响是怎么的，咱们就能够利用这款工具对相干函数做剖析

以内核参数 /proc/sys/net/ipv4/tcp_tw_reuse 为例

3.2.1 默认设置 tcp_tw_reuse = 2

用 curl 在本地发动高并发短连贯，察看__sys_connect 函数状况

# 模仿高并发
root@cluster1-worker1:~# while true;do curl xxxxxxx ;done
# 运行工具
root@cluster1-worker1:~/kprobe_lf# bash start.sh -f __sys_connect -l 100
FUNCTION: __sys_connect, LATENCY_TIME: 100 us (>=100us)
find kprobe_lf.ko
insmod kprobe_lf.ko
save log to lf.log, ctrl + c to stop

运行时火焰图：

运行前堆栈：

__sys_connect cpu:6 PID:26184 COMMAND:curl LATENCY:1781us
     __sys_connect+0x1/0xf0
     __x64_sys_connect+0x16/0x20
     do_syscall_64+0x5b/0x1b0
     entry_SYSCALL_64_after_hwframe+0x44/0xa9
...

通过运行前堆栈能够看到__sys_connect 提早为 1.7ms

通过火焰图能够看到__sys_connect 90% 以上都耗费到了__inet_hash_connect 端口选择函数

3.2.2 启用 tcp_tw_reuse = 1

用 curl 在本地发动高并发短连贯，察看__sys_connect 函数状况

# 模仿高并发
root@cluster1-worker1:~# while true;do curl xxxxxxx ;done
# 运行工具
root@cluster1-worker1:~/kprobe_lf# bash start.sh -f __sys_connect -l 100
FUNCTION: __sys_connect, LATENCY_TIME: 100 us (>=100us)
find kprobe_lf.ko
insmod kprobe_lf.ko
save log to lf.log, ctrl + c to stop

运行时火焰图：

运行前堆栈：

__sys_connect cpu:26 PID:10538 COMMAND:curl LATENCY:101us
     __sys_connect+0x1/0xf0
     __x64_sys_connect+0x16/0x20
     do_syscall_64+0x5b/0x1b0
     entry_SYSCALL_64_after_hwframe+0x44/0xa9
...

通过运行前堆栈能够看到__sys_connect 提早为 0.1ms

通过火焰图能够看到__inet_hash_connect 端口选择函数曾经占比小于 1%

tcp_tw_reuse = 1 对端口抉择的改善成果非常显著

4. 阐明

火焰图制作基于 https://github.com/brendangregg/FlameGraph

本工具受到了字节跳动团队 trace-irqoff 工具的启发