pstack,strace,gdb工具使用

pstack,strace,gdb工具使用
MySQL 的几种调式分析工具介绍
MySQL 的几种调式分析工具，常用的有如下4种：
pstack
gdb
strace
perf
如下分别介绍之。

pstack

注意：pstack所追踪的是用户态调用栈

获取堆栈信息
问题线程的定位
负载较低
mysql_pid=23632
pstack $mysql_pid>pstack.info
pt-pmp对堆栈信息排序
pt-pmp pstack.info | less
也可以直接执行pt-pmp
pt-pmp --pid 4522
gdb
堆栈跟踪
等待分析
侵入性大
mysqld_pid=23632
gdb -p $mysqld_pid
(gdb) info thread 显示运行的所有线程
(gdb) thread 4 切换到某个线程
bt 显示调用栈
注意
pstack 和gdb都可以获取堆栈信息，区别是gdb是交互式的（需要手动退出），pstack是快照形式（执行3s自动退出）
对mysqld使用gdb后，已经建立的连接无法再执行语句，新连接无法建立
strace
查看进程的系统调用信息
负载较高
查看系统调用
strace -cp $mysqld_pid
查看执行语句
mysqld_pid=4522
strace -f -F -ff -o mysqld-strace -s 1024 -p $mysqld_pid
find ./ -name “mysqld-strace” -type f -print |xargs grep -n “SELECT.FROM”
查看读写的文件
strace -o /tmp/strace_output.txt -T -tt -f -e trace=read,open -p “mysqld_pid”
perf
进程内部函数调用情况
负载较低
mysqld内部函数整体消耗情况
perf top -p 23632
记录所有内部函数调用
该命令会输出记录到perf.data中
perf record -p 23632
解析并查看perf.data内容
perf script -i perf.data>perf.log && less perf.log

Linux strace、pstack 命令 使用详解

引言
有时我们需要对程序进行优化、减少程序响应时间。除了一段段地对代码进行时间复杂度分析，我们还有更便捷的方法吗？

若能直接找到影响程序运行时间的函数调用，再有针对地对相关函数进行代码分析和优化，那相比漫无目的地看代码，效率就高多了。

将strace和pstack工具结合起来使用，就可以达到以上目的。strace跟踪程序使用的底层系统调用，可输出系统调用被执行的时间点以及各个调用耗时；pstack工具对指定PID的进程输出函数调用栈。

下面我们通过一个简单的消息收发程序，说明使用strace、pstack进行程序分析的具体方法。

程序说明
该程序是一个简单的socket程序，由server/client组成。server端监听某端口，等待client的连接，client连接server后定时向server发送消息，server每接收一条消息后向client发送响应消息。程序server与client交互如下图示：

在程序运行起来之后，发现server接收到client的submit消息之后，需要较长时间才发出resp响应。通过tcpdump抓包发现，time2与time1的时间间隔在1s左右：

由上初步分析可知，消息响应慢是server端程序问题。下面我们来看如何使用strace和pstack分析server端程序响应慢的原因。
strace查看系统调用
首先我们拉起server/client程序，并使用strace对server进程进行跟踪：

ps -elf | grep server | grep -v grep

0 S root 16739 22642 0 76 0 - 634 1024 14:26 pts/2 00:00:00 ./server

strace -o server.strace -Ttt -p 16739

Process 16739 attached - interrupt to quit

稍等一段时间之后，我们将strace停掉， server.strace文件中有以下输出：

14:46:39.741366 select(8, [3 4], NULL, NULL, {1, 0}) = 1 (in [4], left {0, 1648}) <0.998415>
14:46:40.739965 recvfrom(4, “hello”, 6, 0, NULL, NULL) = 5 <0.000068>
14:46:40.740241 write(1, “hello\n”, 6) = 6 <0.000066>
14:46:40.740414 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0 <0.000046>
14:46:40.740565 rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0 <0.000048>
14:46:40.740715 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 <0.000046>
14:46:40.740853 nanosleep({1, 0}, {1, 0}) = 0 <1.000276>
14:46:41.741284 sendto(4, “hello\0”, 6, 0, NULL, 0) = 6 <0.000111>

可以看到server接收数据之后(对应recvfrom调用)，经过1s左右时间将消息发出(对应sendto调用)，从响应时间看，与抓包的结果吻合。又可以看出nanosleep系统调用耗费了1s时间。

因而可以断定响应延时由nanosleep对应的函数调用造成。

那具体是哪一个函数调用呢？在strace输出结果中并不能找到答案，因其输出显示都是系统调用，要显示程序中函数调用栈信息，就轮到pstack上场了。

pstack查看函数堆栈
pstack是一个脚本工具，其核心实现就是使用了gdb以及thread apply all bt命令，下面我们使用pstack查看server进程函数堆栈：

sh pstack.sh 16739

#0 0x00002ba1f8152650 in __nanosleep_nocancel () from /lib64/libc.so.6
#1 0x00002ba1f8152489 in sleep () from /lib64/libc.so.6
#2 0x00000000004007bb in ha_ha ()
#3 0x0000000000400a53 in main ()

从以上信息可以看出，函数调用关系为：main->ha_ha->sleep，因而我们可以找到ha_ha函数进行分析和优化修改。

小结
本文通过一个server/client程序事例，说明了使用strace和pstack分析响应延时的方法。
由最初server端响应慢现象，到使用strace跟踪出具体耗时的系统调用，再到使用pstack查到程序中具体的耗时函数，一步步找到了影响程序运行时间的程序代码。
更多地了解底层，从操作系统层面着手，更有助于程序性能分析与优化。
手把手教你用Strace诊断问题

早些年，如果你知道有个 strace 命令，就很牛了，而现在大家基本都知道 strace 了，如果你遇到性能问题求助别人，十有八九会建议你用 strace 挂上去看看，不过当你挂上去了，看着满屏翻滚的字符，却十有八九看不出个所以然。本文通过一个简单的案例，向你展示一下在用 strace 诊断问题时的一些套路。

如下真实案例，如有雷同，实属必然！让我们看一台高负载服务器的 top 结果：

技巧：运行 top 时，按「1」打开 CPU 列表，按「shift+p」以 CPU 排序。
在本例中大家很容易发现 CPU 主要是被若干个 PHP 进程占用了，同时 PHP 进程占用的比较多的内存，不过系统内存尚有结余，SWAP 也不严重，这并不是问题主因。
不过在 CPU 列表中能看到 CPU 主要消耗在内核态「sy」，而不是用户态「us」，和我们的经验不符。Linux 操作系统有很多用来跟踪程序行为的工具，内核态的函数调用跟踪用「strace」，用户态的函数调用跟踪用「ltrace」，所以这里我们应该用「strace」：
shell> strace -p 
不过如果直接用 strace 跟踪某个进程的话，那么等待你的往往是满屏翻滚的字符，想从这里看出问题的症结并不是一件容易的事情，好在 strace 可以按操作汇总时间：
shell> strace -cp 

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

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

shell> strace -T -e clone -p 
通过「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> strace -eclone php -r ‘exec(“ls”);’

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

Linux 高级调试工具-pstack和strace

一般调试linux程序，使用gdb即可！但是如果要对程序进行性能分析，或者没有办法使用gdb调试的时候，pstack和strace会排上大用场！！！！

pstack
sudo apt install pstack

pstack命令⽤来显示每个进程的调⽤栈。可以使⽤pstack来查看进程正在挂起的执⾏⽅法，也可以⽤来查看进程的本地线程堆栈。它实际上是gstack的一个链接，而gstack本身是基于gdb封装的shell脚本。pstack是gdb的一部分，如果系统没有pstack命令，使用yum搜索安装gdb即可。

使⽤⽅式：pstack 进程ID
[root@VM_0_3_centos ~]# pstack 25901
Thread 2 (Thread 0x7f950fd02700 (LWP 25902)):
#0 0x00007f9514a1ff73 in select () from /usr/lib64/libc.so.6
#1 0x00007f95136b95a5 in apr_sleep () from /usr/lib64/libapr-1.so.0
#2 0x00007f9514645f19 in ?? ()
#3 0x0000000001186ec0 in ?? ()
#4 0x0000000001186ec0 in ?? ()
#5 0x00007f950fd01d60 in ?? ()
#6 0x00007f95146a3d9e in ?? ()
#7 0x0000000001184da0 in ?? ()
#8 0x0000000000000000 in ?? ()
Thread 1 (Thread 0x7f9515b348c0 (LWP 25901)):
#0 0x00007f9514a29483 in epoll_wait () from /usr/lib64/libc.so.6
#1 0x000000000048604f in CEventDispatch::StartDispatch (this=0x1195600,
wait_timeout=100) at /root/im/0voice_im/server/src/base/EventDispatch.cpp:365
#2 0x0000000000479ad2 in netlib_eventloop (wait_timeout=100) at
/root/im/0voice_im/server/src/base/netlib.cpp:160
#3 0x000000000046f598 in main (argc=1, argv=0x7ffc278e13a8) at
/root/im/0voice_im/server/src/login_server/login_server.cpp:132

strace
系统调⽤⼯具，是Linux系统下的⼀款程序调试⼯具，⽤来监控⼀个应⽤程序所使⽤的 系统调⽤，通过它可以跟踪系统调⽤，让你熟悉⼀个Linux程序在背后是怎么⼯作的。 适⽤于想研究Linux底层的⼯作机制的场景。多用于程序性能分析！

参数
-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信号.54
-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执⾏被跟踪的命令
实时查看进程

[root@VM_0_3_centos ~]# strace -p 25901
strace: Process 25901 attached
gettimeofday({1566530771, 437813}, NULL) = 0
epoll_wait(6, [], 1024, 100) = 0
gettimeofday({1566530771, 538318}, NULL) = 0
gettimeofday({1566530771, 538424}, NULL) = 0
gettimeofday({1566530771, 538458}, NULL) = 0
epoll_wait(6, [], 1024, 100) = 0
gettimeofday({1566530771, 638872}, NULL) = 0
epoll_wait(6, [], 1024, 100) = 0
gettimeofday({1566530771, 739125}, NULL) = 0
epoll_wait(6, [], 1024, 100) = 0
测试⼀段时间进程运⾏情况

[root@VM_0_3_centos ~]# strace -c -p 25901
strace: Process 25901 attached
^Cstrace: Process 25901 detached
% time seconds usecs/call calls errors syscall

---

88.29 0.002972 19 160 epoll_wait
7.31 0.000246 1 198 gettimeofday
4.19 0.000141 47 3 sendto
0.12 0.000004 1 4 2 recvfrom
0.09 0.000003 2 2 ioctl
------ ----------- ----------- --------- --------- ----------------55
100.00 0.003366 367 2 total
输⼊strace -c -p 25901后过段时间按ctrl+c退出
————————————————
版权声明：本文为CSDN博主「小o魂」的原创文章，遵循CC 4.0 BY-SA版权协议，转载请附上原文出处链接及本声明。
原文链接：https://blog.csdn.net/u012173846/article/details/119087211

pstack
显示每个进程的栈跟踪

补充说明
pstack命令可显示每个进程的栈跟踪。pstack命令必须由相应进程的属主或root运行。可以使用pstack来确定进程挂起的位置。此命令允许使用的唯一选项是要检查的进程的PID。
命令软件包下载地址：https://packages.debian.org/sid/pstack

实例
pstree以树结构显示进程

pstree -p work | grep ad
sshd(22669)—bash(22670)—ad_preprocess(4551)-±{ad_preprocess}(4552)
|-{ad_preprocess}(4553)
|-{ad_preprocess}(4554)
|-{ad_preprocess}(4555)
|-{ad_preprocess}(4556)
`-{ad_preprocess}(4557)
work为工作用户，-p为显示进程识别码，ad_preprocess共启动了6个子线程，加上主线程共7个线程。

ps -Lf 4551
UID PID PPID LWP C NLWP STIME TTY stat time CMD
work 4551 22670 4551 2 7 16:30 pts/2 Sl+ 0:02 ./ad_preprocess
work 4551 22670 4552 0 7 16:30 pts/2 Sl+ 0:00 ./ad_preprocess
work 4551 22670 4553 0 7 16:30 pts/2 Sl+ 0:00 ./ad_preprocess
work 4551 22670 4554 0 7 16:30 pts/2 Sl+ 0:00 ./ad_preprocess
work 4551 22670 4555 0 7 16:30 pts/2 Sl+ 0:00 ./ad_preprocess
work 4551 22670 4556 0 7 16:30 pts/2 Sl+ 0:00 ./ad_preprocess
work 4551 22670 4557 0 7 16:30 pts/2 Sl+ 0:00 ./ad_preprocess
进程共启动了7个线程
pstack显示每个进程的栈跟踪：

pstack 4551
Thread 7 (Thread 1084229984 (LWP 4552)):
#0 0x000000302afc63dc in epoll_wait () from /lib64/tls/libc.so.6
#1 0x00000000006f0730 in ub::EPollEx::poll ()
#2 0x00000000006f172a in ub::NetReactor::callback ()
#3 0x00000000006fbbbb in ub::UBTask::CALLBACK ()
#4 0x000000302b80610a in start_thread () from /lib64/tls/libpthread.so.0
#5 0x000000302afc6003 in clone () from /lib64/tls/libc.so.6
#6 0x0000000000000000 in ?? ()
Thread 6 (Thread 1094719840 (LWP 4553)):
#0 0x000000302afc63dc in epoll_wait () from /lib64/tls/libc.so.6
#1 0x00000000006f0730 in ub::EPollEx::poll ()
#2 0x00000000006f172a in ub::NetReactor::callback ()
#3 0x00000000006fbbbb in ub::UBTask::CALLBACK ()
#4 0x000000302b80610a in start_thread () from /lib64/tls/libpthread.so.0
#5 0x000000302afc6003 in clone () from /lib64/tls/libc.so.6
#6 0x0000000000000000 in ?? ()
Thread 5 (Thread 1105209696 (LWP 4554)):
#0 0x000000302b80baa5 in __nanosleep_nocancel ()
#1 0x000000000079e758 in comcm::ms_sleep ()
#2 0x00000000006c8581 in ub::UbClientManager::healthyCheck ()
#3 0x00000000006c8471 in ub::UbClientManager::start_healthy_check ()
#4 0x000000302b80610a in start_thread () from /lib64/tls/libpthread.so.0
#5 0x000000302afc6003 in clone () from /lib64/tls/libc.so.6
#6 0x0000000000000000 in ?? ()
Thread 4 (Thread 1115699552 (LWP 4555)):
#0 0x000000302b80baa5 in __nanosleep_nocancel ()
#1 0x0000000000482b0e in armor::armor_check_thread ()
#2 0x000000302b80610a in start_thread () from /lib64/tls/libpthread.so.0
#3 0x000000302afc6003 in clone () from /lib64/tls/libc.so.6
#4 0x0000000000000000 in ?? ()
Thread 3 (Thread 1126189408 (LWP 4556)):
#0 0x000000302af8f1a5 in __nanosleep_nocancel () from /lib64/tls/libc.so.6
#1 0x000000302af8f010 in sleep () from /lib64/tls/libc.so.6
#2 0x000000000044c972 in Business_config_manager::run ()
#3 0x0000000000457b83 in Thread::run_thread ()
#4 0x000000302b80610a in start_thread () from /lib64/tls/libpthread.so.0
#5 0x000000302afc6003 in clone () from /lib64/tls/libc.so.6
#6 0x0000000000000000 in ?? ()
Thread 2 (Thread 1136679264 (LWP 4557)):
#0 0x000000302af8f1a5 in __nanosleep_nocancel () from /lib64/tls/libc.so.6
#1 0x000000302af8f010 in sleep () from /lib64/tls/libc.so.6
#2 0x00000000004524bb in Process_thread::sleep_period ()
#3 0x0000000000452641 in Process_thread::run ()
#4 0x0000000000457b83 in Thread::run_thread ()
#5 0x000000302b80610a in start_thread () from /lib64/tls/libpthread.so.0
#6 0x000000302afc6003 in clone () from /lib64/tls/libc.so.6
#7 0x0000000000000000 in ?? ()
Thread 1 (Thread 182894129792 (LWP 4551)):
#0 0x000000302af8f1a5 in __nanosleep_nocancel () from /lib64/tls/libc.so.6
#1 0x000000302af8f010 in sleep () from /lib64/tls/libc.so.6
#2 0x0000000000420d79 in Ad_preprocess::run ()
#3 0x0000000000450ad0 in main ()
————————————————