linux神器strace

man strace:

strace - trace system calls and signals

DESCRIPTION
In the simplest case strace runs the specified command until it exits. It intercepts and records the system calls which are called by a process and the signals which are
received by a process. The name of each system call, its arguments and its return value are printed on standard error or to the file specified with the -o option.

strace is a useful diagnostic, instructional, and debugging tool. System administrators, diagnosticians and trouble-shooters will find it invaluable for solving problems
with programs for which the source is not readily available since they do not need to be recompiled in order to trace them. Students, hackers and the overly-curious will
find that a great deal can be learned about a system and its system calls by tracing even ordinary programs. And programmers will find that since system calls and signals
are events that happen at the user/kernel interface, a close examination of this boundary is very useful for bug isolation, sanity checking and attempting to capture race
conditions.

Each line in the trace contains the system call name, followed by its arguments in parentheses and its return value. An example from stracing the command ``cat /dev/null‘‘
is:

open("/dev/null", O_RDONLY) = 3

Errors (typically a return value of -1) have the errno symbol and error string appended.

open("/foo/bar", O_RDONLY) = -1 ENOENT (No such file or directory)

Signals are printed as a signal symbol and a signal string. An excerpt from stracing and interrupting the command ``sleep 666‘‘ is:

sigsuspend([] <unfinished ...>
--- SIGINT (Interrupt) ---
+++ killed by SIGINT +++

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

什么是strace?

strace是一个非常简单的工具,它可以跟踪系统调用的执行。最简单的方式,它可以从头到尾跟踪binary的执行,然后以一行文本输出系统调用的名字,参数和返回值。

其实它可以做的更多:

  • 可以对特定的系统调用或者几组系统调用进行过滤
  • 可以通过统计特定系统调用的调用次数、耗费的时间、成功和失败的次数来配置(profile)系统调用的使用I
  • 跟踪发送给进程的信号量
  • 可以通过pid附着(attach)到任何运行的进程

如果你使用的是其它Unix系统,它类似于"truss"。其它更复杂的是Sun的Dtrace.

怎么使用它

1) 找出程序在startup的时候读取的哪个config文件?

有没有尝过解决为什么某些程序不读去你认为它应该读取的config文件的问题?

[cpp] view plain copy

  1. strace php 2>&1 | grep php.ini  
  2. open("/usr/local/bin/php.ini", O_RDONLY) = -1 ENOENT (No such file or directory)
  3. open("/usr/local/lib/php.ini", O_RDONLY) = 4
  4. lstat64("/usr/local/lib/php.ini", {st_mode=S_IFLNK|0777, st_size=27, ...}) = 0
  5. readlink("/usr/local/lib/php.ini", "/usr/local/Zend/etc/php.ini", 4096) = 27
  6. lstat64("/usr/local/Zend/etc/php.ini", {st_mode=S_IFREG|0664, st_size=40971, ...}) = 0

可以看出这个版本的PHP从/usr/local/lib/php.init读取config文件(但是先尝试/usr/locl/bin)

如果只关心特定的系统调用,有更精致的方法

[cpp] view plain copy

  1. $ strace -e open php 2>&1 | grep php.ini
  2. open("/usr/local/bin/php.ini", O_RDONLY) = -1 ENOENT (No such file or directory)
  3. open("/usr/local/lib/php.ini", O_RDONLY) = 4

相同的方法适用于很多其它类似的问题。比如说,安装了不同版本的library,不确定实际上加载了哪一个版本。

-e expr -- a qualifying expression: option=[!]all or option=[!]val1[,val2]...
options: trace, abbrev, verbose, raw, signal, read, write

2) 为什么这个程序没有打开我的文件?

是否曾经碰到过一个程序拒绝读取它没有权限的文件,但是你发誓原因是它没有真正找到那个文件?对程序跟踪open,access调用,注意失败的情况

[cpp] view plain copy

  1. $ strace -e open,access 2>&1 | grep your-filename

3) 某个进程现在在做什么?

某个进程突然占用了很多CPU? 或者某个进程看起来像hanging了?

找到对应的pid,然后

hang:

悬挂,挂起的意思

就是一个进程被暂时停止执行.

hang

[cpp] view plain copy

  1. [email protected]:~# strace -p 15427
  2. Process 15427 attached - interrupt to quit
  3. futex(0x402f4900, FUTEX_WAIT, 2, NULL
  4. Process 15427 detached

嗯,这个例子里面,它在调用futex()的时候挂起了。

"strace -p"非常有用,它减少了很多猜测工作,也不需要重新启动应用。

-p pid -- trace process with process id PID, may be repeated

4) 是谁偷走了时间?

你可以重新编译app,打开profiling,以获取精确的信息。但是通常利用strace附着(attach)一个进程以快速地看一下当前时间花费在哪里非常有用。可以看下是否90%的CPU用在真正的工作,或者用在其它方面了。

[cpp] view plain copy

  1. [email protected]:~# strace -c -p 11084
  2. Process 11084 attached - interrupt to quit
  3. Process 11084 detached
  4. % time     seconds  usecs/call     calls    errors syscall
  5. ------ ----------- ----------- --------- --------- ----------------
  6. 94.59    0.001014          48        21           select
  7. 2.89    0.000031           1        21           getppid
  8. 2.52    0.000027           1        21           time
  9. ------ ----------- ----------- --------- --------- ----------------
  10. 100.00    0.001072                    63           total
  11. [email protected]:~#

-c -- count time, calls, and errors for each syscall and report summary
-C -- like -c but also print regular output

在执行strace -c -p命令以后,等到你关注的时间到了后,按ctrl-c退出,strace会列出如上的profiling数据。

在这个例子中,程序花了绝大部分时间在等待select()。它在每一个slect()调用这件调用getpid()和time(),这是一种典型的事件循环。

你也可以运行"start to finish",这里是"ls"

[cpp] view plain copy

  1. [email protected]:~# strace -c >/dev/null ls
  2. % time     seconds  usecs/call     calls    errors syscall
  3. ------ ----------- ----------- --------- --------- ----------------
  4. 23.62    0.000205         103         2           getdents64
  5. 18.78    0.000163          15        11         1 open
  6. 15.09    0.000131          19         7           read
  7. 12.79    0.000111           7        16           old_mmap
  8. 7.03    0.000061           6        11           close
  9. 4.84    0.000042          11         4           munmap
  10. 4.84    0.000042          11         4           mmap2
  11. 4.03    0.000035           6         6         6 access
  12. 3.80    0.000033           3        11           fstat64
  13. 1.38    0.000012           3         4           brk
  14. 0.92    0.000008           3         3         3 ioctl
  15. 0.69    0.000006           6         1           uname
  16. 0.58    0.000005           5         1           set_thread_area
  17. 0.35    0.000003           3         1           write
  18. 0.35    0.000003           3         1           rt_sigaction
  19. 0.35    0.000003           3         1           fcntl64
  20. 0.23    0.000002           2         1           getrlimit
  21. 0.23    0.000002           2         1           set_tid_address
  22. 0.12    0.000001           1         1           rt_sigprocmask
  23. ------ ----------- ----------- --------- --------- ----------------
  24. 100.00    0.000868                    87        10 total

正如你的预期,它耗费了大部分时间在两次调用来读取目录条目上(因为运行于一个小的目录上,所有只有两次)

5) 为什么 无法连接到服务器?

调试进程无法连接到远端服务器有时候是件非常头痛的事。DNS会失败,connect会挂起,server有可能返回一些意料之外的数据。可以使用tcpdump来分析这些情况,它是一个非常棒的工作。但是有时候你strace可以给你更简单,耿直借的角度,因为strace只返回你的进程相关的系统调用产生的数据。如果你要从100个连接到统一个数据服务器的运行进程里面找出一个连接所做的事情,用strace就比tcpdump简单得多。

下面是跟踪"nc"连接到www.news.com 80端口的例子

[cpp] view plain copy

  1. $ strace -e poll,select,connect,recvfrom,sendto nc www.news.com 80
  2. sendto(3, "\\24\\0\\0\\0\\26\\0\\1\\3\\255\\373NH\\0\\0\\0\\0\\0\\0\\0\\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
  3. connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
  4. connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
  5. connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, 28) = 0
  6. poll([{fd=3, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
  7. sendto(3, "\\213\\321\\1\\0\\0\\1\\0\\0\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\34\\0\\1", 30, MSG_NOSIGNAL, NULL, 0) = 30
  8. poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
  9. recvfrom(3, "\\213\\321\\201\\200\\0\\1\\0\\1\\0\\1\\0\\0\\3www\\4news\\3com\\0\\0\\34\\0\\1\\300\\f"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, [16]) = 153
  10. connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, 28) = 0
  11. poll([{fd=3, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
  12. sendto(3, "k\\374\\1\\0\\0\\1\\0\\0\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\1\\0\\1", 30, MSG_NOSIGNAL, NULL, 0) = 30
  13. poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
  14. recvfrom(3, "k\\374\\201\\200\\0\\1\\0\\2\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\1\\0\\1\\300\\f"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, [16]) = 106
  15. connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, 28) = 0
  16. poll([{fd=3, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
  17. sendto(3, "\\\\\\2\\1\\0\\0\\1\\0\\0\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\1\\0\\1", 30, MSG_NOSIGNAL, NULL, 0) = 30
  18. poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
  19. recvfrom(3, "\\\\\\2\\201\\200\\0\\1\\0\\2\\0\\0\\0\\0\\3www\\4news\\3com\\0\\0\\1\\0\\1\\300\\f"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("62.30.112.39")}, [16]) = 106
  20. 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)
  21. select(4, NULL, [3], NULL, NULL)        = 1 (out [3])

发生了什么?

注意到尝试连接/var/run/nscd/socket?这意味着nc首先尝试连接NSCD--the Name Service Cache Daemon--它通常用来基于NIS,YP,LDAP或者类似的目录协议提供域名查询。在这里它失败了。

然后它连接DNS(DNS是port 53,所以"sin_port=htons(53)")。然后它调用了"sendto()“,发送包含www.news.com的DNS 包。然后读回响应。不知为何,它尝试了三次,最后一次有细微的却别,我猜是它www.news.com十一个CNAME(别名),多次请求可能是nc故意的。

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

添加"read","write"到过滤系统调用列表中,连接时输入一个字串,可能会得到如下

Notice the connection attempts to /var/run/nscd/socket? They mean nc first tries to connect to NSCD - the Name Service Cache Daemon - which is usually used in setups that rely on NIS, YP, LDAP or similar directory protocols for name lookups. In this case the connects fails.

It then moves on to DNS (DNS is port 53, hence the "sin_port=htons(53)" in the following connect. You can see it then does a "sendto()" call, sending a DNS packet that contains www.news.com. It then reads back a packet. For whatever reason it tries three times, the last with a slightly different request. My best guess why in this case is that www.news.com is a CNAME (an "alias"), and the multiple requests may just be an artifact of how nc deals with that.

Then in the end, it finally issues a connect() to the IP it found. Notice it returns EINPROGRESS. That means the connect was non-blocking - nc wants to go on processing. It then calls select(), which succeeds when the connection was successful.

Try adding "read" and "write" to the list of syscalls given to strace and enter a string when connected, and you‘ll get something like this:

[cpp] view plain copy

  1. read(0, "test\\n", 1024)                 = 5
  2. write(3, "test\\n", 5)                   = 5
  3. poll([{fd=3, events=POLLIN, revents=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1
  4. read(3, "

这表示从标准输入读入"test"+换行符,并写到网络连接中,然后调用poll等待响应,读取响应,写回标准输出。

一切看起来都正常工作。

原文地址:http://www.hokstad.com/5-simple-ways-to-troubleshoot-using-strace

原文出处: 火丁笔记(@火丁笔记)

早些年,如果你知道有个 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

1

shell> strace -p <PID>

不过如果直接用 strace 跟踪某个进程的话,那么等待你的往往是满屏翻滚的字符,想从这里看出问题的症结并不是一件容易的事情,好在 strace 可以按操作汇总时间:

Shell

1

shell> strace -cp <PID>

通过「c」选项用来汇总各个操作的总耗时,运行后的结果大概如下图所示:

strace -cp

很明显,我们能看到 CPU 主要被 clone 操作消耗了,还可以单独跟踪一下 clone:

Shell

1

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 里什么时候会出现此类系统调用呢?查询业务代码看到了 exec 函数,通过如下命令验证它确实会导致 clone 系统调用:

Shell

1

shell> strace -eclone php -r ‘exec("ls");

最后再考大家一个题:如果我们用 strace 跟踪一个进程,输出结果很少,是不是说明进程很空闲?其实试试 ltrace,可能会发现别有洞天。记住有内核态和用户态之分。

原文地址:https://www.cnblogs.com/youxin/p/8837771.html

时间: 2024-10-10 02:52:49

linux神器strace的相关文章

Linux之strace简单用法

Linux下,进程不能直接访问硬件设备.当进程需要访问硬件设备时(读取磁盘文件.接收网络数据等),则必须由用户态切换为内核态,然后通过系统调用来访问硬件设备. strace是跟踪进程执行时的系统调用和所接收的信号(即它跟踪到一个进程产生的系统调用,包括参数.返回值.执行消耗的时间). strace最简单的用法是执行一个指定的命令(过程中,starce会记录和解析命令进程的所有系统调用及这个进程的所有的信号值),在指定命令结束后立即退出 [[email protected] t_7_17]$ st

使用 Linux 的 strace 命令跟踪/调试程序的常用选项

译文:LCTT  https://linux.cn/article-3935-1.html译者: guodongxiaren 在调试的时候,strace能帮助你追踪到一个程序所执行的系统调用.当你想知道程序和操作系统如何交互的时候,这是极其方便的,比如你想知道执行了哪些系统调用,并且以何种顺序执行. 这个简单而又强大的工具几乎在所有的Linux操作系统上可用,并且可被用来调试大量的程序. 命令用法 让我们看看strace命令如何追踪一个程序的执行情况. 最简单的形式,strace后面可以跟任何命

Linux调试工具strace和gdb常用命令小结

strace和gdb是Linux环境下的两个常用调试工具,这里是个人在使用过程中对这两个工具常用参数的总结,留作日后查看使用. strace调试工具 strace工具用于跟踪进程执行时的系统调用和所接收的信号,包括参数.返回值.执行时间.在Linux中,用户程序要访问系统设备,必须由用户态切换到内核态,这是通过系统调用发起并完成的. strace常用参数: -c 统计每种系统调用执行的时间.调用次数.出错次数,程序退出时给出报告 -p pid 跟踪指定的进程,可以使用多个-p同时跟踪多个进程 -

Linux调试工具 strace ldd pstack

strace常用来跟踪进程执行时的系统调用和所接收的信号.你不仅可以调试一个新开始的程序,也可以调试一个已经在运行的程序(把strace绑定到一个已有的PID上 面). 通用语法: strace -o output.txt -T -tt -e trace=all -p 28979 上面的含义是 跟踪28979进程的所有系统调用(-e trace=all),并统计系统调用的花费时间,以及开始时间(并以可视化的时分秒格式显示),最后将记录结果存在output.txt文件里面. [email prot

使用Linux strace命令来跟踪 bdump目录的x权限丢失时sqlplus / as sysdba 的输出

在上一篇文章中,说到bdump目录的x权限丢失,导致oracle数据库异常. 下面就来用linux 的strace命令来跟踪一下,当bdump目录的x权限丢失时,sqlplus / as sysdba会有什么样的输出: strace命令如下,该命令来源于:Using Strace in Linux to Debug Hang Type Problems (Doc ID 1391746.1) strace -fe verbose=all -e write=all -e read=all -o /u

oradebug/strace/pstack等分析数据库性能问题系列一

对于性能问题或者一些比较奇怪妖异的问题,有很多点可以着手去分析. 准备写一个系列关于用ash/dba_hist_active_sess_history,用oradebug,用linux命令strace,pstack或者用等等等等工具~~来归纳下一些思路,就是当目前为止所有分析的结果都没任何头绪的时候,接下来如何进行深入的troubleshooting. 比如当一个sql执行的很慢的时候,看看sql历史等待事件,看sql执行计划,但要是没什么特别明显的等待,或者执行计划看上去可以,感觉这个sql应

Linux基础精华(转)

Linux基础精华 (继续跟新中...) 常用命令: Linux shell 环境 让你提升命令行效 率的 Bash 快捷键 [完整版] 设置你自己的liux alias Linux的Find使用 Linux命令Find实>例 Linux命令xargs+cut grep 小技巧 Linux任务前后台的切换 Linux运行与控制后台进程的方法:nohup, setsid, &, disown, screen Linux的rsh配置rhost Linux的nm查看动态和静态库中的符号 Linux

strace 命令分析mysql的相关的问题

strace 命令分析mysql的相关的问题 使用方式: strace -p pid or strace command 本篇博文主要简单介绍下面关于MySQL的5个问题: 利用strace观察mysqld对my.cnf 配置文件的加载顺序 MySQL启动后默认会启动多少线程 如何匹配conn_id和os_thread_id 利用strace观察client的SQL执行 利用strace观察server端执行 1.strace观察mysqld对my.cnf 配置文件的加载顺序 命令如下: str

神秘的40毫秒延迟与 TCP_NODELAY

写 HTTP Server,不可免俗地一定要用 ab 跑一下性能,结果一跑不打紧,出现了一个困扰了我好几天的问题:神秘的 40ms 延迟. Table of Contents 1 现象 2 背后的原因 3 为什么只有 Write-Write-Read 时才会出问题 4 解决方案 4.1 优化协议 4.2 开启 TCP_NODELAY 1 现象 现象是这样的,首先看我用 ab 不加 -k 选项的结果: [~/dev/personal/breeze]$ /usr/sbin/ab -c 1 -n 10