宋宝华:当Linux内核遭遇鲨鱼—kernelshark
之前小弟一直在宣传推广火焰图,结果是很多童鞋凡事都用火焰图。说实话,火焰图特别适合分析运行时热点(无论是on-cpu、off-cpu、还是内存等,火焰图的想象力可以无穷放大),但是你要分析一个的如果是一个时序问题,比如系统启动的慢、一个软件启动的慢,用火焰图固然可能有一点帮助,但是帮助肯定很微妙。
因为这种某个过程慢的问题,是一个时序问题。不是一个运行时热点的问题,所以你最重要的是画出来你的这个过程的时序图。这里面说不定有I/O的牵绊,说不定就是狂占CPU,说不定谁傻不拉几地在sleep。
Linux界有一个杀手级分析Linux本身启动慢的工具,叫做bootchart,它其实把启动过程中进程的IO,CPU占用情况进行了描述。注意这类图都有一个共同特点,横轴是时间,纵轴是CPU、线程等的状态(运行、睡眠、IO什么的)。
bootchart确实有利于分析开机过程,但是你平时某个软件启动慢呢?或者更广泛地说,某个特定过程特别慢呢?或者更加更加广泛地说,我写的程序在系统里面是怎么在运行,几个线程怎么在跑?我们则要描绘出它的时序图。
这个时候,我们可以用perf的timechart,比如,下面我们写一个很简单的包含了2个线程周期循环做事情和睡眠的代码:
我们运行上面这个a.out,下面我们用perf录制系统的sched情况:
~$ sudo perf sched record -a
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 1.909 MB perf.data (9039 samples) ]
接下来生成timechart:
~$ sudo perf timechart
Written 6.4 seconds of trace to output.svg.
我们用firefox打开这个时序图:
时序图上我们看到了我的8个CPU的运行情况,以及a.out中2个线程一会儿蓝色(running)一会灰色(sleeping)的情况。我们看到,系统差不多在用CPU2和CPU7跑我们a.out里面的2个占用CPU比较高线程。
不过,这类工具里面压轴的不是perf timechart,说实话,有点太粗糙了!我们来看看大名鼎鼎的内核鲨鱼——kernelshark。
下面我们用trace-cmd来录制sched相关的trace点:
~$ sudo trace-cmd record -e 'sched_wakeup*' -e sched_switch -e 'sched_migrate*'
Hit Ctrl^C to stop recording
^CCPU0 data recorded at offset=0x60e000
61440 bytes in size
CPU1 data recorded at offset=0x61d000
184320 bytes in size
CPU2 data recorded at offset=0x64a000
24576 bytes in size
CPU3 data recorded at offset=0x650000
12288 bytes in size
CPU4 data recorded at offset=0x653000
12288 bytes in size
CPU5 data recorded at offset=0x656000
86016 bytes in size
CPU6 data recorded at offset=0x66b000
172032 bytes in size
CPU7 data recorded at offset=0x695000
28672 bytes in size
用kernelshark来打开录制的点:
~$ kernelshark trace.dat
Loading "trace.dat"
看到下面的图形界面:
我们可以在UI上面进行各种操作,比如我们关注a.out,我们就选择task:
我们得到这样的视图:
比如我图上画的那个点,a.out的颜色发生了变化,而下面的文字则表达了发生变化的原因是调度,调度的目标是swapper,这个调度点发生在CPU4上面:
如果你期待的是一个横轴是时间,纵轴是每个线程、CPU在某个时间段里面在干什么的图,kernelshark,你当然值得拥有。