确定进程花费时间等待的系统调用或子系统答案

【问题标题】：Determine syscalls or subsystems a process is spending time waiting in确定进程花费时间等待的系统调用或子系统
【发布时间】：2019-02-08 16:43:31
【问题描述】：

我正在寻找方法来了解哪些系统调用或哪些子系统进程或线程花费时间等待，即被阻塞且未安排在 CPU 上运行。

具体来说，如果我有一些未知的过程，或者我们所知道的“它很慢”的过程，我希望能够学习以下内容：

“它将 80% 的时间花在 sys_write() 上的 fd 13 上，即 /some/file”
“它花费大量时间等待从网络套接字读取（）”
“它正在 epoll_wait() 中休眠，用于 fds [4,5,6] 上的活动，它们是 [file /boo]、[socket 10.1.1.:42]、[notifyfd blah]”

换句话说当我的程序不在 CPU 上运行时，它在做什么？

这令人惊讶地很难用 perf 回答，因为它似乎没有任何方法可以记录 从 sys_enter 到 sys_exit 的系统调用的持续时间或以其他方式保留跟踪事件的多长时间。大概是因为它的采样性质。

我知道一些针对 Linux 4.6 及更高版本的 eBPF 的实验性工作可能会有所帮助，Brendan Gregg 的 off-cpu work。但在悲惨的运营和支持 4.6 内核的世界中，这是一个难得的值得珍惜的独角兽。

现实世界的选择是什么？

ftrace、systemtap 等是否在这里提供任何见解？

【问题讨论】：

标签： linux performance blocking perf systemtap

【解决方案1】：

您可以使用strace。首先，您可能希望获得每种系统调用成本的高级摘要。您可以通过运行strace -c 获取此摘要。例如，一种可能的输出如下：

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 90.07    0.000263          26        10           getdents
  3.42    0.000010           0      1572           read
  3.42    0.000010           0       762         1 stat
  3.08    0.000009           0      1574         6 open
  0.00    0.000000           0        11           write
  0.00    0.000000           0      1569           close
  0.00    0.000000           0        48           fstat

% time 值是相对于整体内核时间，而不是整体执行时间（内核+用户）。此摘要告诉您最昂贵的系统调用是什么。但是，如果您需要确定系统调用的哪些特定实例最昂贵以及传递给它们的参数是什么，您可以运行strace -i -T。 -i 选项显示执行系统调用的指令的指令地址，-T 选项显示系统调用所花费的时间。输出可能如下所示：

[00007f97f1b37367] open("myfile", O_RDONLY|O_CLOEXEC) = 3 <0.000020>
[00007f97f1b372f4] fstat(3, {st_mode=S_IFREG|0644, st_size=159776, ...}) = 0 <0.000018>
[00007f97f1b374ba] mmap(NULL, 159776, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f97f1d19000 <0.000019>
[00007f97f1b37467] close(3)             = 0 <0.000018>

第一列显示指令地址，第二列显示系统调用及其参数，第三列显示返回值，最后一列显示系统调用所花费的时间。该列表按系统调用的动态发生排序。您可以使用grep 或-e 选项过滤此输出。指令地址可以帮助您找到在源代码中进行这些系统调用的位置。例如，如果一长串系统调用具有相同的地址，那么很有可能在包含系统调用的代码中的某处存在循环。如果您的可执行二进制文件不是PIE，则动态地址与objdump 显示的静态地址相同。但即使使用 PIE，动态地址的相对顺序也是相同的。我不知道是否有一种简单的方法可以将这些系统调用映射到源代码行。

如果你想找出诸如“它在 fd 13 上的 sys_write() 中花费 80% 的时间，即 /some/file”之类的东西，那么你需要编写一个脚本，首先提取所有 @987654333 的返回值@调用和相应的文件名参数，然后总结所有sys_write调用的次数，其fd参数等于某个值。

【讨论】：