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

Cra*_*ger 5 linux performance blocking systemtap perf

我正在寻找方法来了解进程或线程花时间等待的系统调用子系统,即阻塞而不是安排在 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 工作。但在悲惨的运维世界中,支持 4.6 内核的独角兽却是难得一见的珍贵。

现实世界的选择是什么?

ftrace、systemtap 等在这里提供任何见解吗?

Had*_*ais 4

您可以使用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
Run Code Online (Sandbox Code Playgroud)

% 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>
Run Code Online (Sandbox Code Playgroud)

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

如果你想找出诸如“它在 fd 13 上的 sys_write() 中花费了 80% 的时间,即 /some/file”之类的信息,那么你需要编写一个脚本,首先提取所有open调用的返回值和相应的文件命名参数,然后对参数等于某个值的所有sys_write调用的时间求和。fd