logo标签列表

使用perf对睡眠时间进行分析

clinuxprofilingperf
21

我想找到一种方法来确定我的程序花费了多少时间。我阅读了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
我认为perf不是合适的工具。它监控CPU使用情况，而你的程序几乎不使用CPU时间。 - ugoren
1
@ugoren 这是一种用于分析睡眠时间的特殊模式，perf 只会查找调度器切换事件，而不是 CPU 周期。 - Pavel Davydov
目前，你所参考的教程是误导性的，按照它所述你将得不到任何有用的东西。我认为perf目前不允许分析睡眠时间，报告已经填写。 - Hi-Angel
@Hi-Angel 这个问题是在2014年提出的。现在我们有ebpf，所以我不认为今天有人需要perf睡眠时间分析... - Pavel Davydov
@PavelDavydov 谢谢你的提醒，不过如果有一些链接会更好。我想你是在提到 bcc 脚本，这里有一个使用示例，可以单独使用或与火焰图一起使用。 - Hi-Angel
3个回答
13

您的第二个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 more self-descriptive (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 失败（因为没有“无法编写 buildid 表”错误消息，因此这不是我们的情况；请检查 write_build_id）

您可以检查一下，是否拥有会话所需的所有 buildid。 另外，清除 buildid 缓存（rm -rf ~/.debug），检查您的内核中是否启用了调试信息或 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 选项。Redhat 自 3.11 版本以来也在发行内核中禁用了该选项，并在 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，由 Dave Jones 在 "[kernel] Disable LATENCYTOP/SCHEDSTATS in non-debug builds." 中宣布。第一个禁用该选项的内核为 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 内核，这些内核没有此选项。

谢谢 Pavel Davydov。

谢谢，有没有办法让它工作起来？我应该构建一个新的内核，重新构建当前的内核，还是进行一些配置？ - Pavel Davydov
@Pavel Davydov，您可以在不重新编译内核本身的情况下从任何内核重建perf工具。执行cd tools/perf，阅读Makefile.perf并运行make（您需要构建linux-tools软件包所需的开发软件包）。我建议您清除buildid缓存（~/.debug文件夹），使用安装了调试符号的发行版内核。然后，您可以重建perf并使用gdb或printf进行调试。还可以尝试perf record的-N选项。 - osgx
1
这看起来很奇怪，为什么没有睡眠样本，当我的程序调用 sleep 四秒钟？ - Pavel Davydov
此外，perf inject 打印了一条消息： symsrc__init: 无法获取 ELF 头。使用 /usr/lib/debug/lib/modules/3.12-1-amd64/vmlinux 作为符号文件。- 也许我需要检查一下我的内核是否有调试符号.. - Pavel Davydov
3
在更新的内核中，您还需要启用调度统计信息，例如：echo 1 | sudo tee /proc/sys/kernel/sched_schedstats。 - milianw
显示剩余8条评论
7
我终于找到了如何使其工作的方法。问题在于默认的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: Do complete reorganization”。此外，在this和this（感谢osgx）的错误报告中指出，CONFIG_LATENCYTOP、CONFIG_SCHEDSTATS选项未启用，因为它们可能会影响内核性能。因此，我认为默认情况下Debian内核从未打开它们。虽然我没有找到有关调度程序统计选项的讨论，但如果我找到了，我会在这里回复。

那么，现在你的 "perf record -e sched:sched_stat_sleep -e sched:sched_switch -e sched:sched_process_exit" 工作了吗？ - osgx
1
是的，我有带有Debian补丁的3.13.10内核源代码（来自存储库），在kernel/sched/fair.c中它禁用了(trace_sched_stat_wait和trace_sched_stat_sleep)跟踪点。更重要的是，它似乎只是禁用了所有调度器统计信息收集，而不仅仅是跟踪点。 - Pavel Davydov
1
@osgx 嗯，我想我得先检查一下... 我认为 Debian 内核团队故意禁用它是因为它已知的开销。我之所以这样认为，是因为我看到了 redhat bug report。 - Pavel Davydov
1
我已经找到了Debian的481684和600935个bug https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=481684 https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=600935 - Debian中的2.6.26版本已经禁用了SCHEDSTATS。我们可以尝试搜索“latencytop”-不工作的报告，因为CONFIG_SCHEDSTAT是其中一个选项；例如https://groups.google.com/forum/#!topic/debian-chinese/EdtPIPovJbQ 我认为Ubuntu启用了此选项，但我会重新检查。 - osgx
@osgx，我在我的回答中添加了一个更新，我认为此选项在Debian内核中从未启用，他们认为这是正确的，因为它可以提高性能。 - Pavel Davydov
显示剩余6条评论
1
这对我来说可行，适用于“openSUSE 13.1（x86_64）”盒子上的“perf版本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, type = 2, config = 0x51, config1 = 0x0, config2 = 0x0, e
# event : name = sched:sched_process_exit, type = 2, config = 0x4e, config1 = 0x0, 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)
#
}
谢谢，那么，我得到的错误是什么意思，我该如何使这个功能工作？您是否使用了一些特殊的标志来编译内核？ - Pavel Davydov
1
我不知道错误的含义，我没有重新编译我的内核，在启动perf之前，我发出了echo 0 > /proc/sys/kernel/kptr_restrict以允许其访问内核地址映射。我认为你应该升级你的perf。 - hivert
看起来我的perf版本比你的新，我有3.12。这是Debian测试存储库中最新的版本，所以要安装更新的perf，我需要编译一个vanilla内核，但我不知道要使用什么标志.. - Pavel Davydov
网页内容由stack overflow 提供, 点击上面的
可以查看英文原文，
原文链接