跟踪工具 | 系统分析与调优指南 | openSUSE Leap 15.6

系统分析与调优指南 › 处理系统转储 › 跟踪工具

适用于 openSUSE Leap 15.6

17 跟踪工具 #编辑源文件

17.1 使用 strace 跟踪系统调用
17.2 使用 ltrace 跟踪库调用
17.3 使用 Valgrind 进行调试和分析
17.4 更多信息

openSUSE Leap 附带了几个工具，可以帮助您获取有关系统的有用信息。您可以将这些信息用于不同的目的。例如，调试和查找程序中的问题，发现导致性能下降的地方，或者跟踪正在运行的进程以找出它使用的系统资源。

注意：跟踪对性能的影响

当正在运行的进程被监视系统或库调用时，该进程的性能会大大降低。建议仅在需要收集数据时才使用跟踪工具。

17.1 使用 strace 跟踪系统调用 #编辑源文件

命令 strace 跟踪进程的系统调用和进程收到的信号。 strace 可以运行新命令并跟踪其系统调用，也可以将 strace 附加到已经运行的命令。该命令输出的每一行包含系统调用名称，后跟其参数（在括号中）和返回值。

要运行新命令并开始跟踪其系统调用，请像往常一样输入要监视的命令，并在命令行开头添加 strace

> strace ls
execve("/bin/ls", ["ls"], [/* 52 vars */]) = 0
brk(0)                                  = 0x618000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) \
        = 0x7f9848667000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) \
        = 0x7f9848666000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT \
(No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=200411, ...}) = 0
mmap(NULL, 200411, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f9848635000
close(3)                                = 0
open("/lib64/librt.so.1", O_RDONLY)     = 3
[...]
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) \
= 0x7fd780f79000
write(1, "Desktop\nDocuments\nbin\ninst-sys\n", 31Desktop
Documents
bin
inst-sys
) = 31
close(1)                                = 0
munmap(0x7fd780f79000, 4096)            = 0
close(2)                                = 0
exit_group(0)                           = ?

要将 strace 附加到已经运行的进程，需要指定 -p 选项以及要监视的进程的进程 ID (PID)

> strace -p `pidof cron`
 Process 1261 attached
 restart_syscall(<... resuming interrupted call ...>) = 0
  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2309, ...}) = 0
  select(5, [4], NULL, NULL, {0, 0})      = 0 (Timeout)
  socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 5
  connect(5, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = 0
  sendto(5, "\2\0\0\0\0\0\0\0\5\0\0\0root\0", 17, MSG_NOSIGNAL, NULL, 0) = 17
  poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=5, revents=POLLIN|POLLHUP}])
  read(5, "\2\0\0\0\1\0\0\0\5\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\5\0\0\0\6\0\0\0"..., 36) = 36
  read(5, "root\0x\0root\0/root\0/bin/bash\0", 28) = 28
  close(5)                                = 0
  rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
  rt_sigaction(SIGCHLD, NULL, {0x7f772b9ea890, [], SA_RESTORER|SA_RESTART, 0x7f772adf7880}, 8) = 0
  rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
  nanosleep({60, 0}, 0x7fff87d8c580)      = 0
  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2309, ...}) = 0
  select(5, [4], NULL, NULL, {0, 0})      = 0 (Timeout)
  socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 5
  connect(5, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = 0
  sendto(5, "\2\0\0\0\0\0\0\0\5\0\0\0root\0", 17, MSG_NOSIGNAL, NULL, 0) = 17
  poll([{fd=5, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=5, revents=POLLIN|POLLHUP}])
  read(5, "\2\0\0\0\1\0\0\0\5\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0\5\0\0\0\6\0\0\0"..., 36) = 36
  read(5, "root\0x\0root\0/root\0/bin/bash\0", 28) = 28
  close(5)
  [...]

选项 -e 理解几个子选项和参数。例如，要跟踪所有尝试打开或写入特定文件的尝试，请使用以下命令

> strace -e trace=open,write ls ~
open("/etc/ld.so.cache", O_RDONLY)       = 3
open("/lib64/librt.so.1", O_RDONLY)      = 3
open("/lib64/libselinux.so.1", O_RDONLY) = 3
open("/lib64/libacl.so.1", O_RDONLY)     = 3
open("/lib64/libc.so.6", O_RDONLY)       = 3
open("/lib64/libpthread.so.0", O_RDONLY) = 3
[...]
open("/usr/lib/locale/cs_CZ.utf8/LC_CTYPE", O_RDONLY) = 3
open(".", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
write(1, "addressbook.db.bak\nbin\ncxoffice\n"..., 311) = 311

要仅跟踪与网络相关的系统调用，请使用 -e trace=network

> strace -e trace=network -p 26520
Process 26520 attached - interrupt to quit
socket(PF_NETLINK, SOCK_RAW, 0)         = 50
bind(50, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
getsockname(50, {sa_family=AF_NETLINK, pid=26520, groups=00000000}, \
[12]) = 0
sendto(50, "\24\0\0\0\26\0\1\3~p\315K\0\0\0\0\0\0\0\0", 20, 0,
{sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
[...]

选项 -c 计算内核在每个系统调用上花费的时间

> strace -c find /etc -name xorg.conf
/etc/X11/xorg.conf
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 32.38    0.000181         181         1           execve
 22.00    0.000123           0       576           getdents64
 19.50    0.000109           0       917        31 open
 19.14    0.000107           0       888           close
  4.11    0.000023           2        10           mprotect
  0.00    0.000000           0         1           write
[...]
  0.00    0.000000           0         1           getrlimit
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         3         1 futex
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         4           fadvise64
  0.00    0.000000           0         1           set_robust_list
------ ----------- ----------- --------- --------- ----------------
100.00    0.000559                  3633        33 total

要跟踪进程的所有子进程，请使用 -f

> strace -f systemctl status apache2.service
execve("/usr/bin/systemctl", ["systemctl", "status", "apache2.service"], \
 0x7ffea44a3318 /* 56 vars */) = 0
brk(NULL)                               = 0x5560f664a000
[...]
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f98c58a5000
mmap(NULL, 4420544, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f98c524a000
mprotect(0x7f98c53f4000, 2097152, PROT_NONE) = 0
[...]
[pid  9130] read(0, "\342\227\217 apache2.service - The Apache"..., 8192) = 165
[pid  9130] read(0, "", 8027)           = 0
● apache2.service - The Apache Webserver227\217 apache2.service - Th"..., 193
   Loaded: loaded (/usr/lib/systemd/system/apache2.service; disabled; vendor preset: disabled)
   Active: inactive (dead)
) = 193
[pid  9130] ioctl(3, SNDCTL_TMR_STOP or TCSETSW, {B38400 opost isig icanon echo ...}) = 0
[pid  9130] exit_group(0)               = ?
[pid  9130] +++ exited with 0 +++
<... waitid resumed>{si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=9130, \
 si_uid=0, si_status=0, si_utime=0, si_stime=0}, WEXITED, NULL) = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=9130, si_uid=0, \
  si_status=0, si_utime=0, si_stime=0} ---
exit_group(3)                           = ?
+++ exited with 3 +++

如果您需要分析 strace 的输出，并且输出消息太长而无法直接在控制台窗口中检查，请使用 -o。在这种情况下，不必要的消息（例如有关附加和分离进程的信息）将被抑制。您还可以使用 -q 抑制这些消息（通常打印到标准输出）。要在每行系统调用的开头添加时间戳，请使用 -t

> strace -t -o strace_sleep.txt sleep 1; more strace_sleep.txt
08:44:06 execve("/bin/sleep", ["sleep", "1"], [/* 81 vars */]) = 0
08:44:06 brk(0)                         = 0x606000
08:44:06 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, \
-1, 0) = 0x7f8e78cc5000
[...]
08:44:06 close(3)                       = 0
08:44:06 nanosleep({1, 0}, NULL)        = 0
08:44:07 close(1)                       = 0
08:44:07 close(2)                       = 0
08:44:07 exit_group(0)                  = ?

strace 的行为和输出格式可以控制。有关更多信息，请参阅相关的手册页 (man 1 strace)。

17.2 使用 ltrace 跟踪库调用 #编辑源文件

ltrace 跟踪进程的动态库调用。它的使用方式与 strace 类似，并且它们的大多数参数具有相似或相同的含义。默认情况下，ltrace 使用 /etc/ltrace.conf 或 ~/.ltrace.conf 配置文件。但是，您可以使用 -F CONFIG_FILE 选项指定替代配置文件。

除了库调用之外，ltrace 还可以使用 -S 选项跟踪系统调用

> ltrace -S -o ltrace_find.txt find /etc -name \
xorg.conf; more ltrace_find.txt
SYS_brk(NULL)                                              = 0x00628000
SYS_mmap(0, 4096, 3, 34, 0xffffffff)                       = 0x7f1327ea1000
SYS_mmap(0, 4096, 3, 34, 0xffffffff)                       = 0x7f1327ea0000
[...]
fnmatch("xorg.conf", "xorg.conf", 0)                       = 0
free(0x0062db80)                                           = <void>
__errno_location()                                         = 0x7f1327e5d698
__ctype_get_mb_cur_max(0x7fff25227af0, 8192, 0x62e020, -1, 0) = 6
__ctype_get_mb_cur_max(0x7fff25227af0, 18, 0x7f1327e5d6f0, 0x7fff25227af0,
0x62e031) = 6
__fprintf_chk(0x7f1327821780, 1, 0x420cf7, 0x7fff25227af0, 0x62e031
<unfinished ...>
SYS_fstat(1, 0x7fff25227230)                               = 0
SYS_mmap(0, 4096, 3, 34, 0xffffffff)                       = 0x7f1327e72000
SYS_write(1, "/etc/X11/xorg.conf\n", 19)                   = 19
[...]

您可以使用 -e 选项更改要跟踪的事件类型。以下示例打印与 fnmatch 和 strlen 函数相关的库调用

> ltrace -e fnmatch,strlen find /etc -name xorg.conf
[...]
fnmatch("xorg.conf", "xorg.conf", 0)             = 0
strlen("Xresources")                             = 10
strlen("Xresources")                             = 10
strlen("Xresources")                             = 10
fnmatch("xorg.conf", "Xresources", 0)            = 1
strlen("xorg.conf.install")                      = 17
[...]

要仅显示特定库中包含的符号，请使用 -l /path/to/library

> ltrace -l /lib64/librt.so.1 sleep 1
clock_gettime(1, 0x7fff4b5c34d0, 0, 0, 0)                  = 0
clock_gettime(1, 0x7fff4b5c34c0, 0xffffffffff600180, -1, 0) = 0
+++ exited (status 0) +++

您可以通过使用指定的空格数缩进每个嵌套调用来使输出更具可读性，方法是使用 -n NUM_OF_SPACES。

17.3 使用 Valgrind 进行调试和分析 #编辑源文件

Valgrind 是一组用于调试和分析程序的工具，以便它们可以更快地运行并减少错误。Valgrind 可以检测与内存管理和线程相关的错误，或者也可以作为构建新的调试工具的框架。众所周知，此工具会产生很高的开销，例如，导致更高的运行时间或更改基于时序的并发工作负载下的正常程序行为。

17.3.1 常规信息 #编辑源文件

Valgrind 的主要优点是它可以与现有的编译的可执行文件一起工作。您无需重新编译或修改程序即可使用它。像这样运行 Valgrind

valgrind VALGRIND_OPTIONS your-prog YOUR-PROGRAM-OPTIONS

Valgrind 由几个工具组成，每个工具都提供特定的功能。本节中的信息是通用的，并且无论使用的工具如何都有效。最重要的配置选项是 --tool。此选项告诉 Valgrind 要运行哪个工具。如果您省略此选项，则默认选择 memcheck。例如，要使用 Valgrind 的 memcheck 工具运行 find ~ -name .bashrc，请在命令行中输入以下内容

valgrind --tool=memcheck find ~ -name .bashrc

以下是标准 Valgrind 工具列表及其简要说明

memcheck: 检测内存错误。它可帮助您调整程序以正确运行。
cachegrind: 分析缓存预测。它可帮助您调整程序以更快地运行。
callgrind: 以类似于 cachegrind 的方式工作，但也会收集其他缓存分析信息。
exp-drd: 检测线程错误。它可帮助您调整多线程程序以正确运行。
helgrind: 另一个线程错误检测器。与 exp-drd 类似，但使用不同的技术进行问题分析。
massif: 堆分析器。堆是用于动态内存分配的内存区域。此工具可帮助您调整程序以使用更少的内存。
lackey: 一个示例工具，显示了工具的基本知识。

17.3.2 默认选项 #编辑源文件

Valgrind 可以在启动时读取选项。Valgrind 检查以下三个位置

运行 Valgrind 的用户的家目录中的文件 .valgrindrc。
环境变量 $VALGRIND_OPTS
Valgrind 运行的当前目录中的文件 .valgrindrc。

这些资源按此顺序解析，而后面的选项优先于较早处理的选项。特定 Valgrind 工具的选项必须以该工具的名称和冒号为前缀。例如，如果您希望 cachegrind 始终将配置文件数据写入 /tmp/cachegrind_%p.log，请将以下行添加到您家目录中的 .valgrindrc 文件

--cachegrind:cachegrind-out-file=/tmp/cachegrind_%p.log

17.3.3 Valgrind 的工作方式 #编辑源文件

Valgrind 在程序启动之前控制您的可执行文件。它从可执行文件和相关的共享库中读取调试信息。可执行文件的代码重定向到选定的 Valgrind 工具，该工具添加自己的代码来处理其调试。然后，代码返回到 Valgrind 核心，执行继续。

例如，memcheck 添加了自己的代码，该代码检查每次内存访问。因此，程序运行的速度比在本地执行环境中的速度慢得多。

Valgrind 模拟程序的每条指令。因此，它不仅检查程序的代码，还检查所有相关的库（包括 C 库）、用于图形环境的库等。如果您尝试使用 Valgrind 检测错误，它还会检测相关库中的错误（例如 C、X11 或 Gtk 库）。由于您并不经常需要所有这些错误，因此 Valgrind 可以选择性地将这些错误消息抑制到抑制文件中。 --gen-suppressions=yes 告诉 Valgrind 报告这些抑制，您可以将其复制到文件中。

您应该提供一个真实的（机器代码）可执行文件作为 Valgrind 参数。如果您的应用程序例如从 shell 或 Perl 脚本运行，您可能会错误地收到与 /bin/sh（或 /usr/bin/perl）相关的错误报告。在这种情况下，您可以使用 --trace-children=yes 来解决此问题。但是，使用可执行文件本身可以避免对此问题的任何混淆。

17.3.4 消息 #编辑源文件

在运行时，Valgrind 会报告包含详细错误和重要事件的消息。以下示例解释了这些消息

> valgrind --tool=memcheck find ~ -name .bashrc
[...]
==6558== Conditional jump or move depends on uninitialised value(s)
==6558==    at 0x400AE79: _dl_relocate_object (in /lib64/ld-2.11.1.so)
==6558==    by 0x4003868: dl_main (in /lib64/ld-2.11.1.so)
[...]
==6558== Conditional jump or move depends on uninitialised value(s)
==6558==    at 0x400AE82: _dl_relocate_object (in /lib64/ld-2.11.1.so)
==6558==    by 0x4003868: dl_main (in /lib64/ld-2.11.1.so)
[...]
==6558== ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 0 from 0)
==6558== malloc/free: in use at exit: 2,228 bytes in 8 blocks.
==6558== malloc/free: 235 allocs, 227 frees, 489,675 bytes allocated.
==6558== For counts of detected errors, rerun with: -v
==6558== searching for pointers to 8 not-freed blocks.
==6558== checked 122,584 bytes.
==6558==
==6558== LEAK SUMMARY:
==6558==    definitely lost: 0 bytes in 0 blocks.
==6558==      possibly lost: 0 bytes in 0 blocks.
==6558==    still reachable: 2,228 bytes in 8 blocks.
==6558==         suppressed: 0 bytes in 0 blocks.
==6558== Rerun with --leak-check=full to see details of leaked memory.

==6558== 引入 Valgrind 的消息并包含进程 ID 号 (PID)。您可以轻松地区分 Valgrind 的消息和程序本身的输出，并确定哪些消息属于特定进程。

要使 Valgrind 的消息更详细，请使用 -v 甚至 -v -v。

您可以将 Valgrind 的消息发送到三个不同的位置

默认情况下，Valgrind 会将消息发送到文件描述符 2，即标准错误输出。您可以告诉 Valgrind 使用 --log-fd=FILE_DESCRIPTOR_NUMBER 选项将其消息发送到任何其他文件描述符。
第二种，更实用的方法是使用 --log-file=FILENAME 将 Valgrind 的消息发送到文件。此选项接受几个变量，例如，%p 将替换为当前分析的进程的 PID。这样，您可以根据其 PID 将消息发送到不同的文件。 %q{env_var} 将替换为相关的 env_var 环境变量的值。
以下示例检查在 Apache Web 服务器重新启动期间可能出现的内存错误，同时跟踪子进程并将详细的 Valgrind 消息写入由当前进程 PID 区分的单独文件
```
> valgrind -v --tool=memcheck --trace-children=yes \
--log-file=valgrind_pid_%p.log systemctl restart apache2.service
```
此过程在测试系统中创建了 52 个日志文件，并且花费了 75 秒，而没有 Valgrind 的 sudo systemctl restart apache2.service 通常需要 7 秒，大约快 10 倍。
```
> ls -1 valgrind_pid_*log
valgrind_pid_11780.log
valgrind_pid_11782.log
valgrind_pid_11783.log
[...]
valgrind_pid_11860.log
valgrind_pid_11862.log
valgrind_pid_11863.log
```
您可能还希望通过网络发送 Valgrind 的消息。您需要使用 --log-socket=AA.BB.CC.DD:PORT_NUM 选项指定 aa.bb.cc.dd IP 地址和 port_num 端口号的网络套接字。如果省略端口号，则使用 1500。
如果远程机器上没有能够接收它们的应用程序，则将 Valgrind 的消息发送到网络套接字是没有用的。这就是为什么 valgrind-listener，一个简单的监听器，与 Valgrind 一起提供的原因。它接受指定端口上的连接并将它接收到的所有内容复制到标准输出。

17.3.5 错误消息 #编辑源文件

Valgrind 会记住所有错误消息，并且如果它检测到新的错误，则会将该错误与旧错误消息进行比较。这样 Valgrind 检查重复的错误消息。如果出现重复的错误，则会记录该错误，但不会显示消息。此机制可以防止您被数百万个重复的错误所淹没。

选项 -v 在 Valgrind 执行输出的末尾添加所有报告的摘要（按总计数排序）。此外，Valgrind 会在检测到 1000 个不同的错误或总共 10,000,000 个错误时停止收集错误。要抑制此限制并查看所有错误消息，请使用 --error-limit=no。

某些错误会导致其他错误。因此，请按照它们出现的顺序修复错误并连续重新检查程序。

17.4 更多信息 #编辑源文件

有关所描述的跟踪工具的完整选项列表，请参阅相应的手册页 (man 1 strace、man 1 ltrace 和 man 1 valgrind)。
描述 Valgrind 的高级用法超出了本文档的范围。它有很好的文档记录，请参阅 Valgrind 用户手册。如果您需要有关 Valgrind 或其标准工具的更多高级信息，这些页面是必不可少的。

打印此页面