【问题标题】:Profiling sleep times with perf使用 perf 分析睡眠时间
【发布时间】:2014-03-12 10:32:30
【问题描述】:

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

#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 这是一种用于分析睡眠时间的特殊模式,perf 仅查找调度程序切换事件,而不是 CPU 周期。
  • 目前,您所指的教程具有误导性,您不会得到任何有用的东西。我认为 perf 目前不允许分析睡眠时间,report is filled。
  • @Hi-Angel 这个问题是在 2014 年提出的。现在我们有了 ebpf,所以我认为今天不需要有人需要 perf 睡眠时间分析......
  • @PavelDavydov 感谢您的提及,尽管有些链接确实会有所帮助。我认为您指的是密件抄送脚本和here's a usage example,无论是单独还是带有火焰图。

标签: c linux profiling perf


【解决方案1】:

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

此外,还有一个由 Brendan Gregg 编写的非常 good article about perf,其中包含许多有用的示例和一些使 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”。此外,在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 是的,现在终于可以使用了!即使perf test 中的大多数自测现在都通过了。谢谢你的帮助。可惜找到它的唯一方法是在内核代码中搜索..
  • 是的,我有带有 debian 补丁的 3.13.10 内核源代码(来自 repo),并且在 kernel/sched/fair.c 中它禁用了(trace_sched_stat_wait 和 trace_sched_stat_sleep)跟踪点。更重要的是,它看起来只是禁用了所有调度程序统计信息收集,而不仅仅是跟踪点。
  • @osgx hm,我想我必须先检查一下。我认为 debian 内核团队故意禁用它,因为它已知开销。我是这么想的,因为我看到了redhat bug report。
  • 我发现 debian 错误 481684 和 600935 bugs.debian.org/cgi-bin/bugreport.cgi?bug=481684 bugs.debian.org/cgi-bin/bugreport.cgi?bug=600935 - debian 中的 2.6.26 已经禁用了 SCHEDSTATS。我们可以尝试搜索latencytop-not working 报告,因为 CONFIG_SCHEDSTAT 是它需要的选项之一;比如groups.google.com/forum/#!topic/debian-chinese/EdtPIPovJbQ我认为Ubuntu启用了这个选项,但我会重新检查它。
【解决方案2】:

来自https://perf.wiki.kernel.org/index.php/Tutorial#Profiling_sleep_times - perf inject -s 的第二个 perf 命令有错误消息

$ 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)” by 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 injection 无法写入有关构建 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) 并检查您是否有最新的 vmlinux 并在您的内核中启用了调试信息或 kallsyms 可能很有用。

更新:在 cmets 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

正如他在 his answer 中解释的那样,他的默认 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 日 "[kernel] Disable LATENCYTOP/SCHEDSTATS in non-debug builds." 由 Dave Jones 禁用了非调试内核中的 CONFIG_SCHEDSTAT。第一个禁用选项的内核: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,您可以从任何内核重建 perf 工具,而无需重新编译内核本身。执行cd tools/perf,阅读Makefile.perf 并运行make(您需要构建linux-tools 包所需的开发包)。我可以建议您清除 buildid 缓存(~/.debug 文件夹),使用安装了调试符号的发行版中的内核。然后,您可以重建 perf 并使用 gdb 或 printfs 对其进行调试。也可以试试perf record 的-N 选项。
  • 调试性能听起来是一项具有挑战性的任务。有时间我会尝试调试它,或者检查 vmlinux 和内核符号。
  • 这看起来很奇怪,为什么当我的程序调用sleep 4 秒时它没有睡眠样本?
  • 在较新的内核中,您还需要启用 sched stats,例如通过:`回声1 | sudo tee /proc/sys/kernel/sched_schedstats`
【解决方案3】:

这适用于“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, 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)
#
}

【讨论】:

  • 谢谢,那么,我得到的错误是什么意思,我怎样才能使这个功能起作用?你是否使用了一些特殊的标志来编译你的内核?
  • 我不知道错误的含义我没有重新编译我的内核,我在启动 perf 之前发出了echo 0 &gt; /proc/sys/kernel/kptr_restrict 以允许它访问内核地址映射。我认为你应该升级你的性能。
  • 看来我的 perf 版本比你的更新,我有 3.12。它是 debian 测试存储库中的最新版本,因此要安装更新的 perf,我需要编译一个 vanilla 内核,但我不知道要使用什么标志..
猜你喜欢
  • 2017-07-25
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 2022-07-08
  • 2022-01-12
相关资源
最近更新 更多