工欲善其事必先利其器，多学一点小技能，将来总能用得上。
在Unix Like系统上,有非常的多的troubleshoot工具能够让你洞察系统环境和运行过程，本文主要是简述其中的非常的strace命令。strace是一款非常强大的debug工具，他能捕捉一个进程的系统调用和进程收到的信号,带有一点hack的味道。我们列一个常用的例子：
- 观察程序是否假死
- 程序耗时操作都是在做什么
- 进程使用了那个配置文件
- 查看一个正在运行的程序的标准输出
- 程序依赖那些动态链接库
以上这些问题，都能通过strace轻松搞定。
如果你还没有安装strace，那么使用如下方式能够安装它:
$ sudo apt install strace #Debian/Ubuntu
# yum install strace #RHEL/CentOS
# dnf install strace #Fedora 22+如果你发现某个进程没有响应，或者工作不正常但是又找不到日志，你可以通过strace命令来看这个进程的工作状态，打开了那些文件，打开了哪些端口，正在进行什么操作。
strace -p追踪命令行启动过程
如果你程序还没有启动，那么你之一在strace后面接上启动的命令行即可,因为设计到系统安全，所以strace需要使用sudo权限。
$ 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, "7ELF
...从上面的例子可以看到有很多的系统调用，比如:
open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3- open 是对应的系统调用
- (“/lib/x86_64-linux-gnu/libc.so.6”, O_RDONLY|O_CLOEXEC) 是对应系统调用的参数
- 3 是这个系统调用的返回值
追踪一个已经存在的进程
如果一个进程已经启动，那么你可以通过给strace传递对应的PID来追踪这个进程的系统调用过程,使用CTRL + C 停止追踪。
[root@iZ2zefvnzjphkalt990sg0Z ~]# strace -p 13449
Process 13449 attached
restart_syscall(<... resuming interrupted call ...>) = 0
nanosleep({0, 100000000}, NULL) = 0
nanosleep({0, 100000000}, NULL) = 0
lstat("/var/log/auth.log", 0x7ffef15cebe0) = -1 ENOENT (No such file or directory)
lstat("/var/log/secure", {st_mode=S_IFREG|0600, st_size=9126, ...}) = 0
lstat("/var/log/secure", {st_mode=S_IFREG|0600, st_size=9126, ...}) = 0
open("/var/log/secure", O_RDONLY) = 24
fcntl(24, F_GETFD) = 0
fcntl(24, F_SETFD, FD_CLOEXEC) = 0
fstat(24, {st_mode=S_IFREG|0600, st_size=9126, ...}) = 0
close(24) = 0
nanosleep({0, 100000000}, NULL) = 0
nanosleep({0, 100000000}, NULL) = 0
nanosleep({0, 100000000}, NULL) = 0
nanosleep({0, 100000000}, NULL) = 0
nanosleep({0, 100000000}, NULL) = 0
nanosleep({0, 100000000}, NULL) = 0
lstat("/var/log/auth.log", 0x7ffef15cebe0) = -1 ENOENT (No such file or directory)
lstat("/var/log/secure", {st_mode=S_IFREG|0600, st_size=9126, ...}) = 0
...统计系统调用次数
有的时候你发现启动某个进程以后，系统io会很卡顿，那么你可以通过strace -c来统计相关的系统调用的次数,CTRL + C 停止统计。
[root@iZ2zefvnzjphkalt990sg0Z ~]# strace -p 13449 -c
Process 13449 attached
^CProcess 13449 detached
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
98.28 0.004123 79 52 nanosleep
0.72 0.000030 1 27 9 lstat
0.67 0.000028 2 15 close
0.31 0.000013 1 15 open
0.02 0.000001 0 18 fcntl
0.00 0.000000 0 6 read
0.00 0.000000 0 2 stat
0.00 0.000000 0 15 fstat
0.00 0.000000 0 6 mmap
0.00 0.000000 0 6 munmap
0.00 0.000000 0 1 restart_syscall
------ ----------- ----------- --------- --------- ----------------
100.00 0.004195 163 9 total这里看到，这里调用了sleep 79次，调用了 open 15 次。
查看系统调用时间
你可能想查看某一条系统调用的发生时间，使用-t选项,注意: -t和-c一起使用的时候-t选项会失效,-t时间精确到秒,-tt则精确到微妙。
[root@iZ2zefvnzjphkalt990sg0Z ~]# strace -p 13449 -t
Process 13449 attached
11:58:24 restart_syscall(<... resuming interrupted call ...>) = 0
11:58:24 lstat("/var/log/auth.log", 0x7ffef15cebe0) = -1 ENOENT (No such file or directory)
11:58:24 lstat("/var/log/secure", {st_mode=S_IFREG|0600, st_size=9126, ...}) = 0
11:58:24 lstat("/var/log/secure", {st_mode=S_IFREG|0600, st_size=9126, ...}) = 0
11:58:24 open("/var/log/secure", O_RDONLY) = 24
11:58:24 fcntl(24, F_GETFD) = 0
11:58:24 fcntl(24, F_SETFD, FD_CLOEXEC) = 0
11:58:24 fstat(24, {st_mode=S_IFREG|0600, st_size=9126, ...}) = 0
11:58:24 close(24) = 0
11:58:24 nanosleep({0, 100000000}, NULL) = 0
11:58:24 nanosleep({0, 100000000}, NULL) = 0
11:58:24 nanosleep({0, 100000000}, NULL) = 0
11:58:24 nanosleep({0, 100000000}, NULL) = 0
11:58:24 nanosleep({0, 100000000}, NULL) = 0
11:58:24 nanosleep({0, 100000000}, NULL) = 0
...查看每一条系统调用的耗时
你是要排查性能相关的问题，你可能需要看每一条系统调用的耗时时间,使用-T,时间单位是秒。
[root@iZ2zefvnzjphkalt990sg0Z ~]# strace -p 13449 -T
Process 13449 attached
restart_syscall(<... resuming interrupted call ...>) = 0 <0.060968>
nanosleep({0, 100000000}, NULL) = 0 <0.100156>
nanosleep({0, 100000000}, NULL) = 0 <0.100127>
lstat("/var/log/auth.log", 0x7ffef15cebe0) = -1 ENOENT (No such file or directory) <0.000031>
lstat("/var/log/secure", {st_mode=S_IFREG|0600, st_size=9126, ...}) = 0 <0.000034>
lstat("/var/log/secure", {st_mode=S_IFREG|0600, st_size=9126, ...}) = 0 <0.000020>
open("/var/log/secure", O_RDONLY) = 24 <0.000026>
fcntl(24, F_GETFD) = 0 <0.000019>
fcntl(24, F_SETFD, FD_CLOEXEC) = 0 <0.000016>
fstat(24, {st_mode=S_IFREG|0600, st_size=9126, ...}) = 0 <0.000016>
close(24) = 0 <0.000018>如上，每一行输出的最后尖括号中的数据表示执行耗时，单位是秒。
也可以使用-r选项来查看每一条系统调用之间的时间间隔
查看指定的系统调用
使用-e指定需要查看的系统调用，其他系统调用不会显示。
strace -p 12323 -w=write,read这里降看到read和write这两个系统调用的使用情况，其他还有sigal,network等等。
将监控过程输出到文件
使用-o选项能将监控过程中的输入写入到文件。
strace -p 23423 -o output.txt查看执行时间顺序与间隔时间
使用-r选项能够按照执行的时间输出，时间单位是秒。
[infra@test01 ~]$ strace -r ls
0.000000 execve("/usr/bin/ls", ["ls"], [/* 22 vars */]) = 0
0.000321 brk(NULL) = 0x14f2000
0.000097 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2ab603259000
0.000081 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
0.000085 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
0.000040 fstat(3, {st_mode=S_IFREG|0644, st_size=44685, ...}) = 0
0.000036 mmap(NULL, 44685, PROT_READ, MAP_PRIVATE, 3, 0) = 0x2ab60325a000
0.000023 close(3) = 0
0.000027 open("/lib64/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
0.000026 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320i\0\0\0\0\0\0"..., 832) = 832
0.000040 fstat(3, {st_mode=S_IFREG|0755, st_size=155784, ...}) = 0
0.000025 mmap(NULL, 2255184, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x2ab60345b000
0.000023 mprotect(0x2ab60347f000, 2093056, PROT_NONE) = 0
0.000026 mmap(0x2ab60367e000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x23000) = 0x2ab60367e000
0.000052 mmap(0x2ab603680000, 6480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x2ab603680000
0.000054 close(3) = 0
0.000040 open("/lib64/libcap.so.2", O_RDONLY|O_CLOEXEC) = 3
0.000044 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 \26\0\0\0\0\0\0"..., 832) = 832
0.000028 fstat(3, {st_mode=S_IFREG|0755, st_size=20032, ...}) = 0
0.000022 mmap(NULL, 2114112, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x2ab603682000
0.000024 mprotect(0x2ab603686000, 2093056, PROT_NONE) = 0
0.000023 mmap(0x2ab603885000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) = 0x2ab603885000
....第一行显示的是秒级别的时间顺序。
