欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识!
您现在的位置是: 首页

实操strace

程序员文章站 2024-03-22 10:54:46
...

1.strace简介

  • Strace是Linux中一个调试和跟踪工具。
    (1)可以通过strace找到问题出现在user层还是kernel层
    (2)进程不能直接访问硬件设备,当进程需要访问硬件设备(比如读取磁盘文件,接收网络数据等等)时,必须由用户态模式切换至内核态模式,通 过系统调用访问硬件设备

  • man strace

2.strace的2种用法

  • strace常用组合
strace -p <PID>

strace -cp <PID>		「c」选项用来汇总各个操作的总耗时
eg:clone的time很大,则可以单独跟踪以下clone

strace -T -e clone -p <PID>
通过「T」选项可以获取操作实际消耗的时间,通过「e」选项可以跟踪某个操作
  • (1)一种是通过它启动要跟踪的进程 ,在原本的命令前加上strace即可
strace ls -lh /var/log/messages
strace ./可执行程序
  • (2)另外一种运行模式,给strace传递-p pid 选项
strace -p 17553
  • strace的常用选项
-c 统计每一系统调用的所执行的时间,次数和出错的次数等. 
-d 输出strace关于标准错误的调试信息. 
-f 除了跟踪当前进程外,还跟踪由fork调用所产生的子进程. 
-ff 如果提供-o filename,则所有进程的跟踪结果输出到相应的filename.pid中,pid是各进程的进程号. 
-F 尝试跟踪vfork调用.-f时,vfork不被跟踪. 
-h 输出简要的帮助信息. 
-i 输出系统调用的入口指针寄存器值. 
-q 禁止输出关于结合(attaching)、脱离(detaching)的消息,当输出重定向到一个文件时,自动抑制此类消息. 
-r 打印出相对时间关于每一个系统调用,即连续的系统调用起点之间的时间差,与-t对应. 
-t 打印各个系统调用被调用时的绝对时间秒级,观察程序各部分的执行时间可以用此选项。 
-tt 在输出中的每一行前加上时间信息,微秒级. 
-ttt 在每行输出前添加相对时间信息,格式为”自纪元时间起经历的秒数.微秒数”
-T 显示每一调用所耗的时间,其时间开销在输出行最右侧的尖括号内. 
-v 冗余显示模式:显示系统调用中argv[]envp[]stat、termio(s)等数组/结构体参数所有的元素/成员内容. 
-V 输出strace的版本信息. 
-x 以十六进制形式输出非标准字符串 。
-xx 所有字符串以十六进制形式输出. 
-a column 设置返回值的输出位置.默认为40,即"="出现在第40.
-e expr 指定一个表达式,用来控制如何跟踪.
    -e trace=set 只跟踪指定的系统 调用.例如:-e trace=open.
    -e trace=file 只跟踪有关文件操作的系统调用. 
    -e trace=process 只跟踪有关进程控制的系统调用. 
    -e trace=network 跟踪与网络有关的所有系统调用. 
    -e trace=signal 跟踪所有与系统信号有关的 系统调用 
    -e trace=ipc 跟踪所有与进程通讯有关的系统调用 
    -e abbrev=set 设定 strace输出的系统调用的结果集.-v 等与 abbrev=none.默认为abbrev=all. 
    -e raw=set 将指 定的系统调用的参数以十六进制显示. 
    -e signal=set 指定跟踪的系统信号.默认为all.如signal=!SIGIO,表示不跟踪SIGIO信号. 
    -e read=set 输出从指定文件中读出 的数据.例如: -e read=3,5 -e write=set 
-E var 从命令的环境变量列表中移除var。
-E var=val 将var=val放入命令的环境变量列表.
-o filename 将strace的输出写入文件filename,而不是显示到标准错误输出(stderr.
-p pid 跟踪指定的进程pid,可指定多达32(-p pid)选项以同时跟踪多个进程。该选项常用于调试后台进程. 
-s strsize 限制每行输出中字符串(如read参数)的最大显示长度,默认32字节。但文件名总是完整显示
-S sortby 按指定规则对-c选项的输出直方图进行排序。sortby取值可为time、calls、name和nothing(默认     time)
-u username 以username 的UID和GID执行被跟踪的命令
  • eg:
strace -o output.txt -T -tt -e trace=all -p 28979
表示的含义是,跟踪28979进程的所有系统调用(-e trace=all),并统计系统调用的花费时间,以及开始时间(并以可视化的时分秒格式显示),
最后将记录结果存在output.txt文件里面。

strace -f -e trace=read,write -p 17151 -o log
跟踪进程17151及子进程中read和write系统调用,输出到log文件

注意:
-e trace=open,close,rean,write表示只跟踪这四个系统调用.默认的为set=all

  • strace记录程序所产生的每次系统调用的格式为:
    (1)单独为一行
    (2)每行起始为系统调用的函数名,括号内为参数,该调用的返回值则显示在等号右侧。
当参数为bit时,使用方括号并用空格隔开每项参数
sigprocmask(SIG_BLOCK,[CHLD TTOU],[ ]) = 0					​ 第二个参数代表信号SIGCHLD和SIGTTOU		

若bit型参数全部置位,则输出如:
sigprocmask(SIG_UNBLOCK,~[ ],NULL) = 0

3.strace使用案例

  • strace用法举例,测试程序test1.c运行过程中的系统调用情况:
#include <stdio.h>
int main(void)
{
	fputs("hello", stdout);
	sleep(2);
	//这里一开始输出了换行符,所以前面的hello就被输出到屏幕上了。
	fputs("\nworld\n", stdout);
	sleep(2);
	return 0;
}
@Cpl-WH-30:~/test$ gcc test1.c -o test1
@Cpl-WH-30:~/test$ strace ./test1
execve("./test1", ["./test1"], [/* 30 vars */]) = 0
brk(0)                                  = 0x12b7000
...
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=143984, ...}) = 0
mmap(NULL, 143984, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7feee4d32000
close(3)                                = 0
...
fstat(1, {st_mode=S_IFCHR|0622, st_rdev=makedev(136, 14), ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7feee4d55000
...
nanosleep({2, 0}, 0x7ffd00227380)       = 0
write(1, "hello\n", 6hello
)                  = 6
...
nanosleep({2, 0}, 0x7ffd00227380)       = 0
write(1, "world", 5world)                    = 5
exit_group(0)                           = ?
+++ exited with 0 +++
  • 分析如下:
    (1)第3行表示通过系统调用execve来建立一个进程,本例中为test1对应的进程,在控制台中执行各种命令,比如ls、cd时,都是通过系统调用execve来建立它们的进程的,通过strace可以看到程序运行的细节。
    (2)第4行brk通过传递的addr来重新设置program break,成功则返回0,否则返回-1。
    brk(0)的参数是一个地址,假如已经知道了堆的起始地址,还有堆的大小,那么就可以据此修改 brk() 中的地址参数已达到调整堆的目的。
    以0作为参数调用brk,返回值为内存管理的起始地址(若在子进程中调用malloc,则从0x12b7000地址开始分配空间)
    (3)​ 第6~8行表示打开动态连接库的过程,如果程序是静态连接的,这几个步骤将不需要。
    (4)第14~19行是程序的处理过程,nanosleep()使得进程进入睡眠状态,指定时候后唤醒进程,sleep()基于其实现 ,然后写入hello和world
    (5)20~21行表示退出进程中所有的线程。

  • ​ test2.c代码使用死循环模拟用户态挂死,调用sleep模拟内核态程序挂死,然后利用strace工具分析原因。

#include <stdio.h>
#include <sys/types.h>
#include <unistd.h>
#include <string.h>

int main(int argc, char** argv)
{
    getpid(); //该系统调用起到标识作用
    if(argc < 2)
    {
        printf("hang (user|system)\n");
        return 1;
    }
    if(!strcmp(argv[1], "user"))
        while(1);
    else if(!strcmp(argv[1], "system"))
        sleep(500);
    return 0;
}
...
open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P \2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1857312, ...}) = 0
...
close(3)                                = 0
...
munmap(0x7f21e695f000, 143984)          = 0
getpid()                                = 8446
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
nanosleep({500, 0},
  • 分析:
    (1)第3行,调用read,从/lib/i386-linux-gnu/libc.so.6该libc库文件中读取832bytes,即读取ELF头信息 。
    ​ (2)分析:
    用户态挂死情况下,strace在getpid()一行输出之后没有其他系统调用输出;
    进程在内核态挂死,最后一行的系统调用nanosleep不能完整显示,这里nanosleep没有返回值表示该调用尚未完成。
    (3)​ 结论:
    使用strace跟踪挂死程序,如果最后一行系统调用显示完整,程序在逻辑代码处挂死;
    如果最后一行系统调用显示不完整,程序在该系统调用处挂死。
    当程序挂死在系统调用处,可以查看相应系统调用的man手册,了解在什么情况下该系统调用会出现挂死情况。

  • eg:定位共享内存异常

-WH-30~/$ strace -tt -f -e trace=ipc ./a_mon_svr     ../conf/a_mon_svr.conf
22:46:36.351798 shmget(0x5feb, 12000, 0666) = 0
22:46:36.351939 shmat(0, 0, 0)          = ?
Process 21406 attached
22:46:36.355439 shmget(0x41400, 30097568, 0666) = -1 EINVAL (Invalid argument)
shmget 267264 30097568: Invalid argument
Can not get shm...exit!
  • 分析:
ipcs  -m | grep 41400
key        shmid      owner      perms      bytes      nattch     status    
0x00041400 1015822    root       666        30095516   1

​ 可以看到,已经0x41400这个key已经存在,并且其大小为30095516字节,和我们调用参数中的30097568不匹配,于是产生了这个错误。

4.五种利用strace查故障的简单方法

  • (1)找出程序在startup的时候读取的哪个config文件?
$ strace php 2>&1 | grep php.ini  
open("/usr/local/bin/php.ini", O_RDONLY) = -1 ENOENT (No such file or directory)  
open("/usr/local/lib/php.ini", O_RDONLY) = 4  
lstat64("/usr/local/lib/php.ini", {st_mode=S_IFLNK|0777, st_size=27, ...}) = 0  
readlink("/usr/local/lib/php.ini", "/usr/local/Zend/etc/php.ini", 4096) = 27  
lstat64("/usr/local/Zend/etc/php.ini", {st_mode=S_IFREG|0664, st_size=40971, ...}) = 0  

更精致的方法
$ strace -e open php 2>&1 | grep php.ini  
open("/usr/local/bin/php.ini", O_RDONLY) = -1 ENOENT (No such file or directory)  
open("/usr/local/lib/php.ini", O_RDONLY) = 4  
  • (2)为什么这个程序没有打开我的文件?
strace -e open,access 2>&1 | grep your-filename  
  • (3) 某个进程现在在做什么?
aaa@qq.com:~# strace -p 15427  
Process 15427 attached - interrupt to quit  
futex(0x402f4900, FUTEX_WAIT, 2, NULL   
Process 15427 detached  

这个例子里面,它在调用futex()的时候挂起了。
  • (4) 是谁偷走了时间?
aaa@qq.com:~# strace -c -p 11084  				aaa@qq.com:~# strace -c >/dev/null ls
Process 11084 attached - interrupt to quit  
Process 11084 detached  
% time     seconds  usecs/call     calls    errors syscall  
------ ----------- ----------- --------- --------- ----------------  
 94.59    0.001014          48        21           select  
  2.89    0.000031           1        21           getppid  
  2.52    0.000027           1        21           time  
------ ----------- ----------- --------- --------- ----------------  
100.00    0.001072                    63           total  

在这个例子中,程序花了绝大部分时间在等待select()。

它在每一个slect()调用这件调用getpid()time(),这是一种典型的事件循环
  • (4)为什么 无法连接到服务器?
    strace只返回你的进程相关的系统调用产生的数据。
    如果你要从100个连接到统一个数据服务器的运行进程里面找出一个连接所做的事情,用strace就比tcpdump简单得多。
$ strace -e poll,select,connect,recvfrom,sendto nc www.news.com 80  
.。。。。。。。。
connect(3, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("216.239.122.102")}, 16) = -1 EINPROGRESS (Operation now in progress) 
。。。。

最后,它发起一个connect()请求到得到的IP地址,注意到返回值是EINPROGRESS。这意味这connect是非阻塞的,nc希望继续处理,
然后它调用slect(),连接建立后,select返回成功。

5.strace解决高负载服务器的top

  • top技巧
运行 top 时,按「1」打开 CPU 列表,按「shift+p」以 CPU 排序
  • 分析
    (1)CPU 主要是被若干个 PHP 进程占用了,同时 PHP 进程占用的比较多的内存,不过系统内存尚有结余,SWAP 也不严重
    (2)在 CPU 列表中能看到 CPU 主要消耗在内核态「sy」,而不是用户态「us」
    实操strace

6.linux下的调试工具ltrace与strace

  • ltrace能够跟踪进程的库函数调用,它会显现出哪个库函数被调用,而strace则是跟踪程序的每个系统调用

  • strace在跟踪系统调用的时候不需要动态库,而ltrace是根据动态库来分析程序运行的,所以ltrace也只能跟踪动态库,不能跟踪静态库

  • 用ltrace和strace都可以发现程序在哪个系统调用时发生了性能瓶径

  • 参考:strace工具使用手册linux神器stracestrace命令详解,linux下的调试工具ltrace与strace