kprobe-lf - 高延迟内核函数定位分析工具

  • Z时代
  • 2024-01-10
  • 分类：综合

1.kprobe-lf是什么

kprobe-lf是一款基于kprobe和中断定时器的高延迟函数定位分析工具

kprobe-lf可以定位分析大多数内核函数

当设置延迟足够小时，kprobe-lf也可以观察正常延迟函数的堆栈

1.1 为什么叫kprobe-lf

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

1.2 适配问题

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

2.如何使用

git clone https://git.n.xiaomi.com/chenpu1/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 (>=1us)
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 (>=1us)
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 (>=1us)
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 工具的启发

以上是 kprobe-lf - 高延迟内核函数定位分析工具 的全部内容， 来源链接： utcz.com/z/267452.html

回到顶部