在Linux中如果发现服务器的CPU消耗过大的时候,我们可以通过strace这个Linux的基础设施来检查服务器系统调用是否过多消耗服务器的资源。这个是排除掉了自己逻辑相关的一个视角来观看服务器的性能消耗(意味着,如果逻辑上写了一些非常消耗的点其实是没有太多办法检查出来的)。使用的方法也非常简单下面我们就开始了。
最简单的用法strace将会对于运行中的command做trace,直到退出。它将会拦截、记录被监控的process系统调用和所有被监控的process接受到的信号。全部的系统调用的名字,参数和返回值被输出到标准的错误输出中或者通过-o这个option重定向到文件中。
strace是一个很有用的诊断、指导、调试工具。系统管理员,诊断专家和解决问题者将发现它的巨大价值,在解决一些问题的时候,不如说,某些程序没有现成的源码,他们不需要去重新编译代码来跟踪程序。学生,黑客和狂热分子会发现通过它能学习到大量的通过他们自己的程序甚至是普通程序发起的系统调用。程序员将会发现系统调用、信号通知发生在用户级或者系统级的接口,仔细检查这个两个级别接口的边界有利于来做bug隔离,清晰的检查、试图抓出竞争紊乱。
系统调用打印
在trace对于系统调用的描述中,第一个是系统调用名称,圆括号里面说明他的调用参数,最后将打印调用的返回值。举个例子当我们strace了一个command cat /dev/null他的反馈是如下:
[abel@iZ23jhimygwZ ~]$ strace cat /dev/null
execve("/usr/bin/cat", ["cat", "/dev/null"], [/* 22 vars */]) = 0
brk(0) = 0x1d17000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f026253f000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
...
当发生调用失败的时候一般都会将错误号和错误的字符串输出出来
open("/foo/bar", O_RDONLY) = -1 ENOENT (No such file or directory)
选项说明
-c
在程序退出的时候输出计数调用次数,和每个系统调用的错误的报告。
-C
类似-c,但是是在进程运行中定期打印输出。
-d
将tracer变成一个grandchild,而不是以parent方式运行。
-f
跟踪被进程通过fork,vfork,clone系统调用产生子进程。注意-p PID -f 将会挂载PID进程下的全部线程。
-ff
如果-o filename选项生效,每个process的trace将被写入filename.pid这个pid就是处理进程的id好。这个option和-c有冲突。
-F
现在已经废弃,他的用途类似于-f
-h
打印帮助信息。
-i
在系统调用时,打印指令指针(instruction pointer,在gdb调试时候说的ip,其实就是程序的代码段在内存中的位置)。
-q
禁止挂载,卸载等消息。
禁止进程退出状态消息。
-r
打印相对时间戳进入每次系统调用。
-t
在每行的前面缀上日期时间戳。
-tt
时间戳将会带上微秒(microsecond)
-ttt
带上微秒,前面是直接使用unix时间戳秒数。
-T
显示系统调用消耗时间。
-v
类似-h
-x
将non-ASCII打印成16进制
-xx
将全部的string都输出成16进制
-y
打印路径管理的文件描述字参数。
-a column
设置列间距,默认为40
-b syscall
如果某个系统调用被触发,将会卸载掉traced进程。
-e expr
正则表达式,用于去决定将对那些事件去trace。
-e trace=set
-e trace=file
-e trace=process
-e trace=network
-e trace=signal
-e trace=ipc
-e trace=desc
-e trace=memory
-e abbrev=set
-e verbose=set
-p pid
指定attach进程编号
-P path
监控某个目录,支持对多个目录做监控。
-s strsize
设置最大string打印长度(默认32)
实战
如果当发现服务器的cpu比较高的时候,我们可以通过这个来检查服务器的系统调用情况。
abel@centos7$ strace -c -tt -o ./td_server.log -p 26844
output report:
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
99.96 0.014022 9 1611 nanosleep
0.04 0.000006 6 1 restart_syscall
0.00 0.000000 0 3 sendto
------ ----------- ----------- --------- --------- ----------------
100.00 0.014028 1615 total