测来测去20:快速定位short-lived进程对性能的负面影响

案例

遇到过的一个案例是这样:DPDK应用在小流量的情况下丢包,并且是间歇性地丢。很自然的,会怀疑有其他进程抢占分配给DPDK的CPU核。

这个案例里Kernel里面CPU隔离的参数都是配好的,不过并非所有的进程都完全按照内核的要求行事。比如一些自己在代码里面调用了sched_setaffinity方法的程序。

比较特殊的是,抢占这个CPU核的进程是一个生命周期非常短(short-lived)的进程,从启动到退出只有几毫秒的时间。所以很难在一些类似topps等一般查看进程状态的工具中“逮住”它。

perf

无论再短的进程都可以通过追踪Kernel里的方法观察到。一般这个时候想到的是利用ftrace来抓取,但perf提供了一些更为简便的操作和事件统计。

首先看一下perf里面关于调度器的事件:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
[root@server-P1 ~]# perf list | grep sched
irq_vectors:reschedule_entry [Tracepoint event]
irq_vectors:reschedule_exit [Tracepoint event]
sched:sched_kthread_stop [Tracepoint event]
sched:sched_kthread_stop_ret [Tracepoint event]
sched:sched_migrate_task [Tracepoint event]
sched:sched_move_numa [Tracepoint event]
sched:sched_pi_setprio [Tracepoint event]
sched:sched_process_exec [Tracepoint event]
sched:sched_process_exit [Tracepoint event]
sched:sched_process_fork [Tracepoint event]
sched:sched_process_free [Tracepoint event]
sched:sched_process_hang [Tracepoint event]
sched:sched_process_wait [Tracepoint event]
sched:sched_stat_blocked [Tracepoint event]
sched:sched_stat_iowait [Tracepoint event]
sched:sched_stat_runtime [Tracepoint event]
sched:sched_stat_sleep [Tracepoint event]
sched:sched_stat_wait [Tracepoint event]
sched:sched_stick_numa [Tracepoint event]
sched:sched_swap_numa [Tracepoint event]
sched:sched_switch [Tracepoint event]
sched:sched_wait_task [Tracepoint event]
sched:sched_wake_idle_without_ipi [Tracepoint event]
sched:sched_wakeup [Tracepoint event]
sched:sched_wakeup_new [Tracepoint event]
syscalls:sys_enter_sched_get_priority_max [Tracepoint event]
syscalls:sys_enter_sched_get_priority_min [Tracepoint event]
syscalls:sys_enter_sched_getaffinity [Tracepoint event]
syscalls:sys_enter_sched_getattr [Tracepoint event]
syscalls:sys_enter_sched_getparam [Tracepoint event]
syscalls:sys_enter_sched_getscheduler [Tracepoint event]
syscalls:sys_enter_sched_rr_get_interval [Tracepoint event]
syscalls:sys_enter_sched_setaffinity [Tracepoint event]
syscalls:sys_enter_sched_setattr [Tracepoint event]
syscalls:sys_enter_sched_setparam [Tracepoint event]
syscalls:sys_enter_sched_setscheduler [Tracepoint event]
syscalls:sys_enter_sched_yield [Tracepoint event]
syscalls:sys_exit_sched_get_priority_max [Tracepoint event]
syscalls:sys_exit_sched_get_priority_min [Tracepoint event]
syscalls:sys_exit_sched_getaffinity [Tracepoint event]
syscalls:sys_exit_sched_getattr [Tracepoint event]
syscalls:sys_exit_sched_getparam [Tracepoint event]
syscalls:sys_exit_sched_getscheduler [Tracepoint event]
syscalls:sys_exit_sched_rr_get_interval [Tracepoint event]
syscalls:sys_exit_sched_setaffinity [Tracepoint event]
syscalls:sys_exit_sched_setattr [Tracepoint event]
syscalls:sys_exit_sched_setparam [Tracepoint event]
syscalls:sys_exit_sched_setscheduler [Tracepoint event]
syscalls:sys_exit_sched_yield [Tracepoint event]

基本上够用了..其实真正重要的也就是*exec*exit*switch这仨。为了避免要抓取的short-lived进程仅仅存在于想象之中,我们先搞一些具体统计数据涨涨信心。

perf stat

可以先用perf stat看看具体事件的计数:

perf stat -e sched:sched_switch -a -I 1000 sleep 10

这里面会给出当前整个系统调度器发生switch的统计情况,每1秒输出一次,总计10秒。

如果想针对某一个特定的CPU,可以把-a替换成-C 4这类。其他事件的统计也可以用类似的方法。

如果switch事件比较多,那么可以继续看一下shced:sched_process_exec事件在某个CPU上发生的频率,当然了,这个CPU一般是正在跑DPDK或其他生产业务的CPU。

详细内容

如果想看到该事件的一些详细信息,比如具体是哪个程序在频繁启动,对应的PID,以及程序在哪个CPU上启动,可执行文件的路径是什么等信息,可以用ftrace的方式实现。

首先使能该trace事件:

echo 1 > /sys/kernel/debug/tracing/events/sched/sched_process_exec/enable

然后cat /sys/kernel/debug/tracing/trace

应该就可以看到了。

也可以用perf-tools里的execsnoop工具,不过本质上都是一样的。

© 2020 DecodeZ All Rights Reserved. 本站访客数人次 本站总访问量
Theme by hiero