perf 使用

perf中几个常用的命令

perf top 类似系统命令 查看消耗cpu比较高的内核函数或者进程
perf list 列出perf支持的事件
perf stat 统计profiling进程的各种信息
perf record profiling进程的数据,并生成 xx.data文件
perf report 读取xx.data文件

废话不多说,先来看看一个例子

#include <stdio.h>
#include <stdlib.h>

#define TEST_NUM    2000000000

long sum(unsigned char *a, unsigned long lenght)
{
    long nSum = 0;
    for(unsigned long i = 0; i < lenght; i++)
        nSum += a[i];
    return nSum;
}

void Rand(unsigned char *a, unsigned long lenght)
{
    for(unsigned long i = 0; i < lenght; i++)
        a[i] = 1;//rand() % 100;
}

void* start(void *arg)
{
    unsigned char *pa = (unsigned char*)malloc(sizeof(unsigned char)*TEST_NUM);
    Rand(pa, TEST_NUM);
    long ret = sum(pa, TEST_NUM);
    printf("ret=%ld\n", ret);
    free(pa);

}

int main()
{
    start(NULL);
    return 0;
}

gcc -O2 -std=c99 test.c -o test 编译生成test
perf stat ./test

ret=2000000000

 Performance counter stats for './perf_r':

       3219.798267      task-clock (msec)         #    0.996 CPUs utilized          
                72      context-switches          #    0.022 K/sec                  
                 1      cpu-migrations            #    0.000 K/sec                  
            65,820      page-faults               #    0.020 M/sec                  
   <not supported>      cycles                                                      
   <not supported>      instructions                                                
   <not supported>      branches                                                    
   <not supported>      branch-misses                                               

       3.232352319 seconds time elapsed

由于我用的是虚拟机 而且cpu没有虚拟化,所有有些时间不支持,不过不影响我们分析
Task-clock-msecs:CPU 利用率,该值高,说明程序的多数时间花费在 CPU 计算上而非 IO。
Context-switches:进程切换次数,记录了程序运行过程中发生了多少次进程切换,频繁的进程切换是应该避免的。
Cache-misses:程序运行过程中总体的 cache 利用情况,如果该值过高,说明程序的 cache 利用不好
CPU-migrations:表示进程 t1 运行过程中发生了多少次 CPU 迁移,即被调度器从一个 CPU 转移到另外一个 CPU 上运行
page-faults 内存页面交换
Cycles:处理器时钟,一条机器指令可能需要多个 cycles,
Instructions: 机器指令数目。
IPC:是 Instructions/Cycles 的比值,该值越大越好,说明程序充分利用了处理器的特性。
Cache-references: cache 命中的次数
Cache-misses: cache 失效的次数。
从输出我们可以看出这个程序是一个cpu密集型的程序。

执行命令
perf record -g -e cpu-clock ./perf_r
生成perf.data 由于我们程序是cpu是cpu密集型,所有我只关注了cpu始终(-e cpu-clock )
perf report -g 读取perf.data文件

Samples: 7K of event 'cpu-clock', Event count (approx.): 1808250000
  Children      Self  Command  Shared Object      Symbol
+   99.74%    55.43%  perf_r   perf_r             [.] start
+   44.26%     0.00%  perf_r   [kernel.kallsyms]  [k] do_page_fault
+   44.26%     0.00%  perf_r   [kernel.kallsyms]  [k] page_fault
+   44.23%     0.03%  perf_r   [kernel.kallsyms]  [k] handle_mm_fault
+   44.23%     0.00%  perf_r   [kernel.kallsyms]  [k] __do_page_fault
+   44.16%     0.00%  perf_r   [kernel.kallsyms]  [k] do_huge_pmd_anonymous_page
+   43.15%    43.15%  perf_r   [kernel.kallsyms]  [k] clear_page
+    1.09%     0.01%  perf_r   [kernel.kallsyms]  [k] __alloc_pages_nodemask
+    0.76%     0.00%  perf_r   [kernel.kallsyms]  [k] alloc_pages_vma
     0.44%     0.00%  perf_r   [kernel.kallsyms]  [k] __alloc_pages_slowpath
     0.41%     0.00%  perf_r   [kernel.kallsyms]  [k] compact_zone
     0.41%     0.00%  perf_r   [kernel.kallsyms]  [k] compact_zone_order
     0.41%     0.00%  perf_r   [kernel.kallsyms]  [k] try_to_compact_pages
     0.41%     0.00%  perf_r   [kernel.kallsyms]  [k] __alloc_pages_direct_compact
     0.39%     0.00%  perf_r   [kernel.kallsyms]  [k] migrate_pages
     0.37%     0.00%  perf_r   [kernel.kallsyms]  [k] migrate_page
     0.37%     0.00%  perf_r   [kernel.kallsyms]  [k] move_to_new_page
     0.37%     0.37%  perf_r   [kernel.kallsyms]  [k] copy_page
     0.35%     0.00%  perf_r   [kernel.kallsyms]  [k] alloc_pages_current
     0.35%     0.00%  perf_r   [kernel.kallsyms]  [k] pte_alloc_one
     0.28%     0.28%  perf_r   [kernel.kallsyms]  [k] get_page_from_freelist
     0.22%     0.00%  perf_r   [kernel.kallsyms]  [k] system_call_fastpath
     0.21%     0.00%  perf_r   [kernel.kallsyms]  [k] unmap_region

在图中 我们可以看出用户态函数start函数和内核态很熟 clear_page最消耗cpu,有同学可能会问为什么没有sum和Rand函数,因为我用的是O2编译,这两个函数都被内敛到start函数了 ,这个可以通过汇编代码看出来。

如果你还觉得不够直观,brendangreg大大还写了一个工具 对perf.data数据生成火焰图
工具地址:https://github.com/brendangregg/FlameGraph.git
用perf生成火焰图
下载上面的工具

  1. 先生成perf.data
  2. perf script对perf.data进行解析 perf script -i perf.data &> perf.unfold
  3. 将perf.unfold的符号进行折叠 ./stackcollapse-perf.pl perf.unfold &> perf.folded
  4. 最后生成svg图 ./flamegraph perf.foleded > perf.svg
Paste_Image.png

横轴的长度代表cpu的消耗时间 纵轴代表调用堆栈
对于正在运行的程序 可以直接使用 pert stat -p pid 或者perf record -g -e cpu-clock -pid生成perf.data数据用于分析

统计进程10秒钟的系统调用
perf stat -p $pid -e 'syscalls:sys_enter_*' sleep 10
查看系统中所有进程系统调用排序
perf top -F 49 -e raw_syscalls:sys_enter --sort comm,dso --show-nr-samples
追踪进程的系统调用
perf trace -p <PID>

brendangreg大大关于perf使用的文章
http://www.brendangregg.com/perf.html

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 203,324评论 5 476
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,303评论 2 381
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 150,192评论 0 337
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,555评论 1 273
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,569评论 5 365
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,566评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,927评论 3 395
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,583评论 0 257
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,827评论 1 297
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,590评论 2 320
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,669评论 1 329
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,365评论 4 318
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,941评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,928评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,159评论 1 259
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 42,880评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,399评论 2 342

推荐阅读更多精彩内容