用性能分析睡眠时间

我正在寻找一种方法来找出我的程序在哪里花费时间。 我读了perf教程，并试图描述那里描述的睡眠时间。 我写了最简单的程序来描述：

#include <unistd.h> int main() { sleep(10); return 0; }

然后我用perf来执行它：

$ sudo perf record -e sched:sched_stat_sleep -e sched:sched_switch -e sched:sched_process_exit -g -o ~/perf.data.raw ./a.out [ perf record: Woken up 1 times to write data ] [ perf record: Captured and wrote 0.013 MB /home/pablo/perf.data.raw (~578 samples) ] $ sudo perf inject -v -s -i ~/perf.data.raw -o ~/perf.data build id event received for [kernel.kallsyms]: d62870685909222126e7070d2bafdf029f7ed3b6 Failed to write feature 2 $ sudo perf report --stdio --show-total-period -i ~/perf.data Error: The /home/pablo/perf.data file has no samples!

有谁知道如何避免这些错误？ 他们的意思是什么？ Failed to write feature 2不看起来太人性化…

更新：

如何获得调用父母的libc6符号（例如_int_malloc）与Linux perf？

perf中的预定义事件的原始编码

你用什么工具来分析你的C ++应用程序的挂钟？

linux perf：如何解释和查找热点

理解Perf工具输出

$ uname -a Linux debian 3.12-1-amd64 #1 SMP Debian 3.12.9-1 (2014-02-01) x86_64 GNU/Linux

在Linux中进行性能分析

在perf分析器中调用堆栈

从https://perf.wiki.kernel.org/index.PHP/Tutorial#Profiling_sleep_times的第二个perf命令有一个错误信&#x606F; – perf inject -s

$ sudo perf inject -v -s -i ~/perf.data.raw -o ~/perf.data build id event received for [kernel.kallsyms]: d62870685909222126e7070d2bafdf029f7ed3b6 Failed to write feature 2

未能写功能2不看起来太人性化…

…但它被添加到性能使错误更加用户友好： http ://lwn.net/Articles/460520/“perf：使perf.data更自我描述性（v5）”由Stephane Eranian，9月22日2011：

+static int do_write_feat(int fd,struct perf_header *h,int type,.... + pr_debug("Failed to write feature %dn",type);

所有功能在这里列出http://lxr.free-electrons.com/source/tools/perf/util/header.h#L13

15 HEADER_TRACING_DATA = 1,16 HEADER_BUILD_ID,

所以，听起来perf perf无法写入关于构建id的信息write_build_id()来自util / write_build_id()函数write_build_id()错误），如果我没有错的话。 有两种情况可能会导致错误：调用perf_session__read_build_ids()失败或者编写buildid表失败dsos__write_buildid_table （这不是我们的情况，因为没有“编写失败的buildid表”错误消息;请检查write_build_id ）

你可以检查，你有所有buildids需要的会议。 清除buildid缓存（ rm -rf ~/.debug -rf〜 rm -rf ~/.debug ）也是有用的，并且检查你的内核是否有最新版本的vmlinux，并在内核中启用了调试信息或者kallsyms。

更新：在评论帕维尔说，他的sched:sched_stat_sleep记录没有任何sched:sched_stat_sleep事件写入perf.data：

sudo perf record -e sched:sched_stat_sleep -e sched:sched_switch -e sched:sched_process_exit -g -o ~/perf.data.raw ./a.out

正如他在他的回答中解释的，他的默认debian内核的CONfig_SCHEDSTATS选项被供应商的补丁禁用 。 从3.11开始， Redhat与发行版内核中的选项做了同样的事情，这在Redhat Bug 1013225 （Josh Boyer 2013-10-28，评论4）中有解释：

我们切换到启用，只有在调试版本前一阵子。 似乎完全关闭了最后的3.11.0版本，并一直保持关闭。 内部测试显示该选项对上下文切换具有不重要的性能影响。

我们可以在调试内核中再次打开它，但我不确定这是否值得。

Josh Poimboeuf 2013-11-04在评论8中说，性能影响是可以检测到的：

在我的测试中，我在各种cpu负载下做了很多上下文切换。 当CONfig_SCHEDSTATS被使能时，我看到平均上下文切换速度下降了5-10％。 …性能打击似乎只发生在CFS内核（> = 2.6.23）上。 以前的O（1）调度程序似乎没有这个问题。

Fedora在2013年7月12日的非调试内核中禁用CONfig_SCHEDSTAT “[内核]在非调试版本中禁用LATENCYTOP / SCHEDSTATS”。 由戴夫琼斯。 先禁用内核的选项：3.11.0-0.rc0.git6.4。

为了使用类似sched:sched_stat_* （ sched:sched_stat_wait ， sched:sched_stat_sleep ， sched:sched_stat_iowait ）的任何perf软件跟踪事件，我们必须使用CONfig_SCHEDSTATS选项重新编译内核，并替换没有这个的默认Debian，RedHat或Fedora内核选项。

谢谢帕维尔·达维多夫。

我终于找到了如何使它工作。 问题是默认的debian内核没有配置选项，那么perf需要能够监视睡眠时间。 看起来应该启用CONfig_SCHEDSTATS来使内核收集调度程序统计信息。 这被告知有一些运行时间的开销。 另外我启用了CONfig_SCHED_TRACER和一些锁定追踪选项，但我不确定他们是否在我的情况。 无论如何，没有统计数据在没有CONfig_SCHEDSTATS调度程序中收集（参见kernel/sched/目录）。

此外，Brendan Gregg还写了一篇关于perf的非常好的文章 ，里面有很多有用的例子和一些内核选项，这些都是正确执行perf的工具。

更新：我在debian查了CONfig_SCHEDSTATS的历史。 我已经检查了debian内核补丁和构建脚本回购：

svn checkout svn://svn.debian.org/svn/kernel/dists/trunk/linux/debian

然后在那里找到CONfig_SCHEDSTATS选项

$ grep -R CONfig_SCHEDSTAT config/ config/config:# CONfig_SCHEDSTATS is not set

这个字符串在2008-03-14的提交10837中被添加到回购中，评论“debian / config：做完整的重组”。 另外，在这个和这个 （感谢osgx ）错误报告中，告诉CONfig_LATENCYTOP，CONfig_SCHEDSTATS选项没有被启用，因为它们会影响内核性能。 所以，我认为这是从来没有在默认的debian内核打开。 尽管如此，我还没有找到关于调度程序统计信息的讨论。 如果我这样做，我会写在这里。

这适用于“openSUSE 13.1（x86_64）”框中的“perf version 3.11.1”。

这里是输出，如果你关心：

# ======== # captured on: Sun Feb 16 09:49:38 2014 # hostname : ***************** # os release : 3.11.10-7-desktop # perf version : 3.11.1 # arch : x86_64 # nrcpus online : 8 # nrcpus avail : 8 # cpudesc : Intel(R) Core(TM) i7-3840QM cpu @ 2.80GHz # cpuid : GenuineIntel,6,58,9 # total memory : 32945368 kB # cmdline : /usr/bin/perf inject -v -s -i perf.data.raw -o perf.data # event : name = sched:sched_stat_sleep,type = 2,config = 0x48,config1 = 0x0,config2 = 0x # event : name = sched:sched_switch,config = 0x51,config2 = 0x0,e # event : name = sched:sched_process_exit,config = 0x4e,config2 = # HEADER_cpu_TOPOLOGY info available,use -I to display # HEADER_NUMA_TOPOLOGY info available,use -I to display # pmu mappings: cpu = 4,software = 1,tracepoint = 2,uncore_cBox_0 = 6,uncore_cBox_1 = 7,# ======== # # Samples: 0 of event 'sched:sched_stat_sleep' # Event count (approx.): 0 # # Overhead Period Command Shared Object Symbol # ........ ............ ....... ............. ...... # # Samples: 8 of event 'sched:sched_switch' # Event count (approx.): 80099958776 # # Overhead Period Command Shared Object Symbol # ........ ............ ....... ................. ................. # 100.00% 80099958776 bla [kernel.kallsyms] [k] thread_return | --- thread_return thread_return do_nanosleep hrtimer_nanosleep SyS_nanosleep system_call_fastpath 0x7fbc0dec6570 __GI___libc_nanosleep (nil) # Samples: 0 of event 'sched:sched_process_exit' # Event count (approx.): 0 # # Overhead Period Command Shared Object Symbol # ........ ............ ....... ............. ...... # # # (For a higher level overview,try: perf report --sort comm,dso) # }