linux命令——strace命令（跟踪进程中的系统调⽤）
strace常⽤来跟踪进程执⾏时的系统调⽤和所接收的信号。在Linux世界，进程不能直接访问硬件设备，当进程需要访问硬件设备(⽐如读取磁盘⽂件，接收⽹络数据等等)时，必须由⽤户态模式切换⾄内核态模式，通过系统调⽤访问硬件设备。strace可以跟踪到⼀个进程产⽣的系统调⽤，包括参数，返回值，执⾏消耗的时间。
1、参数
每⼀⾏都是⼀条系统调⽤，等号左边是系统调⽤的函数名及其参数，右边是该调⽤的返回值。 strace 显⽰这些调⽤的参数并返回符号形式的值。strace 从内核接收信息，⽽且不需要以任何特殊的⽅式来构建内核。
$strace cat /dev/null
execve("/bin/cat", ["cat", "/dev/null"], [/* 22 vars */]) = 0
brk(0)                                  = 0xab1000
access("/etc/hwcap", F_OK)      = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f29379a7000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
...
参数含义
-c 统计每⼀系统调⽤的所执⾏的时间，次数和出错的次数等.
-d 输出strace关于标准错误的调试信息.
-f 跟踪由fork调⽤所产⽣的⼦进程.
-ff 如果提供-o filename，则所有进程的跟踪结果输出到相应的filename.pid中,pid是各进程的进程号.
-F 尝试跟踪vfork调⽤.在-f时,vfork不被跟踪.
-h 输出简要的帮助信息.
-i 输出系统调⽤的⼊⼝指针.
-q 禁⽌输出关于脱离的消息.
-r 打印出相对时间关于,，每⼀个系统调⽤.
-t 在输出中的每⼀⾏前加上时间信息.
-tt 在输出中的每⼀⾏前加上时间信息，微秒级.
-ttt 微秒级输出，以秒了表⽰时间.
-T 显⽰每⼀调⽤所耗的时间.
-v 输出所有的系统调⽤.⼀些调⽤关于环境变量，状态，输⼊输出等调⽤由于使⽤频繁，默认不输出.
-V 输出strace的版本信息.
-x 以⼗六进制形式输出⾮标准字符串
-xx 所有字符串以⼗六进制形式输出.
-a column
设置返回值的输出位置.默认为40.
-e expr
指定⼀个表达式,⽤来控制如何跟踪.格式如下:
[qualifier=][!]value1[,value2]...
qualifier只能是 trace,abbrev,verbose,raw,signal,read,write其中之⼀.value是⽤来限定的符号或数字.默认的 qualifier是 trace.感叹号是否定符号.例如:
-eopen等价于 -e trace=open，表⽰只跟踪open调⽤.⽽-etrace!=open表⽰跟踪除了open以外的其他调⽤.有两个特殊的符号 all 和 none.
注意有些shell使⽤!来执⾏历史记录⾥的命令，所以要使⽤\\.
-e trace=set
只跟踪指定的系统调⽤.例如:-e trace=open,close,rean,write表⽰只跟踪这四个系统调⽤.默认的为set=all.
-
e trace=file
只跟踪有关⽂件操作的系统调⽤.
-e trace=process
只跟踪有关进程控制的系统调⽤.
-e trace=network
跟踪与⽹络有关的所有系统调⽤.
-e strace=signal
跟踪所有与系统信号有关的系统调⽤
-e trace=ipc
跟踪所有与进程通讯有关的系统调⽤
-e abbrev=set
设定 strace输出的系统调⽤的结果集.-v 等与 abbrev=none.默认为abbrev=all.
-e raw=set
将指定的系统调⽤的参数以⼗六进制显⽰.
-e signal=set
指定跟踪的系统信号.默认为all.如 signal=!SIGIO(或者signal=!io)，表⽰不跟踪SIGIO信号.
-e read=set
输出从指定⽂件中读出的数据.例如:
-e read=3,5
-e write=set
输出写⼊到指定⽂件中的数据.
-o filename
将strace的输出写⼊⽂件filename
-p pid
跟踪指定的进程pid.
-s strsize
指定输出的字符串的最⼤长度.默认为32.⽂件名⼀直全部输出.
-u username
以username 的UID和GID执⾏被跟踪的命令
2、使⽤实例
实例1：跟踪可执⾏程序
strace -f -F -o ~/ myserver
-f -F选项告诉strace同时跟踪fork和vfork出来的进程，-o选项把所有strace输出写到~/⾥⾯，myserver是要启动和调试的程序。
实例2：跟踪服务程序
strace - -T -tt -e trace=all -p 28979
跟踪28979进程的所有系统调⽤（-e trace=all），并统计系统调⽤的花费时间，以及开始时间（并以可视化的时分秒格式显⽰），最后将记录结果存在⽂件⾥⾯。
实例3：转⾃
早些年，如果你知道有个 strace 命令，就很⽜了，⽽现在⼤家基本都知道 strace 了，如果你遇到性能问题求助别⼈，⼗有⼋九会建议你⽤strace 挂上去看看，不过当你挂上去了，看着满屏翻滚的字符，却⼗有⼋九看不出个所以然。本⽂通过⼀个简单的案例，向你展⽰⼀下在⽤strace 诊断问题时的⼀些套路。
如下真实案例，如有雷同，实属必然！让我们看⼀台⾼负载服务器的 top 结果：
top
技巧：运⾏ top 时，按「1」打开 CPU 列表，按「shift+p」以 CPU 排序。
在本例中⼤家很容易发现 CPU 主要是被若⼲个 PHP 进程占⽤了，同时 PHP 进程占⽤的⽐较多的内存，不过系统内存尚有结余，SWAP 也不严重，这并不是问题主因。
不过在 CPU 列表中能看到 CPU 主要消耗在内核态「sy」，⽽不是⽤户态「us」，和我们的经验不符。Linux 操作系统有很多⽤来跟踪程序⾏为的⼯具，内核态的函数调⽤跟踪⽤「strace」，⽤户态的函数调⽤跟踪⽤「ltrace」，所以这⾥我们应该⽤「strace」：
shell> strace -p <PID>
不过如果直接⽤ strace 跟踪某个进程的话，那么等待你的往往是满屏翻滚的字符，想从这⾥看出问题的症结并不是⼀件容易的事情，好在strace  可以按操作汇总时间：
shell> strace -cp <PID>
通过「c」选项⽤来汇总各个操作的总耗时，运⾏后的结果⼤概如下图所⽰：
strace -cp
很明显，我们能看到 CPU 主要被 clone 操作消耗了，还可以单独跟踪⼀下 clone：
shell> strace -T -e clone -p <PID>
通过「T」选项可以获取操作实际消耗的时间，通过「e」选项可以跟踪某个操作：
strace -T -e clone -p
很明显，⼀个 clone 操作需要⼏百毫秒，⾄于 clone 的含义，参考 man ⽂档：
clone() creates a new process, in a manner similar to fork(2). It is actually a library function layered on top of the underlying
clone() system call, hereinafter referred to as sys_clone. A description of sys_clone is given towards the end of this page.
Unlike fork(2), these calls allow the child process to share parts of its execution context with the calling process, such as the
memory space, the table of file descriptors, and the table of signal handlers. (Note that on this manual page, “calling process”
normally corresponds to “parent process”. But see the description of CLONE_PARENT below.)
简单来说，就是创建⼀个新进程。那么在 PHP ⾥什么时候会出现此类系统调⽤呢？查询业务代码看到了函数，通过如下命令验证它确实会导致 clone 系统调⽤：
shell> strace -eclone php -r 'exec("ls");'
最后再考⼤家⼀个题：如果我们⽤ strace 跟踪⼀个进程，输出结果很少，是不是说明进程很空闲？其实试试 ltrace，可能会发现别有洞天。
记住有内核态和⽤户态之分。
实例4 ：转⾃
服务器却频现⾼负载，Nginx出现错误⽇志：
connect() failed (110: Connection timed out) while connecting to upstream
connect() failed (111: Connection refused) while connecting to upstream
看上去是Upstream出了问题，在本例中Upstream就是PHP（版本：5.2.5）。可惜监控不完善，我搞不清楚到底是哪出了问题，⽆奈之下只好不断重启PHP来缓解故障。
如果每次都⼿动重启服务⽆疑是个苦差事，幸运的是可以通过CRON设置每分钟执⾏：
#/bin/bash
LOAD=$(awk '{print $1}' /proc/loadavg)
if [ $(echo "$LOAD > 100" | bc) = 1 ]; then
/etc/init.d/php-fpm restart
fi
可惜这只是⼀个权宜之计，要想彻底解决就必须出故障的真正原因是什么。
闲⾔碎语不要讲，轮到Strace出场了，统计⼀下各个系统调⽤的耗时情况：
shell> strace -c -p $(pgrep -n php-cgi)
% time    seconds  usecs/call    calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
30.53    0.023554        132      179          brk
14.71    0.011350        140        81          mlock
12.70    0.009798          15      658        16 recvfrom
8.96    0.006910          7      927          read
6.61    0.005097          43      119          accept
5.57    0.004294          4      977          poll
3.13    0.002415          7      359          write
2.82    0.002177          7      311          sendto
2.64    0.002033          2      1201        1 stat
2.27    0.001750          1      2312          gettimeofday
2.11    0.001626          1      1428          rt_sigaction
1.55    0.001199          2      730          fstat
1.29    0.000998          10      100      100 connect
1.03    0.000792          4      178          shutdown
1.00    0.000773          2      492          open
0.93    0.000720          1      711          close
0.49    0.000381          2      238          chdir
0.35    0.000271          3        87          select
linux用户系统相关命令
0.29    0.000224          1      357          setitimer
0.21    0.000159          2        81          munlock
0.17    0.000133          2        88          getsockopt
0.14    0.000110          1      149          lseek
0.14    0.000106          1      121          mmap
0.11    0.000086          1      121          munmap
0.09    0.000072          0      238          rt_sigprocmask
0.08    0.000063          4        17          lstat
0.07    0.000054          0      313          uname
0.00    0.000000          0        15        1 access
0.00    0.000000          0      100          socket
0.00    0.000000          0      101          setsockopt
0.00    0.000000          0      277          fcntl
------ ----------- ----------- --------- --------- ----------------
100.00    0.077145                13066      118 total
看上去「brk」⾮常可疑，它竟然耗费了三成的时间，保险起见，单独确认⼀下：
shell> strace -T -e brk -p $(pgrep -n php-cgi)
brk(0x1f18000) = 0x1f18000 <0.024025>
brk(0x1f58000) = 0x1f58000 <0.015503>
brk(0x1f98000) = 0x1f98000 <0.013037>
brk(0x1fd8000) = 0x1fd8000 <0.000056>
brk(0x2018000) = 0x2018000 <0.012635>
说明：在Strace中和操作花费时间相关的选项有两个，分别是「-r」和「-T」，它们的差别是「-r」表⽰相对时间，⽽「-T」表⽰绝对时间。简单统计可以⽤「-r」，但是需要注意的是在多任务背景下，CPU随时可能会被切换出去做别的事情，所以相对时间不⼀定准确，此时最好使⽤「-T」，在⾏尾可以看到操作时间，可以发现确实很慢。
在继续定位故障原因前，我们先通过「man brk」来查询⼀下它的含义：
brk() sets the end of the data segment to the value specified by end_data_segment, when that value is reasonable, the system does have enough memory and the process does not exceed its max data size (see setrlimit(2)).
简单点说就是内存不够⽤时通过它来申请新内存（），可是为什么呢？
shell> strace -T -p $(pgrep -n php-cgi) 2>&1 | grep -B 10 brk
stat("/path/to/script.php", {...}) = 0 <0.000064>
brk(0x1d9a000) = 0x1d9a000 <0.000067>
brk(0x1dda000) = 0x1dda000 <0.001134>
brk(0x1e1a000) = 0x1e1a000 <0.000065>
brk(0x1e5a000) = 0x1e5a000 <0.012396>
brk(0x1e9a000) = 0x1e9a000 <0.000092>
通过「grep」我们很⽅便就能获取相关的上下⽂，反复运⾏⼏次，发现每当请求某些PHP脚本时，就
会出现若⼲条耗时的「brk」，⽽且这些PHP脚本有⼀个共同的特点，就是⾮常⼤，甚⾄有⼏百K，为何会出现这么⼤的PHP脚本？实际上是程序员为了避免数据库操作，把⾮常庞⼤的数组变量通过「」持久化到PHP⽂件中，然后在程序中通过「」来获取相应的变量，因为变量太⼤，所以PHP不得不频繁执⾏「brk」，不幸的是在本例的环境中，此操作⽐较慢，从⽽导致处理请求的时间过长，加之PHP进程数有限，于是乎在Nginx上造成请求拥堵，最终导致⾼负载故障。
下⾯需要验证⼀下推断似乎否正确，⾸先查询⼀下有哪些地⽅涉及问题脚本：
shell> find /path -name "*.php" | xargs grep "script.php"
直接把它们都禁⽤了，看看服务器是否能缓过来，或许⼤家觉得这太鲁蒙了，但是特殊情况必须做出特殊的决定，不能像个娘们⼉似的优柔寡断，没过多久，服务器负载恢复正常，接着再统计⼀下系统调⽤的耗时：
shell> strace -c -p $(pgrep -n php-cgi)
% time    seconds  usecs/call    calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
24.50    0.001521          11      138        2 recvfrom
16.11    0.001000          33        30          accept
7.86    0.000488          8        59          sendto
7.35    0.000456          1      360          rt_sigaction
6.73    0.000418          2      198          poll
5.72    0.000355          1      285          stat
4.54    0.000282          0      573          gettimeofday
4.41    0.000274          7        42          shutdown
4.40    0.000273          2      137          open
3.72    0.000231          1      197          fstat
2.93    0.000182          1      187          close
2.56    0.000159          2        90          setitimer
2.13    0.000132          1      244          read
1.71    0.000106          4        30          munmap
1.16    0.000072          1        60          chdir
1.13    0.000070          4        18          setsockopt
1.05    0.000065          1      100          write
1.05    0.000065          1        64          lseek
0.95    0.000059          1        75          uname
0.00    0.000000          0        30          mmap
0.00    0.000000          0        60          rt_sigprocmask
0.00    0.000000          0        3        2 access
0.00    0.000000          0        9          select
0.00    0.000000          0        20          socket
0.00    0.000000          0        20        20 connect
0.00    0.000000          0        18          getsockopt
0.00    0.000000          0        54          fcntl
0.00    0.000000          0        9          mlock
0.00    0.000000          0        9          munlock
------ ----------- ----------- --------- --------- ----------------
100.00    0.006208                  3119        24 total
显⽽易见，「brk」已经不见了，取⽽代之的是「recvfrom」和「accept」，不过这些操作本来就是很耗时的，所以可以定位「brk」就是故障的原因。

版权声明：本站内容均来自互联网，仅供演示用，请勿用于商业和其他非法用途。如果侵犯了您的权益请与我们联系QQ:729038198，我们将在24小时内删除。