十个例子让你了解 strace 的使用技巧

2022-03-01 17:53:25   最后更新: 2022-03-01 17:54:46   访问数量:141




 

此前的文章中我们介绍了 tcpdump 的实用技巧:

 

实战计算机网络问题排查(二) -- tcpdump 的过滤指令

 

tcpdump 作为计算机网络排查的一大神器,掌握了上文所说的技巧,可以让你随时随地得心应手的掌握网络应用的一举一动。

 

那么,除了得知一个应用正在做着什么样的网络通信,有没有办法知道一个正在运行中的进程到底做了什么呢?

 

答案当然是可以了,linux 命令 strace 就是跟踪进程行为的一大神器,你可以通过它知道正在执行的进程中到底发生了什么,以及程序为什么出现错误等等。

 

本文,我们就来详细介绍一下 strace 的十大用法。

 

 

 

 

如今,linux 几乎都有成熟的包管理机制,strace 的安装也因此变得非常简单:

 

  • ubuntu/Debian 系统

 

 

sudo apt install strace

 

  • RHEL/CentOS 系统

 

 

yum install strace

 

  • Fedora 系统

 

 

dnf install strace

 

 

只要在原本命令的前面,加上 strace 关键字,我们就可以看到原本要执行的这个命令到底做了什么,下面就是一个追踪 df 命令的例子:

 

$ strace df -h

execve("/bin/df", ["df", "-h"], [/* 50 vars */]) = 0

brk(NULL) = 0x136e000

access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)

mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f82f78fd000

access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)

open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3

fstat(3, {st_mode=S_IFREG|0644, st_size=147662, ...}) = 0

mmap(NULL, 147662, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f82f78d8000

close(3) = 0

access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)

open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3

read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\t\2\0\0\0\0\0"..., 832) = 832

fstat(3, {st_mode=S_IFREG|0755, st_size=1868984, ...}) = 0

mmap(NULL, 3971488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f82f7310000

...

 

结果非常容易理解,可以看到,每一行都是一个系统调用,比如:

 

open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3

 

其中:

 

  • open: 系统调用名
  • (“/etc/ld.so.cache”, O_RDONLY|O_CLOEXEC) : 系统调用的参数
  • 3: 系统调用的返回结果

 

 

上述 df -h 的 strace 结果是非常多的,从中比较难以找到我们真正关心的调用,通过 -e trace 参数,通过传入不同的参数值,就可以过滤出想要的结果了。

 

4.1 过滤指定系统调用

 

通过传入系统调用的名称,就可以只查看对应的系统调用了。

 

$ sudo strace -e trace=write df -h

write(1, "Filesystem Size Used Avail"..., 49Filesystem Size Used Avail Use% Mounted on

) = 49

write(1, "udev 3.9G 0 3.9G"..., 43udev 3.9G 0 3.9G 0% /dev

) = 43

write(1, "tmpfs 788M 9.6M 779M"..., 43tmpfs 788M 9.6M 779M 2% /run

) = 43

write(1, "/dev/sda10 324G 252G 56G"..., 40/dev/sda10 324G 252G 56G 82% /

) = 40

write(1, "tmpfs 3.9G 104M 3.8G"..., 47tmpfs 3.9G 104M 3.8G 3% /dev/shm

) = 47

write(1, "tmpfs 5.0M 4.0K 5.0M"..., 48tmpfs 5.0M 4.0K 5.0M 1% /run/lock

) = 48

write(1, "tmpfs 3.9G 0 3.9G"..., 53tmpfs 3.9G 0 3.9G 0% /sys/fs/cgroup

) = 53

write(1, "cgmfs 100K 0 100K"..., 56cgmfs 100K 0 100K 0% /run/cgmanager/fs

) = 56

write(1, "tmpfs 788M 28K 788M"..., 53tmpfs 788M 28K 788M 1% /run/user/1000

) = 53

+++ exited with 0 +++

 

除此以外,你还可以传入:

 

  • \$ sudo strace -e trace=open,close df -h

 

  • sudo strace -e trace=open,close,read,write df -h

 

  • sudo strace -e trace=all df -h

 

 

4.2 针对进行管理的追踪

 

$ sudo strace -q -e trace=process df -h

execve("/bin/df", ["df", "-h"], [/* 17 vars */]) = 0

arch_prctl(ARCH_SET_FS, 0x7fe2222ff700) = 0

Filesystem Size Used Avail Use% Mounted on

udev 3.9G 0 3.9G 0% /dev

tmpfs 788M 9.6M 779M 2% /run

/dev/sda10 324G 252G 56G 82% /

tmpfs 3.9G 104M 3.8G 3% /dev/shm

tmpfs 5.0M 4.0K 5.0M 1% /run/lock

tmpfs 3.9G 0 3.9G 0% /sys/fs/cgroup

cgmfs 100K 0 100K 0% /run/cgmanager/fs

tmpfs 788M 28K 788M 1% /run/user/1000

exit_group(0) = ?

+++ exited with 0 +++

 

4.3 针对文件系统调用的追踪

 

$ sudo strace -q -e trace=file df -h

execve("/bin/df", ["df", "-h"], [/* 17 vars */]) = 0

access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)

access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)

open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3

access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)

open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3

open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3

open("/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = 3

...

 

4.4 针对内存的追踪

 

$ sudo strace -q -e trace=memory df -h

brk(NULL) = 0x77a000

mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe8f4658000

mmap(NULL, 147662, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fe8f4633000

mmap(NULL, 3971488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fe8f406b000

mprotect(0x7fe8f422b000, 2097152, PROT_NONE) = 0

mmap(0x7fe8f442b000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1c0000) = 0x7fe8f442b000

mmap(0x7fe8f4431000, 14752, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fe8f4431000

mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe8f4632000

mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe8f4631000

mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fe8f4630000

mprotect(0x7fe8f442b000, 16384, PROT_READ) = 0

mprotect(0x616000, 4096, PROT_READ) = 0

mprotect(0x7fe8f465a000, 4096, PROT_READ) = 0

munmap(0x7fe8f4633000, 147662) = 0

mmap(NULL, 2981280, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fe8f3d93000

brk(NULL) = 0x77a000

brk(0x79b000) = 0x79b000

mmap(NULL, 619, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fe8f4657000

mmap(NULL, 26258, PROT_READ, MAP_SHARED, 3, 0) = 0x7fe8f4650000

Filesystem Size Used Avail Use% Mounted on

udev 3.9G 0 3.9G 0% /dev

tmpfs 788M 9.6M 779M 2% /run

/dev/sda10 324G 252G 56G 82% /

tmpfs 3.9G 104M 3.8G 3% /dev/shm

tmpfs 5.0M 4.0K 5.0M 1% /run/lock

tmpfs 3.9G 0 3.9G 0% /sys/fs/cgroup

cgmfs 100K 0 100K 0% /run/cgmanager/fs

tmpfs 788M 28K 788M 1% /run/user/1000

+++ exited with 0 +++

 

4.5 针对网络的追踪

 

$ sudo strace -e trace=network df -h

 

4.6 针对信号的追踪

 

$ sudo strace -e trace=signal df -h

 

 

如果一个进程已经在运行,你可以通过它的pid进行追踪,它会显示追踪后这个进程的系统调用。

 

$ sudo strace -p 3569

strace: Process 3569 attached

restart_syscall(<... resuming interrupted poll ...>) = 1

recvmsg(4, {msg_name(0)=NULL, msg_iov(1)=[{"U\2\24\300!\247\330\0\3\24\4\0\20\0\0\0\0\0\0\24\24\24\24\24\0\0\3\37%\2\0\0", 4096}], msg_controllen=0, msg_flags=0}, 0) = 32

recvmsg(4, 0x7ffee4dbf870, 0) = -1 EAGAIN (Resource temporarily unavailable)

recvmsg(4, 0x7ffee4dbf850, 0) = -1 EAGAIN (Resource temporarily unavailable)

poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=10, events=POLLIN}, {fd=30, events=POLLIN}, {fd=31, events=POLLIN}], 6, -1) = 1 ([{fd=31, revents=POLLIN}])

read(31, "\372", 1) = 1

recvmsg(4, 0x7ffee4dbf850, 0) = -1 EAGAIN (Resource temporarily unavailable)

poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=10, events=POLLIN}, {fd=30, events=POLLIN}, {fd=31, events=POLLIN}], 6, 0) = 1 ([{fd=31, revents=POLLIN}])

read(31, "\372", 1) = 1

recvmsg(4, 0x7ffee4dbf850, 0) = -1 EAGAIN (Resource temporarily unavailable)

poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=10, events=POLLIN}, {fd=30, events=POLLIN}, {fd=31, events=POLLIN}], 6, 0) = 0 (Timeout)

mprotect(0x207faa20000, 8192, PROT_READ|PROT_WRITE) = 0

mprotect(0x207faa20000, 8192, PROT_READ|PROT_EXEC) = 0

mprotect(0x207faa21000, 4096, PROT_READ|PROT_WRITE) = 0

mprotect(0x207faa21000, 4096, PROT_READ|PROT_EXEC) = 0

...

 

 

使用-c参数,可以得到追踪的每一种系统调用的耗时、次数和失败数。

 

$ sudo strace -c -p 3569

strace: Process 3569 attached

^Cstrace: Process 3569 detached

% time seconds usecs/call calls errors syscall

---

99.73 0.016000 8 1971 poll

0.16 0.000025 0 509 75 futex

0.06 0.000010 0 1985 1966 recvmsg

0.06 0.000009 0 2336 mprotect

0.00 0.000000 0 478 read

0.00 0.000000 0 13 write

0.00 0.000000 0 29 mmap

0.00 0.000000 0 9 munmap

0.00 0.000000 0 18 writev

0.00 0.000000 0 351 madvise

0.00 0.000000 0 1 restart_syscall

---

100.00 0.016044 7700 2041 total

 

 

-i可以显示每一次系统调用的时候的指令指针

 

$ sudo strace -i df -h

[00007f0d7534c777] execve("/bin/df", ["df", "-h"], [/* 17 vars */]) = 0

[00007faf9cafa4b9] brk(NULL) = 0x12f0000

[00007faf9cafb387] access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)

[00007faf9cafb47a] mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7faf9cd03000

[00007faf9cafb387] access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)

[00007faf9cafb327] open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3

[00007faf9cafb2b4] fstat(3, {st_mode=S_IFREG|0644, st_size=147662, ...}) = 0

[00007faf9cafb47a] mmap(NULL, 147662, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7faf9ccde000

[00007faf9cafb427] close(3) = 0

[00007faf9cafb387] access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)

[00007faf9cafb327] open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3

[00007faf9cafb347] read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\t\2\0\0\0\0\0"..., 832) = 832

[00007faf9cafb2b4] fstat(3, {st_mode=S_IFREG|0755, st_size=1868984, ...}) = 0

[00007faf9cafb47a] mmap(NULL, 3971488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7faf9c716000

[00007faf9cafb517] mprotect(0x7faf9c8d6000, 2097152, PROT_NONE) = 0

...

 

 

-t参数可以显示调用时间。

 

$ sudo strace -t df -h

15:19:25 execve("/bin/df", ["df", "-h"], [/* 17 vars */]) = 0

15:19:25 brk(NULL) = 0x234c000

15:19:25 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)

15:19:25 mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f8c7f1d9000

15:19:25 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)

15:19:25 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3

15:19:25 fstat(3, {st_mode=S_IFREG|0644, st_size=147662, ...}) = 0

15:19:25 mmap(NULL, 147662, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f8c7f1b4000

15:19:25 close(3) = 0

15:19:25 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)

15:19:25 open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3

15:19:25 read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\t\2\0\0\0\0\0"..., 832) = 832

15:19:25 fstat(3, {st_mode=S_IFREG|0755, st_size=1868984, ...}) = 0

15:19:25 mmap(NULL, 3971488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f8c7ebec000

15:19:25 mprotect(0x7f8c7edac000, 2097152, PROT_NONE) = 0

...

 

 

-T参数可以显示系统调用的耗时时间。

 

$ sudo strace -T df -h

execve("/bin/df", ["df", "-h"], [/* 17 vars */]) = 0 <0.000287>

brk(NULL) = 0xeca000 <0.000035>

access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) <0.000028>

mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9aff2b1000 <0.000020>

access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) <0.000019>

open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 <0.000022>

fstat(3, {st_mode=S_IFREG|0644, st_size=147662, ...}) = 0 <0.000015>

mmap(NULL, 147662, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f9aff28c000 <0.000019>

close(3) = 0 <0.000014>

...

 

 

-o参数将标准输出写入到文件

 

$ sudo strace -o df_debug.txt df -h

Filesystem Size Used Avail Use% Mounted on

udev 3.9G 0 3.9G 0% /dev

tmpfs 788M 9.6M 779M 2% /run

/dev/sda10 324G 252G 56G 82% /

tmpfs 3.9G 104M 3.8G 3% /dev/shm

tmpfs 5.0M 4.0K 5.0M 1% /run/lock

tmpfs 3.9G 0 3.9G 0% /sys/fs/cgroup

cgmfs 100K 0 100K 0% /run/cgmanager/fs

tmpfs 788M 28K 788M 1% /run/user/1000

 

 

-d可以显示strace的debug信息。

 

$ strace -d df -h

ptrace_setoptions = 0x11

new tcb for pid 5637, active tcbs:1

[wait(0x80137f) = 5637] ?? (128),PTRACE_EVENT_?? (128)

pid 5637 has TCB_STARTUP, initializing it

setting opts 11 on pid 5637

[wait(0x80057f) = 5637] ?? (128),PTRACE_EVENT_?? (128)

[wait(0x127f) = 5637] WIFSTOPPED,sig=SIGCONT

[wait(0x857f) = 5637] WIFSTOPPED,sig=133

execve("/usr/bin/df", ["df", "-h"], [/* 22 vars */] [wait(0x4057f) = 5637] WIFSTOPPED,sig=SIGTRAP,PTRACE_EVENT_EXEC

[wait(0x857f) = 5637] WIFSTOPPED,sig=133

) = 0

[wait(0x857f) = 5637] WIFSTOPPED,sig=133

...

 

 

https://www.tecmint.com/strace-commands-for-troubleshooting-and-debugging-linux/

 

 

欢迎关注微信公众号,以技术为主,涉及历史、人文等多领域的学习与感悟,每周三到七篇推文,只有全部原创,只有干货没有鸡汤

 

linux 使用及配置相关

 






linux      系统调用      架构      strace      性能优化     


京ICP备2021035038号