c - 使用 perf 分析 sleep 时间

Question

我一直在寻找一种方法来找出我的程序花费时间的地方。我读了perf tutorial并尝试按照那里的描述描述 sleep 时间。我写了最简单的程序来分析:

#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!

有人知道如何避免这些错误吗？他们的意思是什么？ 无法编写功能 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

来自 https://perf.wiki.kernel.org/index.php/Tutorial#Profiling_sleep_times 的第二个 perf 命令有一条错误消息- 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

failed to write feature 2 doesn't look too user-friendly...

... 但它被添加到 perf 中以使错误更加用户友好:http://lwn.net/Articles/460520/ “perf:使 perf.data 更具 self 描述性(v5)”，作者 Stephane Eranian，2011 年 9 月 22 日:

+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 inject 无法写入有关构建 ID 的信息(来自 util/header.c 的函数 write_build_id() 的错误)。有两种情况会导致错误:perf_session__read_build_ids() 调用不成功或写入 buildid 表失败dsos__write_buildid_table(这不是我们的情况，因为没有“failed to write buildid table"错误消息；检查 write_build_id)

您可以检查一下，您是否拥有 session 所需的所有 buildids。清除您的 buildid 缓存 (rm -rf ~/.debug) 也可能很有用，并检查您是否拥有最新的 vmlinux，并在您的内核中启用了调试信息或 kallsyms。

更新:Pavel 在评论中说他的 pref 记录没有任何写入 perf.data 的 sched:sched_stat_sleep 事件:

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

正如他在 his answer 中解释的那样，他的默认 debian 内核有 CONFIG_SCHEDSTATS 选项禁用 与供应商的补丁。自 3.11 以来，redhat 对发布内核中的选项做了同样的事情，这在 Redhat Bug 1013225 中有解释。 (Josh Boyer 2013-10-28，评论 4):

We switched to enabling that only on debug builds a while ago. It seems that was turned off entirely with the final 3.11.0 build and has remained off since. Internal testing shows the option has a non-trivial performance impact for context switches.

We can turn this on in debug kernels again, but I'm not sure it's worthwhile.

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

In my tests I did a lot of context switches under various CPU loads. I saw a ~5-10% drop in average context switch speed when CONFIG_SCHEDSTATS was enabled. ...The performance hit only seemed to happen on post-CFS kernels (>= 2.6.23). The previous O(1) scheduler didn't seem to have this issue.

Fedora 于 2013 年 7 月 12 日在非调试内核中禁用了 CONFIG_SCHEDSTAT "[kernel] Disable LATENCYTOP/SCHEDSTATS in non-debug builds."戴夫琼斯。第一个禁用选项的内核:3.11.0-0.rc0.git6.4。

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

谢谢你，Pavel Davydov。