用perf来分析睡眠时间

Question

我正在寻找一种方法来找出我的程序花费时间的地方.我阅读了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看起来不太用户友好......

更新:

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

Answer 1

您的第二个perf命令中有一条错误消息来自https://perf.wiki.kernel.org/index.php/Tutorial#Profiling_sleep_times -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看起来不太用户友好...

...但它被添加到perf以使错误更加用户友好:http://lwn.net/Articles/460520/"perf:make 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 %d\n", type);

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

 15         HEADER_TRACING_DATA     = 1,
 16         HEADER_BUILD_ID,

所以,听起来像perf注入无法写入有关构建ID的信息(write_build_id()来自util/header.c的函数的错误),如果我没有错的话.有两种情况可能导致错误:perf_session__read_build_ids()写入buildid表失败或写入失败dsos__write_buildid_table(这不是我们的情况,因为没有"写入buildid表失败"错误消息;检查write_build_id)

您可以检查,您是否拥有会话所需的所有构建.清除buildid cache(rm -rf ~/.debug)并检查是否有最新的vmlinux以及内核中启用的调试信息或kallsyms 可能很有用.

更新:在评论中,Pavel说他的pref记录没有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 "[kernel]在非调试版本中禁用LATENCYTOP/SCHEDSTATS." 戴夫琼斯 第一个带有禁用选项的内核:3.11.0-0.rc0.git6.4.

为了使用任何perf名称为sched:sched_stat_*(sched:sched_stat_wait,, )的软件跟踪点事件sched:sched_stat_sleep,sched:sched_stat_iowait我们必须在CONFIG_SCHEDSTATS启用选项的情况下重新编译内核,并替换没有此选项的默认Debian,RedHat或Fedora内核.

谢谢Pavel Davydov.

Answer 2

我终于找到了如何让它发挥作用.问题是默认的debian内核是在没有一些配置选项的情况下构建的,perf需要能够监控休眠时间.看起来CONFIG_SCHEDSTATS应该启用内核收集调度程序统计信息.这被告知有一些运行时开销.我也启用了CONFIG_SCHED_TRACER一些锁定跟踪选项,但我不确定它们在我的情况下是否重要.无论如何,没有调度程序中没有收集统计​​数据CONFIG_SCHEDSTATS(参见kernel/sched/内核源代码目录).

此外,还有一篇非常好的关于性能的文章,由Brendan Gregg编写,有很多有用的例子和一些内核选项,这些都是使perf正常工作所必需的.

更新:我检查了debian中CONFIG_SCHEDSTATS的历史记录.我查看了debian内核补丁并构建了脚本repo:

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年3月14日的提交10837中的repo中,注释为"debian/config:Do complete reorganization".此外,在这个和这个(感谢osgx)错误报告被告知CONFIG_LATENCYTOP,CONFIG_SCHEDSTATS选项未启用,因为它们会影响内核更流畅.所以,我认为它从未在默认的debian内核中打开.但是,我还没有找到关于调度程序统计选项的讨论.如果我这样做,我会在这里回信.