使用strace查找故障原因

strace是Linux上最常用的调试工具之一了,通过它可以了解程序进行系统调用的情况从而定位问题。这次在修复一个cpu loading过高的问题上使用了这个工具,所以简单记录一下使用方法。

问题描述

起因是因为samba传输速度太慢,在系统中打开或者关闭某个feature之后传输速度就会恢复正常。查看内存占用和usb传输速度没有异常之后就怀疑到了cpu loading上。使用cpu命令查看当前cpu占用量,发现几乎达到了100%,其中system占了90%以上。那使用strace分析问题原因肯定是再合适不过的了。

使用方法

一般来讲,我们都是对于某个已知的进程去查找问题。

指定pid

strace -p [pid]

使用-p参数可以指定pid,实时打印出目前的系统调用情况。

统计耗时情况

比如本例中,出现的是cpu loading很高的问题,实时打印就很难看清发生了什么。

strace -c -p [PID]

使用-c参数可以很方便的统计出某段时间内系统调用耗时比例的情况。

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 40.00    0.020000        1250        16           wait4
 40.00    0.020000          17      1203       304 ipc
 20.00    0.010000          34       294        10 open
  0.00    0.000000           0        16           fork
  0.00    0.000000           0       421           read
  0.00    0.000000           0         6           write
  0.00    0.000000           0       294         2 close
  0.00    0.000000           0       184           getpid
  0.00    0.000000           0         2           access
  0.00    0.000000           0         3           pipe
  0.00    0.000000           0       239       222 ioctl
  0.00    0.000000           0         5           fcntl
  0.00    0.000000           0       368           stat
  0.00    0.000000           0       113           flock
  0.00    0.000000           0         4           nanosleep
  0.00    0.000000           0         3           socket
  0.00    0.000000           0       108           rt_sigaction
  0.00    0.000000           0         1           stat64
  0.00    0.000000           0         1           restart_syscall
------ ----------- ----------- --------- --------- ----------------
100.00    0.050000                  3281       538 total

查看指定的系统调用

strace -e expr

通过-e参数来跟踪某个指定的系统调用,这样去掉其他的系统调用之后可以让我们打印的信息更加清晰。

查看系统调用时长

strace -T

有时候我们需要知道每个系统调用到底执行了多长时间来判断是哪个调用拖慢了程序,这时候使用—T参数可以很方便的将调用时长显示在结尾。下面的输出中行尾的<>中的内容就代表了执行的时间。

read(4, "", 4096)                       = 0 <0.000000>
read(3, "276\n", 4096)                  = 4 <0.000000>
read(3, "", 4096)                       = 0 <0.000000>
read(4, "276\n", 4096)                  = 4 <0.000000>
read(4, "", 4096)                       = 0 <0.000000>
read(3, "276\n", 4096)                  = 4 <0.000000>
read(3, "", 4096)                       = 0 <0.000000>
read(4, "276\n", 4096)                  = 4 <0.000000>
read(4, "", 4096)                       = 0 <0.000000>
read(3, "276\n", 4096)                  = 4 <0.000000>
read(3, "", 4096)                       = 0 <0.000000>
read(4, "276\n", 4096)                  = 4 <0.000000>
read(4, "", 4096)                       = 0 <0.010000>

总结时间

strace用起来确实很方便啊!不过这次使用到的也只是最基本的内容,最后定位到问题是在某个accept的死循环上,具体原因在这里就不多说了。此外除了查看系统调用strace,用户态的库函数调用还可以用ltrace来查看,以后有机会也去试一试。

点赞

发表评论

电子邮件地址不会被公开。 必填项已用*标注