使用 GDB 调试 Linux 软件
除了调试 core 文件或程序之外,gdb 还可以连接到已经运行的进程,例如:
#./nginx -V
#ps -ef|grep nginx
查找 nginx pid 为1283
#gdb /usr/local/nginx/sbin/nginx 1283
#(gdb) bt
编译
开始调试之前,必须用程序中的调试信息编译要调试的程序。这样,gdb 才能够调试所使用的变量、代码行和函数。如果要进行编译,请在 gcc(或 g++)下使用额外的 '-g' 选项来编译程序:
gcc -g eg.c -o eg
运行 gdb
在 shell 中,可以使用 'gdb' 命令并指定程序名作为参数来运行 gdb,例如 'gdb eg';或者在 gdb 中,可以使用 file 命令来装入要调试的程序,例如 'file eg'。这两种方式都假设您是在包含程序的目录中执行命令。装入程序之后,可以用 gdb 命令 'run' 来启动程序。
调试会话示例
如果一切正常,程序将执行到结束,此时 gdb 将重新获得控制。但如果有错误将会怎么样?这种情况下,gdb 会获得控制并中断程序,从而可以让您检查所有事物的状态,如果运气好的话,可以找出原因。为了引发这种情况,我们将使用一个 示例程序:
代码示例 eg1.c
#include int wib(int no1, int no2) { int result, diff; diff = no1 - no2; result = no1 / diff; return result; } int main(int argc, char *argv[]) { int value, div, result, i, total; value = 10; div = 6; total = 0; for(i = 0; i < 10; i++) { result = wib(value, div); total += result; div++; value--; } printf("%d wibed by %d equals %d\n", value, div, total); return 0; }
这个程序将运行 10 次 for 循环,使用 'wib()" 函数计算出累积值,最后打印出结果。
在您喜欢的文本编辑器中输入这个程序(要保持相同的行距),保存为 'eg1.c',使用 'gcc -g eg1.c -o eg1' 进行编译,并用 'gdb eg1' 启动 gdb。使用 'run' 运行程序可能会产生以下消息:
Program received signal SIGFPE, Arithmetic exception. 0x80483ea in wib (no1=8, no2=8) at eg1.c:7 7 result = no1 / diff; (gdb)
gdb 指出在程序第 7 行发生一个算术异常,通常它会打印这一行以及 wib() 函数的自变量值。要查看第 7 行前后的源代码,请使用 'list' 命令,它通常会打印 10 行。再次输入 'list'(或者按回车重复上一条命令)将列出程序的下 10 行。从 gdb 消息中可以看出,第 7 行中的除法运算出了错,程序在这一行中将变量 "no1" 除以 "diff"。
要查看变量的值,使用 gdb 'print' 命令并指定变量名。输入 'print no1' 和 'print diff',可以相应看到 "no1" 和 "diff" 的值,结果如下:
(gdb) print no1 $5 = 8 (gdb) print diff $2 = 0
gdb 指出 "no1" 等于 8,"diff" 等于 0。根据这些值和第 7 行中的语句,我们可以推断出算术异常是由除数为 0 的除法运算造成的。清单显示了第 6 行计算的变量 "diff",我们可以打印 "diff" 表达式(使用 'print no1 - no2' 命令),来重新估计这个变量。gdb 告诉我们 wib 函数的这两个自变量都等于 8,于是我们要检查调用 wib() 函数的 main() 函数,以查看这是在什么时候发生的。在允许程序自然终止的同时,我们使用 'continue' 命令告诉 gdb 继续执行。
(gdb) continue Continuing. Program terminated with signal SIGFPE, Arithmetic exception. The program no longer exists.
使用断点
为了查看在 main() 中发生了什么情况,可以在程序代码中的某一特定行或函数中设置断点,这样 gdb 会在遇到断点时中断执行。可以使用命令 'break main' 在进入 main() 函数时设置断点,或者可以指定其它任何感兴趣的函数名来设置断点。然而,我们只希望在调用 wib() 函数之前中断执行。输入 'list main' 将打印从 main() 函数开始的源码清单,再次按回车将显示第 21 行上的 wib() 函数调用。要在那一行上设置断点,只需输入 'break 21'。gdb 将发出以下响应:
(gdb) break 21 Breakpoint 1 at 0x8048428: file eg1.c, line 21.
以显示它已在我们请求的行上设置了 1 号断点。'run' 命令将从头重新运行程序,直到 gdb 中断为止。发生这种情况时,gdb 会生成一条消息,指出它在哪个断点上中断,以及程序运行到何处:
Breakpoint 1, main (argc=1, argv=0xbffff954) at eg1.c:21 21 result = wib(value, div);
发出 'print value' 和 'print div' 将会显示在第一次调用 wib() 时,变量分别等于 10 和 6,而 'print i' 将会显示 0。幸好,gdb 将显示所有局部变量的值,并使用 'info locals' 命令保存大量输入信息。
从以上的调查中可以看出,当 "value" 和 "div" 相等时就会出现问题,因此输入 'continue' 继续执行,直到下一次遇到 1 号断点。对于这次迭代,'info locals' 显示了 value=9 和 div=7。
与其再次继续,还不如使用 'next' 命令单步调试程序,以查看 "value" 和 "div" 是如何改变的。gdb 将响应:
(gdb) next 22 total += result;
再按两次回车将显示加法和减法表达式:
(gdb) 23 div++; (gdb) 24 value--;
再按两次回车将显示第 21 行,wib() 调用。'info locals' 将显示目前 "div" 等于 "value",这就意味着将发生问题。如果有兴趣,可以使用 'step' 命令(与 'next' 形成对比,'next' 将跳过函数调用)来继续执行 wib() 函数,以再次查看除法错误,然后使用 'next' 来计算 "result"。
现在已完成了调试,可以使用 'quit' 命令退出 gdb。由于程序仍在运行,这个操作会终止它,gdb 将提示您确认。
更多断点和观察点
由于我们想要知道在调用 wib() 函数之前 "value" 什么时候等于 "div",因此在上一示例中我们在第 21 行中设置断点。我们必须继续执行两次程序才会发生这种情况,但是只要在断点上设置一个条件就可以使 gdb 只在 "value" 与 "div" 真正相等时暂停。要设置条件,可以在定义断点时指定 "break <line number> if <conditional expression>"。将 eg1 再次装入 gdb,并输入:
(gdb) break 21 if value==div Breakpoint 1 at 0x8048428: file eg1.c, line 21.
如果已经在第 21 行中设置了断点,如 1 号断点,则可以使用 'condition' 命令来代替在断点上设置条件:
(gdb) condition 1 value==div
使用 'run' 运行 eg1.c 时,如果 "value" 等于 "div",gdb 将中断,从而避免了在它们相等之前必须手工执行 'continue'。调试 C 程序时,断点条件可以是任何有效的 C 表达式,一定要是程序所使用语言的任意有效表达式。条件中指定的变量必须在设置了断点的行中,否则表达式就没有什么意义!
使用 'condition' 命令时,如果指定断点编号但又不指定表达式,可以将断点设置成无条件断点,例如,'condition 1' 就将 1 号断点设置成无条件断点。
要查看当前定义了什么断点及其条件,请发出命令 'info break':
(gdb) info break Num Type Disp Enb Address What 1 breakpoint keep y 0x08048428 in main at eg1.c:21 stop only if value == div breakpoint already hit 1 time
除了所有条件和已经遇到断点多少次之外,断点信息还在 'Enb' 列中指定了是否启用该断点。可以使用命令 'disable <breakpoint number>'、'enable <breakpoint number>' 或 'delete <breakpoint number>' 来禁用、启用和彻底删除断点,例如 'disable 1' 将阻止在 1 号断点处中断。
如果我们对 "value" 什么时候变得与 "div" 相等更感兴趣,那么可以使用另一种断点,称作监视。当指定表达式的值改变时,监视点将中断程序执行,但必须在表达式中所使用的变量在作用域中时设置监视点。要获取作用域中的 "value" 和 "div",可以在 main 函数上设置断点,然后运行程序,当遇到 main() 断点时设置监视点。重新启动 gdb,并装入 eg1,然后输入:
(gdb) break main Breakpoint 1 at 0x8048402: file eg1.c, line 15. (gdb) run ... Breakpoint 1, main (argc=1, argv=0xbffff954) at eg1.c:15 15 value = 10;
要了解 "div" 何时更改,可以使用 'watch div',但由于要在 "div" 等于 "value" 时中断,那么应输入:
(gdb) watch div==value Hardware watchpoint 2: div == value
如果继续执行,那么当表达式 "div==value" 的值从 0(假)变成 1(真)时,gdb 将中断:
(gdb) continue Continuing. Hardware watchpoint 2: div == value Old value = 0 New value = 1 main (argc=1, argv=0xbffff954) at eg1.c:19 19 for(i = 0; i < 10; i++)
'info locals' 命令将验证 "value" 是否确实等于 "div"(再次声明,是 8)。
'info watch' 命令将列出已定义的监视点和断点(此命令等价于 'info break'),而且可以使用与断点相同的语法来启用、禁用和删除监视点。
core 文件
在 gdb 下运行程序可以使俘获错误变得更容易,但在调试器外运行的程序通常会中止而只留下一个 core 文件。gdb 可以装入 core 文件,并让您检查程序中止之前的状态。
在 gdb 外运行示例程序 eg1 将会导致核心信息转储:
$ ./eg1 Floating point exception (core dumped)
要使用 core 文件启动 gdb,在 shell 中发出命令 'gdb eg1 core' 或 'gdb eg1 -c core'。gdb 将装入 core 文件,eg1 的程序清单,显示程序是如何终止的,并显示非常类似于我们刚才在 gdb 下运行程序时看到的消息:
... Core was generated by `./eg1'. Program terminated with signal 8, Floating point exception. ... #0 0x80483ea in wib (no1=8, no2=8) at eg1.c:7 7 result = no1 / diff;
此时,可以发出 'info locals'、'print'、'info args' 和 'list' 命令来查看引起除数为零的值。'info variables' 命令将打印出所有程序变量的值,但这要进行很长时间,因为 gdb 将打印 C 库和程序代码中的变量。为了更容易地查明在调用 wib() 的函数中发生了什么情况,可以使用 gdb 的堆栈命令。
堆栈跟踪
程序“调用堆栈”是当前函数之前的所有已调用函数的列表(包括当前函数)。每个函数及其变量都被分配了一个“帧”,最近调用的函数在 0 号帧中(“底部”帧)。要打印堆栈,发出命令 'bt'('backtrace' [回溯] 的缩写):
(gdb) bt #0 0x80483ea in wib (no1=8, no2=8) at eg1.c:7 #1 0x8048435 in main (argc=1, argv=0xbffff9c4) at eg1.c:21
此结果显示了在 main() 的第 21 行中调用了函数 wib()(只要使用 'list 21' 就能证实这一点),而且 wib() 在 0 号帧中,main() 在 1 号帧中。由于 wib() 在 0 号帧中,那么它就是执行程序时发生算术错误的函数。
实际上,发出 'info locals' 命令时,gdb 会打印出当前帧中的局部变量,缺省情况下,这个帧中的函数就是被中断的函数(0 号帧)。可以使用命令 'frame' 打印当前帧。要查看 main 函数(在 1 号帧中)中的变量,可以发出 'frame 1' 切换到 1 号帧,然后发出 'info locals' 命令:
(gdb) frame 1 #1 0x8048435 in main (argc=1, argv=0xbffff9c4) at eg1.c:21 21 result = wib(value, div); (gdb) info locals value = 8 div = 8 result = 4 i = 2 total = 6
此信息显示了在第三次执行 "for" 循环时(i 等于 2)发生了错误,此时 "value" 等于 "div"。
可以通过如上所示在 'frame' 命令中明确指定号码,或者使用 'up' 命令在堆栈中上移以及 'down' 命令在堆栈中下移来切换帧。要获取有关帧的进一步信息,如它的地址和程序语言,可以使用命令 'info frame'。
gdb 堆栈命令可以在程序执行期间使用,也可以在 core 文件中使用,因此对于复杂的程序,可以在程序运行时跟踪它是如何转到函数的。
连接到其它进程
除了调试 core 文件或程序之外,gdb 还可以连接到已经运行的进程(它的程序已经过编译,并加入了调试信息),并中断该进程。只需用希望 gdb 连接的进程标识替换 core 文件名就可以执行此操作。以下是一个执行循环并睡眠的 示例程序:
eg2 示例代码
#include int main(int argc, char *argv[]) { int i; for(i = 0; i < 60; i++) { sleep(1); } return 0; }
使用 'gcc -g eg2.c -o eg2' 编译该程序并使用 './eg2 &' 运行该程序。请留意在启动该程序时在背景上打印的进程标识,在本例中是 1283:
./eg2 & [3] 1283
启动 gdb 并指定进程标识,在我举的这个例子中是 'gdb eg2 1283'。gdb 会查找一个叫作 "1283" 的 core 文件。如果没有找到,那么只要进程 1283 正在运行(在本例中可能在 sleep() 中),gdb 就会连接并中断该进程:
... /home/seager/gdb/1283: No such file or directory. Attaching to program: /home/seager/gdb/eg2, Pid 1283 ... 0x400a87f1 in __libc_nanosleep () from /lib/libc.so.6 (gdb)
此时,可以发出所有常用 gdb 命令。可以使用 'backtrace' 来查看当前位置与 main() 的相对关系,以及 mian() 的帧号是什么,然后切换到 main() 所在的帧,查看已经在 "for" 循环中运行了多少次:
(gdb) backtrace #0 0x400a87f1 in __libc_nanosleep () from /lib/libc.so.6 #1 0x400a877d in __sleep (seconds=1) at ../sysdeps/unix/sysv/linux/sleep.c:78 #2 0x80483ef in main (argc=1, argv=0xbffff9c4) at eg2.c:7 (gdb) frame 2 #2 0x80483ef in main (argc=1, argv=0xbffff9c4) at eg2.c:7 7 sleep(1); (gdb) print i $1 = 50
如果已经完成了对程序的修改,可以 'detach' 命令继续执行程序,或者 'kill' 命令杀死进程。还可以首先使用 'file eg2' 装入文件,然后发出 'attach 1283' 命令连接到进程标识 1283 下的 eg2。
其它小技巧
gdb 可以让您通过使用 shell 命令在不退出调试环境的情况下运行 shell 命令,调用形式是 'shell [commandline]',这有助于在调试时更改源代码。
最后,在程序运行时,可以使用 'set ' 命令修改变量的值。在 gdb 下再次运行 eg1,使用命令 'break 7 if diff==0' 在第 7 行(将在此处计算结果)设置条件断点,然后运行程序。当 gdb 中断执行时,可以将 "diff" 设置成非零值,使程序继续运行直至结束:
Breakpoint 1, wib (no1=8, no2=8) at eg1.c:7 7 result = no1 / diff; (gdb) print diff $1 = 0 (gdb) set diff=1 (gdb) continue Continuing. 0 wibed by 16 equals 10 Program exited normally.
使用 gdb 抓取进程Stack Trace
[root@centos ~]# ps -ef|grep nginx
root 1348 1 0 12:01 ? 00:00:00 nginx: master process /usr/local/nginx/sbin/nginx
nobody 1350 1348 0 12:01 ? 00:00:00 nginx: worker process
root 2457 2223 0 12:05 pts/0 00:00:00 grep nginx
[root@centos ~]# gdb /usr/local/nginx/sbin/nginx 1350
GNU gdb (GDB) Red Hat Enterprise Linux (7.2-60.el6)
Copyright (C) 2010 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show copying"
and "show warranty" for details.
This GDB was configured as "i686-redhat-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/local/nginx/sbin/nginx...done.
Attaching to program: /usr/local/nginx/sbin/nginx, process 1350
Reading symbols from /lib/libpthread.so.0...(no debugging symbols found)...done.
[Thread debugging using libthread_db enabled]
Loaded symbols for /lib/libpthread.so.0
Reading symbols from /lib/libcrypt.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib/libcrypt.so.1
Reading symbols from /lib/libc.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib/ld-linux.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/libfreebl3.so...(no debugging symbols found)...done.
Loaded symbols for /lib/libfreebl3.so
Reading symbols from /lib/libdl.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /lib/libnss_files.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/libnss_files.so.2
0x00399416 in __kernel_vsyscall ()
Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.132.el6_5.2.i686 nss-softokn-freebl-3.12.9-11.el6.i686
(gdb) bt
#0 0x00399416 in __kernel_vsyscall ()
#1 0x00a055c8 in __epoll_wait_nocancel () from /lib/libc.so.6
#2 0x08066d18 in ngx_epoll_process_events (cycle=0x946eeb8, timer=53791, flags=1) at src/event/modules/ngx_epoll_module.c:579
#3 0x0805fd41 in ngx_process_events_and_timers (cycle=0x946eeb8) at src/event/ngx_event.c:248
#4 0x08065add in ngx_worker_process_cycle (cycle=0x946eeb8, data=0x0) at src/os/unix/ngx_process_cycle.c:816
#5 0x080643a4 in ngx_spawn_process (cycle=0x946eeb8, proc=0x8065a26 <ngx_worker_process_cycle>, data=0x0, name=0x80c153a "worker process", respawn=-3)
at src/os/unix/ngx_process.c:198
#6 0x08064fbf in ngx_start_worker_processes (cycle=0x946eeb8, n=1, type=-3) at src/os/unix/ngx_process_cycle.c:364
#7 0x08066035 in ngx_master_process_cycle (cycle=0x946eeb8) at src/os/unix/ngx_process_cycle.c:136
#8 0x0804b38d in main (argc=1, argv=0xbfba0114) at src/core/nginx.c:407
(gdb) n
Single stepping until exit from function __kernel_vsyscall,
which has no line number information.
0x00a055c8 in __epoll_wait_nocancel () from /lib/libc.so.6
(gdb)
使用 GNU profiler 来提高代码运行速度
各种软件对于性能的需求可能会有很大的区别,但是很多应用程序都有非常严格的性能需求,这一点并不奇怪。电影播放器就是一个很好的例子:如果一个电影播放器只能以所需要速度的 75% 来播放电影,那么它几乎就没什么用处了。
其他应用程序(例如视频编码)如果是耗时非常长的操作,最好以 “批处理” 任务的方式运行,此时启动一个作业,让其一直运行,然后我们就可以去干别的事情了。尽管这些类型的应用程序没有这种硬性性能指标的限制,但是提高速度仍然会带来很多好处,例如可以在给定的时间内可以对更多电影进行编码,在同样的时间内可以以更高的品质进行编码。
通常,除了最简单的应用程序之外,对于其他应用程序来说,性能越好,这个应用程序的用处就越大,也就会越流行。由于这个原因,性能考虑是(也应该是)很多应用程序开发人员脑袋中的第一根弦。
不幸的是,很多尝试让应用程序速度更快的努力都白费了,因为开发人员通常都是对自己的软件进行一些小型的优化,而没有去研究程序在更大的范围内是如何操作的。例如,我们可能会花费大量的时间来让某个特定函数的运行速度达到原来的两倍,这一点非常不错,但是如果这个函数很少被调用(例如打开文件),那么将这个函数的执行时间从 200ms 减少到 100ms,对于整个软件的总体执行时间来说并不会有太大的影响。
有效地利用您的时间的方法是,尽量优化软件中被频繁调用的部分。例如,假设应用程序花了 50% 的时间在字符串处理函数上,如果可以对这些函数进行优化,提高 10% 的效率,那么应用程序的总体执行时间就会改进 5%。
因此,如果希望能够有效地对程序进行优化,那么精确地了解时间在应用程序中是如何花费的,以及真实的输入数据,这一点非常重要。这种行为就称为代码剖析(code profiling)。本文将简要介绍 GNU 编译器工具包所提供的一种剖析工具,它的名字让人可以产生无限遐想,叫 GNU profiler(gprof)。本文主要面向那些开放源码软件开发工具的新手。
gprof 来救援了
在开始介绍如何使用 gprof 之前,需要首先了解一下在整个开发周期中,剖析应该在何处进行。通常来说,编写代码应该有 3 个目标,按照重要性的次序分别如下所示:
- 保证软件可以正确地工作。这通常是开发过程的重点。通常,如果一个软件根本连我们期望它做的事情都实现不了,那么即使它运行速度非常快,也根本没有任何意义!显然,正确性在某些情况下可能并不是至关重要的;例如,如果一个电影播放器可以正确地播放 99% 的电影文件,但是偶然会有些显示问题,那它依然可以使用。但是通常来说,正确性要远远比速度更加重要。
- 保证软件是可维护的。这实际上是第一个目标的一个子项。通常,如果软件编写得可维护性不好,那么即使它最开始时可以很好地工作,很快您(或其他人)在修正 bug 或添加新特性时可能也会破坏程序的正确性。
- 让软件可以快速运行。这就是剖析的用武之地。当软件可以正确运行之后,我们就可以开始剖析的过程来帮助它更快地运行了。
假设我们现在已经有了一个可以工作的应用程序,接下来让我们来看一下如何使用 gprof 来精确测量应用程序执行过程中时间都花费到什么地方去了,这样做的目的是了解一下在什么地方进行优化效果最佳。
gprof 可以对 C、C++、Pascal 和 Fortran 77 应用程序进行剖析。本文中的例子使用的是 C。
清单 1. 耗时的应用程序示例
#include <stdio.h> int a(void) { int i=0,g=0; while(i++<100000) { g+=i; } return g; } int b(void) { int i=0,g=0; while(i++<400000) { g+=i; } return g; } int main(int argc, char** argv) { int iterations; if(argc != 2) { printf("Usage %s <No of Iterations>\n", argv[0]); exit(-1); } else iterations = atoi(argv[1]); printf("No of iterations = %d\n", iterations); while(iterations--) { a(); b(); } }
正如我们从代码中可以看到的,这个非常简单的应用程序包括两个函数:a
和 b
,它们都处于一个繁忙的循环中消耗 CPU 周期。main
函数中采用了一个循环来反复调用这两个函数。第二个函数 b
循环的次数是 a
函数的 4 倍,因此我们期望在对代码分析完之后,可以看出大概有 20% 的时间花在了 a
函数中,而 80% 的时间花在了 b
函数中。下面就开始剖析代码,并看一下我们的这些期望是否正确。
启用剖析非常简单,只需要在 gcc 编译标志中加上 -pg
即可。编译方法如下:
gcc example1.c -pg -o example1 -O2 -lc
在编译好这个应用程序之后,可以按照普通方式运行这个程序:
./example1 50000
当这个程序运行完之后,应该会看到在当前目录中新创建了一个文件 gmon.out。
使用输出结果
首先看一下 “flat profile”,我们可以使用 gprof
命令获得它,这需要为其传递可执行文件和 gmon.out 文件作为参数,如下所示:
gprof example1 gmon.out -p
这会输出以下内容:
清单 2. flat profile 的结果
Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls ms/call ms/call name 80.24 63.85 63.85 50000 1.28 1.28 b 20.26 79.97 16.12 50000 0.32 0.32 a
从这个输出结果中可以看到,正如我们期望的一样,b
函数所花费的时间大概是 a
函数所花费的时间的 4 倍。真正的数字并不是十分有用;由于取整舍入错误,这些数字可能并不是非常精确。
聪明的读者可能会注意到,很多函数调用(例如 printf
)在这个输出中都没有出现。这是因为这些函数都是在 C 运行时库(libc.so)中的,(在本例中)它们都没有使用 -pg
进行编译,因此就没有对这个库中的函数收集剖析信息。稍后我们会回到这个问题上来。
接下来我们希望了解的是 “call graph”,这可以通过下面的方式获得:
gprof example1 gmon.out -q
这会输出下面的结果。
清单 3. Call graph
Call graph (explanation follows) granularity: each sample hit covers 2 byte(s) for 0.01% of 79.97 seconds index % time self children called name <spontaneous> [1] 100.0 0.00 79.97 main [1] 63.85 0.00 50000/50000 b [2] 16.12 0.00 50000/50000 a [3] ----------------------------------------------- 63.85 0.00 50000/50000 main [1] [2] 79.8 63.85 0.00 50000 b [2] ----------------------------------------------- 16.12 0.00 50000/50000 main [1] [3] 20.2 16.12 0.00 50000 a [3] -----------------------------------------------
最后,我们可能会希望获得一个 “带注解的源代码” 清单,它会将源代码输出到应用程序中,并加上每个函数被调用了多少次的注释。
要使用这种功能,请使用启用调试功能的标志来编译源代码,这样源代码就会被加入可执行程序中:
gcc example1.c -g -pg -o example1 -O2 -lc
像以前一样重新运行这个应用程序:
./example1 50000
gprof
命令现在应该是:
gprof example1 gmon.out -A
这会输出下面的结果:
清单 4. 带注释的源代码
*** File /home/martynh/profarticle/example1.c: #include <stdio.h> 50000 -> int a(void) { int i=0,g=0; while(i++<100000) { g+=i; } return g; } 50000 -> int b(void) { int i=0,g=0; while(i++<400000) { g+=i; } return g; } int main(int argc, char** argv) ##### -> { int iterations; if(argc != 2) { printf("Usage %s <No of Iterations>\n", argv[0]); exit(-1); } else iterations = atoi(argv[1]); printf("No of iterations = %d\n", iterations); while(iterations--) { a(); b(); } } Top 10 Lines: Line Count 3 50000 11 50000 Execution Summary: 3 Executable lines in this file 3 Lines executed 100.00 Percent of the file executed 100000 Total number of line executions 33333.33 Average executions per line
共享库的支持
正如在前面曾经介绍的,对于代码剖析的支持是由编译器增加的,因此如果希望从共享库(包括 C 库 libc.a)中获得剖析信息,就需要使用 -pg
来编译这些库。幸运的是,很多发行版都提供了已经启用代码剖析支持而编译的 C 库版本(libc_p.a)。
在我使用的发行版 gentoo 中,需要将 “profile” 添加到 USE 标志中,并重新执行 emerge
glibc。当这个过程完成之后,就会看到 /usr/lib/libc_p.a 文件已经创建好了。对于没有按照标准提供 libc_p 的发行版本来说,需要检查它是否可以单独安装,或者可能需要自己下载 glibc 的源代码并进行编译。
在获得 libc_p.a 文件之后,就可以简单地重新编译前面的例子了,方法如下:
gcc example1.c -g -pg -o example1 -O2 -lc_p
然后,可以像以前一样运行这个应用程序,并获得 flat profile 或 call graph,应该会看到很多 C 运行函数,包括 printf
(这些函数在我们的测试函数中并不是太重要)。
用户时间与内核时间
现在我们已经知道如何使用 gprof 了,接下来可以简单且有效地对应用程序进行分析了,希望可以消除性能瓶颈。
不过现在您可能已经注意到了 gprof 的最大缺陷:它只能分析应用程序在运行 过程中所消耗掉的用户 时间。通常来说,应用程序在运行时既要花费一些时间来运行用户代码,也要花费一些时间来运行 “系统代码”,例如内核系统调用。
如果对清单 1 稍加修改,就可以清楚地看出这个问题:
清单 5. 为清单 1 添加系统调用分析功能
#include <stdio.h> int a(void) { sleep(1); return 0; } int b(void) { sleep(4); return 0; } int main(int argc, char** argv) { int iterations; if(argc != 2) { printf("Usage %s <No of Iterations>\n", argv[0]); exit(-1); } else iterations = atoi(argv[1]); printf("No of iterations = %d\n", iterations); while(iterations--) { a(); b(); } }
正如您可以看到的,我们对清单 1 中的代码进行了修改,现在 a
函数和 b
函数不再只处理繁忙的循环了,而是分别调用 C 运行时函数 sleep
来挂起执行 1 秒和 4 秒。
像以前一样编译这个应用程序:
gcc example2.c -g -pg -o example2 -O2 -lc_p
并让这个程序循环 30 次:
./example2 30
所生成的 flat profile 如下所示:
清单 6. flat profile 显示了系统调用的结果
Flat profile: Each sample counts as 0.01 seconds. no time accumulated % cumulative self self total time seconds seconds calls Ts/call Ts/call name 0.00 0.00 0.00 120 0.00 0.00 sigprocmask 0.00 0.00 0.00 61 0.00 0.00 __libc_sigaction 0.00 0.00 0.00 61 0.00 0.00 sigaction 0.00 0.00 0.00 60 0.00 0.00 nanosleep 0.00 0.00 0.00 60 0.00 0.00 sleep 0.00 0.00 0.00 30 0.00 0.00 a 0.00 0.00 0.00 30 0.00 0.00 b 0.00 0.00 0.00 21 0.00 0.00 _IO_file_overflow 0.00 0.00 0.00 3 0.00 0.00 _IO_new_file_xsputn 0.00 0.00 0.00 2 0.00 0.00 _IO_new_do_write 0.00 0.00 0.00 2 0.00 0.00 __find_specmb 0.00 0.00 0.00 2 0.00 0.00 __guard_setup 0.00 0.00 0.00 1 0.00 0.00 _IO_default_xsputn 0.00 0.00 0.00 1 0.00 0.00 _IO_doallocbuf 0.00 0.00 0.00 1 0.00 0.00 _IO_file_doallocate 0.00 0.00 0.00 1 0.00 0.00 _IO_file_stat 0.00 0.00 0.00 1 0.00 0.00 _IO_file_write 0.00 0.00 0.00 1 0.00 0.00 _IO_setb 0.00 0.00 0.00 1 0.00 0.00 ____strtol_l_internal 0.00 0.00 0.00 1 0.00 0.00 ___fxstat64 0.00 0.00 0.00 1 0.00 0.00 __cxa_atexit 0.00 0.00 0.00 1 0.00 0.00 __errno_location 0.00 0.00 0.00 1 0.00 0.00 __new_exitfn 0.00 0.00 0.00 1 0.00 0.00 __strtol_internal 0.00 0.00 0.00 1 0.00 0.00 _itoa_word 0.00 0.00 0.00 1 0.00 0.00 _mcleanup 0.00 0.00 0.00 1 0.00 0.00 atexit 0.00 0.00 0.00 1 0.00 0.00 atoi 0.00 0.00 0.00 1 0.00 0.00 exit 0.00 0.00 0.00 1 0.00 0.00 flockfile 0.00 0.00 0.00 1 0.00 0.00 funlockfile 0.00 0.00 0.00 1 0.00 0.00 main 0.00 0.00 0.00 1 0.00 0.00 mmap 0.00 0.00 0.00 1 0.00 0.00 moncontrol 0.00 0.00 0.00 1 0.00 0.00 new_do_write 0.00 0.00 0.00 1 0.00 0.00 printf 0.00 0.00 0.00 1 0.00 0.00 setitimer 0.00 0.00 0.00 1 0.00 0.00 vfprintf 0.00 0.00 0.00 1 0.00 0.00 write
如果对这个输出结果进行分析,我们就会看到,尽管 profiler 已经记录了每个函数被调用的确切次数,但是为这些函数记录的时间(实际上是所有函数)都是 0.00。这是因为 sleep
函数实际上是执行了一次对内核空间的调用,从而将应用程序的执行挂起了,然后有效地暂停执行,并等待内核再次将其唤醒。由于花在用户空间执行的时间与花在内核中睡眠的时间相比非常小,因此就被取整成零了。其原因是 gprof 仅仅是通过以固定的周期对程序运行时间 进行采样测量来工作的。因此,当程序不运行时,就不会对程序进行采样测量。
这实际上是一把双刃剑。从一个方面来说,这使得有些程序非常难以进行优化,例如花费大部分时间在内核空间的程序,或者由于外部因素(例如操作系统的 I/O 子系统过载)而运行得非常慢的程序。从另一个方面来说,这意味着剖析不会受到系统中其他事件的影响(例如另外一个用户使用了大量的 CPU 时间)。
通常,有一个很好的基准测试可以用来查看 gprof 对于帮助对应用程序进行优化是多么有用,方法是在 time
命令下面执行它。这个命令会显示一个应用程序运行完成需要多少时间,并可以测量它在用户空间和内核空间各花费了多少时间。
如果查看一下清单 2 中的例子:
time ./example2 30
输出结果应该如下所示:
清单 7. time 命令的输出结果
No of iterations = 30 real 2m30.295s user 0m0.000s sys 0m0.004s
我们可以看出几乎没有多少时间被花费在执行用户空间的代码上,因此 gprof 在此处不会非常有用。
结束语
尽管 gprof 存在上面的限制,但是它对于优化代码来说依然是个非常有用的工具,如果您的代码大部分是用户空间 CPU 密集型的,它的用处就更加明显。首先使用 time
来运行程序从而判断 gprof 是否能产生有用信息是个好主意。
如果 gprof 不适合您的剖析需要,那么还有其他一些工具可以克服 gprof 部分缺陷,包括 OProfile 和 Sysprof (请参看 参考资料 中有关这些工具信息的链接)。
从另一个方面来说,假设我们已经安装了 gcc,gprof 相对于其他工具来说,一个主要的优点是很可能早已在 Linux 机器上安装了需要使用的工具。