《Linux调优工具oprofile的演示分析》

Posted 2020-09-03 菜鸟程序monkey

根据CPU架构oprofile采样的触发有两种模式:
1) NMI模式: 利用处理器的performance counter功能, 指定counter的类型type和累进数量count. 比如

type=DTLB_MISS, count=500, 代表"Data TLB miss"每发生500次, 会触发一次中断. Oprofile.ko模块会相应这个中断, 然后看当前正在执行的是什么指令,那个函数, 那个模块(或者app, lib), 并进行计数. 不同的处理器支持的counter类型和count取值范围各不相同. 可以通过ophelp来查看当前cpu所支持的counter类型和参数. 例如, "--event=MISALIGN_MEM_REF:1000:0:1:0"表示非对齐的内存访问, 每1000次触发一个中断, 1000后面的0表示改特定counter的mask, 具体含义看ophelp的内容; 最后的1:0表示只对kernel采样, 不对用户空间程序采样. "--event=CPU_CLK_UNHALTED:10000:0:1:0"代表cpu时钟周期事件.每10000个cycle触发一次中断. "--event=L1I_MISSES:500:0:1:0"表示一级指令缓存的cache miss.

2) Timer Interrupt模式: 在没有performance counter支持的情况下(例如Vmware虚拟机下), 可以利用时钟中断来采样. 这时候就没有performance counter的概念了. 或者可以当成近似的cpu时钟周期事件. 要使用timer interrupt模式, 需要在加载oprofile.ko模块的时候,传递"timer=1"参数. modprobe oprofile timer=1

 

一)用opcontrol控制profile
要打开oprofile,需要用start选项来调用opconrol,当第一次调用opcontrol时,必须告诉它想统计内核还是用户空间数据.
因为我们的例子是在用户空间工作,应该用--no-vmlinux选项来取消内核统计,如下:

1.首先需要加载profile：

opcontrol --init

初始化oprofile，可以通过demsg查看oprofile使用的是哪一种模式：
[[email protected] /]# dmesg | grep oprofile
oprofile: using NMI interrupt.
oprofile: using NMI interrupt.
oprofile: using NMI interrupt.
oprofile: using NMI interrupt.
oprofile: using NMI interrupt.

 

2.然后start 调用开始获取CPU采样：

[[email protected] /]# opcontrol --start --no-vmlinux
ATTENTION: Use of opcontrol is discouraged. Please see the man page for operf.
Using default event: CPU_CLK_UNHALTED:100000:0:1:1
Using 2.6+ OProfile kernel interface.
Using log file /var/lib/oprofile/samples/oprofiled.log
Daemon started.
Profiler running.

每次启动都会在/root/.oprofile/目录下生成一个配置文件daemonrc,如下:

[[email protected] /]# cat /root/.oprofile/daemonrc
SESSION_DIR=/var/lib/oprofile
NR_CHOSEN=0
SEPARATE_LIB=0
SEPARATE_KERNEL=0
SEPARATE_THREAD=0
SEPARATE_CPU=0
VMLINUX=none
IMAGE_FILTER=
CPU_BUF_SIZE=0
CALLGRAPH=0
XENIMAGE=none

注:
以上的每个配置项是通过启动oprofile时加的参数生成的.

 

清理统计数据，重置统计量,如下:
[[email protected] /]# opcontrol --reset

3.这个时候启动需要监控的程序，如果是内核，就直接sleep一段时间即可

[[email protected] /]# /usr/local/nginx/sbin/nginx

 

4.接下来我们用--dump选项告诉oprofiled输出统计量,如下:
[[email protected] /]# opcontrol --dump

（可选）停止后台程序
[[email protected] /]# opcontrol --shutdown

 

5.再下来我们就可以用opreport,opgprof或者opannotate来观察它们,任何用户都可以看到输出,下面我们用opreport来查看统计量,如下:
(1)opreport

[[email protected] /]# opreport |grep nginx
Using /var/lib/oprofile/samples/ for samples directory.
39 1.0e-04 nginx

观察对应进程里面函数在运行时候的的占用百分比
[[email protected] /]# opreport -l /usr/local/nginx/sbin/nginx
Using /var/lib/oprofile/samples/ for samples directory.
CPU: Intel Core/i7, speed 2.128e+06 MHz (estimated)
Counted CPU_CLK_UNHALTED events (Clock cycles when not halted) with a unit mask of 0x00 (No unit mask) count 100000
samples % symbol name
20 39.2157 ngx_hash_init
10 19.6078 ngx_conf_parse
2 3.9216 ngx_init_setproctitle
1 1.9608 _fini
1 1.9608 main
1 1.9608 ngx_array_push
1 1.9608 ngx_cpuinfo
1 1.9608 ngx_event_process_init
1 1.9608 ngx_hash_key_lc
1 1.9608 ngx_http_core_merge_loc_conf
1 1.9608 ngx_http_core_server_name
1 1.9608 ngx_http_core_type
1 1.9608 ngx_http_limit_conn_merge_conf
1 1.9608 ngx_http_log_compile_format
1 1.9608 ngx_http_log_init
1 1.9608 ngx_http_merge_locations
1 1.9608 ngx_http_upstream_keepalive_create_conf
1 1.9608 ngx_http_uwsgi_merge_loc_conf
1 1.9608 ngx_signal_handler
1 1.9608 ngx_strlow
1 1.9608 ngx_vslprintf
1 1.9608 ngx_worker_process_init
[[email protected] /]#

(2)opannotate
[[email protected] /]# opannotate --source /usr/local/nginx/sbin/nginx > 1.txt

可以针对某一个进程，里面所有函数的执行采样统计，用于优化函数。

        
注:
输出显示了一系列对象文件,文件包含了当profile测试时正在运行的代码.
oprofiled 从调用opcontrol --start时开始记录,到调用opcontrol --dump时会截取当前的统计量,但是oprofiled仍会继续搜集并积累统计数据,之后再调用opconrol --dump就会有旧的积累数据产生.直到调用opcontrol --stop时,才会停止搜集.

 

(3)opgprof

我们可以通过gprof来产生一个gmon.out文件,如下:
[[email protected] /]# opgprof /usr/local/nginx/sbin/nginx

不调用图像数据得出gmon.out结果

[[email protected] /]# gprof --no-graph /usr/local/nginx/sbin/nginx
Flat profile:

Each sample counts as 1 samples.
% cumulative self self total
time samples samples calls T1/call T1/call name
39.22 20.00 20.00 ngx_hash_init
19.61 30.00 10.00 ngx_conf_parse
3.92 32.00 2.00 ngx_init_setproctitle
1.96 33.00 1.00 _fini
1.96 34.00 1.00 main
1.96 35.00 1.00 ngx_array_push
1.96 36.00 1.00 ngx_cpuinfo
1.96 37.00 1.00 ngx_event_process_init
1.96 38.00 1.00 ngx_hash_key_lc
1.96 39.00 1.00 ngx_http_core_merge_loc_conf
1.96 40.00 1.00 ngx_http_core_server_name
1.96 41.00 1.00 ngx_http_core_type
1.96 42.00 1.00 ngx_http_limit_conn_merge_conf
1.96 43.00 1.00 ngx_http_log_compile_format
1.96 44.00 1.00 ngx_http_log_init
1.96 45.00 1.00 ngx_http_merge_locations
1.96 46.00 1.00 ngx_http_upstream_keepalive_create_conf
1.96 47.00 1.00 ngx_http_uwsgi_merge_loc_conf
1.96 48.00 1.00 ngx_signal_handler
1.96 49.00 1.00 ngx_strlow
1.96 50.00 1.00 ngx_vslprintf
1.96 51.00 1.00 ngx_worker_process_init

% the percentage of the total running time of the
time program used by this function.

cumulative a running sum of the number of seconds accounted
seconds for by this function and those listed above it.

self the number of seconds accounted for by this
seconds function alone. This is the major sort for this
listing.

calls the number of times this function was invoked, if
this function is profiled, else blank.

self the average number of milliseconds spent in this
ms/call function per call, if this function is profiled,
else blank.

total the average number of milliseconds spent in this
ms/call function and its descendents per call, if this
function is profiled, else blank.

name the name of the function. This is the minor sort
for this listing. The index shows the location of
the function in the gprof listing. If the index is
in parenthesis it shows where it would appear in
the gprof listing if it were to be printed.
[[email protected] /]#

 

6.
opcontrol --stop  #停止profiling
opcontrol --shutdown  #关闭守护进程oprofiled
opcontrol --deinit  #卸载模块

 

 

二)关于oprofile的最终论述

这里只提到了oprofile的表面功能.
默认情况下,oprofile不支持在虚拟机上进行调试,我们可以通过下面的方法让oprofile可以在虚拟机上跑,如下:

echo "options oprofile timer=1" >> /etc/modprobe.conf
此时再重启虚拟机就可以工作了.