本文目录:
- strace 简介
- strace 的两种启动方式
- 追踪 nginx 示例
- 系统调用返回错误示例
- 还有哪些系统调用
- 统计每个系统调用的耗时,调用次数,错误次数
- 捕获信号
- 其他
strace 简介
strace 可用于追踪进程与内核的交互情况,包括系统调用,信号,进程状态等信息。
strace 常用于性能分析、问题定位等场景。
strace 基于 linux 内核特性 ptrace 开发,相当于直接 hook 了系统调用。这意味着 strace 可以追踪所有的用户进程,即使没有被追踪程序的源码,或者程序是非 debug 版本,或者程序日志不完善,都可以通过 strace 追踪到不少有用信息。
strace 的两种启动方式
一种是使用 strace 启动被追踪的程序,比如:
# 追踪单次执行的ls命令$strace ls /etc/nginx/
另一种是追踪已启动的进程,使用-p加上进程号:
$strace -p 14735strace: Process 14735 attached...
追踪 nginx 示例
所有网络 IO,文件 IO 操作,底层都涉及到系统调用,我们用一个 nginx 示例来演示。
在我的博客服务器上使用 strace 追踪 nginx worker 的情况:
# 14735是nginx worker的进程号。我的服务器配置比较低,只启动了一个worker进程。$strace -p 14735strace: Process 14735 attachedepoll_wait(11,
当没有请求时,strace 的打印停留在epoll_wait,等待网络事件。
在我本地向远端服务器发起一个请求:
$wget https://pengrl.com/sitemap.xml
strace 将打印出一大堆信息,我截取了部分内容:
...# 每个系统调用,都有参数值,返回值# 可以看到wget客户端的ip和端口,以及该连接对应的文件描述符是5accept4(8, {sa_family=AF_INET, sin_port=htons(58442), sin_addr=inet_addr("111.196.59.95")}, [16], SOCK_NONBLOCK) = 5# 使用的是EPOLLET模式epoll_ctl(11, EPOLL_CTL_ADD, 5, {EPOLLIN|EPOLLRDHUP|EPOLLET, {u32=716806128, u64=93944536471536}}) = 0# 打开了本地的sitemap.xml文件,并读取了文件内容,共9635字节open("/data/pengrl.com/sitemap.xml", O_RDONLY|O_NONBLOCK) = 17pread64(17, "<?xml version="1.0" encoding="UT"..., 9635, 0) = 9635# 向客户端发送了文件内容write(5, "2733&24337232033424127323624120322124734235036357Q5276251/3662=250A327k"..., 9896) = 9896# 向日志文件写入了内容write(3, "111.196.59.95 - - [12/Feb/2020:1"..., 121) = 121# 使用非阻塞模式setsockopt(5, SOL_TCP, TCP_NODELAY, [1], 4) = 0# 关闭了这条连接close(5) = 0...
如果想把写入日志的内容全部打印出来,可以使用如下命令:
# 3是nginx进程写日志的文件描述符$strace -p 14735 -e write=3
再次 wget,得到如下结果:
write(3, "111.196.59.95 - - [12/Feb/2020:1"..., 121) = 121 | 00000 31 31 31 2e 31 39 36 2e 35 39 2e 39 35 20 2d 20 111.196.59.95 - | | 00010 2d 20 5b 31 32 2f 46 65 62 2f 32 30 32 30 3a 31 - [12/Feb/2020:1 | | 00020 31 3a 31 35 3a 30 34 20 2b 30 38 30 30 5d 20 22 1:15:04 +0800] " | | 00030 47 45 54 20 2f 73 69 74 65 6d 61 70 2e 78 6d 6c GET /sitemap.xml | | 00040 20 48 54 54 50 2f 31 2e 31 22 20 32 30 30 20 39 HTTP/1.1" 200 9 | | 00050 36 33 35 20 22 2d 22 20 22 57 67 65 74 2f 31 2e 635 "-" "Wget/1. | | 00060 31 39 2e 31 20 28 64 61 72 77 69 6e 31 35 2e 36 19.1 (darwin15.6 | | 00070 2e 30 29 22 20 22 2d 22 0a .0)" "-". |
系统调用返回错误示例
比如使用 cat 命令打开一个不存在的文件:
$strace cat /etc/nginx/nginx.conf.notexist
在 strace 的输出中将看到:
...open("/etc/nginx/nginx.conf.notexist", O_RDONLY) = -1 ENOENT (No such file or directory)...exit_group(1) = ?+++ exited with 1 +++
可以看到,open 系统调用返回的错误值及对应的错误信息。并且,cat 在打开不存在的文件时,exit code 是 1。如果打开文件成功,exit code 则是 0。
还有哪些系统调用
strace 的-e trace=参数,可以追踪特定系统调用。借由这个参数列表,我们也可以看看还有哪些系统调用:
-e trace=%desc Trace all file descriptor related system calls. %file Trace all system calls which take a file name as an argument. %fstat Trace fstat and fstatat syscall variants. %fstatfs Trace fstatfs, fstatfs64, fstatvfs, osf_fstatfs, and osf_fstatfs64 system calls. %ipc Trace all IPC related system calls. %lstat Trace lstat syscall variants. %memory Trace all memory mapping related system calls. %network Trace all the network related system calls. %process Trace all system calls which involve process management. %pure Trace syscalls that always succeed and have no arguments. %signal Trace all signal related system calls. %stat Trace stat syscall variants. %statfs Trace statfs, statfs64, statvfs, osf_statfs, and osf_statfs64 system calls. %%stat Trace syscalls used for requesting file status. %%statfs Trace syscalls related to file system statistics.
我们尝试使用一个:
$strace -e trace=memory ls /etc/nginx/brk(NULL) = 0x11d4000mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f881f8a2000mmap(NULL, 23250, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f881f89c000...
统计每个系统调用的耗时,调用次数,错误次数
$strace -c ls /etc/nginx/% time seconds usecs/call calls errors syscall------ ----------- ----------- --------- --------- ---------------- 22.16 0.000082 3 28 mmap 19.19 0.000071 4 18 mprotect 12.70 0.000047 4 11 open 8.65 0.000032 3 10 read 7.57 0.000028 9 3 munmap 6.49 0.000024 12 2 getdents 4.05 0.000015 5 3 write 3.24 0.000012 6 2 2 statfs 2.97 0.000011 1 14 close 2.97 0.000011 1 12 fstat 2.16 0.000008 4 2 1 stat 1.62 0.000006 3 2 ioctl 1.62 0.000006 3 2 1 access 1.35 0.000005 5 1 execve 0.81 0.000003 1 3 brk 0.81 0.000003 3 1 openat 0.54 0.000002 1 2 rt_sigaction 0.27 0.000001 1 1 rt_sigprocmask 0.27 0.000001 1 1 getrlimit 0.27 0.000001 1 1 arch_prctl 0.27 0.000001 1 1 set_tid_address 0.00 0.000000 0 1 set_robust_list------ ----------- ----------- --------- --------- ----------------100.00 0.000370 121 4 total
捕获信号
打开一个 tcp 监听进程:
$nc -l 8888
使用 strace 追踪这个进程:
$strace -p $(pidof nc)
kill 掉这个进程:
$kill -9 $(pidof nc)
strace 的输出:
strace: Process 12377 attachedselect(5, [3 4], [], NULL, NULL +++ killed by SIGKILL +++
其他
strace 还有许多其他的参数,比如常用的-tt可以打印每个系统调用的时间戳,-T可以打印每个系统调用花费的时间。
strace 不光能追踪统计系统调用,还能修改系统调用的行为,比如指定某个系统调用返回指定的错误值。
关于更多 strace 的玩法,可以使用strace -h命令或访问如下两个网站获取更多的信息:
- http://www.man7.org/linux/man-pages/man1/strace.1.html
- https://strace.io/