#定位系统性能瓶颈#strace&ltrace


strace和ltrace分别对应的是系统调用和库函数调用, 系统调用实际上就是指最底层的一个调用,在linux程序设计里面就是底层调用的意思,面向的是硬件。 而库函数调用则面向的是应用开发的,相当于应用程序的api,常见的lib有openssl、libxml等。 前者属于内核层,后者属于用户层,下面有其层次对应图
引用《UNIX环境高级编程》对这两个概念的区别描述如下: 另一个可说明系统调用和库函数之间的差别的例子是, U N I X提供决定当前时间和日期的 界面。某些操作系统提供一个系统调用以返回时间,而另一个则返回日期。任何特殊的处理,
例如正常时制和夏时制之间的转换,由内核处理或要求人为干预。U N I X则不同,它只提供一
条系统调用,该系统调用返回国际标准时间1 9 7 0年1月1日零点以来所经过的秒数。对该值的
任何解释,例如将其变换成人们可读的,使用本地时区的时间和日期,都留给用户进程运行。
在标准C库中,提供了若干例程以处理大多数情况。这些库函数处理各种细节,例如各种夏时
制算法。
应用程序可以调用系统调用或者库函数,而很多库函数则会调用系统调用。这在图1 - 2中
显示。
系统调用和库函数之间的另一个差别是:系统调用通常提供一种最小界面,而库函数通常
提供比较复杂的功能。我们从s b r k系统调用和m a l l o c库函数之间的差别中可以看
到这一点,在以后当比较不带缓存的I / O函数(见第3章)以及标准I / O函数(见第5章)
时,还将看到这种差别。
进程控制系统调用( fork, exec和w a i t)通常由用户的应用程序直接调用(请回忆
程序1 - 5中的基本s h e l l)。但是为了简化某些常见的情况,U N I X系统也提供了一些库
函数;例如s y s t e m和p o p e n。8 . 1 2节将说明s y s t e m函数的一种实现,它使用基本的进
程控制系统调用。1 0 . 1 8节还将强化这一实例以正确地处理信号。
为使读者了解大多数程序员应用的U N I X系统界面,我们不得不既说明系统调用,只介绍某些库函数。
例如若只说明s b r k系统调用,那么就会忽略很多应用程序使用的m a l l o c库函数。
本书除了必须要区分两者时,都将使用术语函数( f u n c t i o n)来指代系统调用和库函数两者。
\



一般来说,进程是不能访问内核的。它不能访问内核所占内存空间也不能调用内核函数。CPU硬件决定了这些(这就是为什么它被称作"保护模式")。系统调用是这些规则的一个例外。其原理是进程先用适当的值填充寄存器,然后调用一个特殊的指令,这个指令会跳到一个事先定义的内核中的一个位置(当然,这个位置是用户进程可读但是不可写的)。在Intel CPU中,这个由中断0x80实现。硬件知道一旦你跳到这个位置,你就不是在限制模式下运行的用户,而是作为操作系统的内核--所以你就可以为所欲为。
进程可以跳转到的内核位置叫做sysem_call。这个过程检查系统调用号,这个号码告诉内核进程请求哪种服务。然后,它查看系统调用表(sys_call_table)找到所调用的内核函数入口地址。接着,就调用函数,等返回后,做一些系统检查,最后返回到进程(或到其他进程,如果这个进程时间用尽)。如果你希望读这段代码,它在<内核源码目录>/kernel/entry.S,Entry(system_call)的下一行。
为防止和正常的返回值混淆,系统调用并不直接返回错误码,而是将错误码放入一个名为errno的全局变量中。如果一个系统调用失败,你可以读出errno的值来确定问题所在。
errno不同数值所代表的错误消息定义在errno.h中,你也可以通过命令"man 3 errno"来察看它们。
需要注意的是,errno的值只在函数发生错误时设置,如果函数不发生错误,errno的值就无定义,并不会被置为0。另外,在处理errno前最好先把它的值存入另一个变量,因为在错误处理过程中,即使像printf()这样的函数出错时也会改变errno的值。

好吧,理论都说得差不多了,该看看怎么使用strace和ltrace 首先安装直接用命令
yum install strace ltrace

然后我会man一个命令的详细描述,因为man已经写得非常好,虽然是英语会影响阅读速度,但是与其看网络上3、4手的转载资料,还不如正正经经把官方man文档看一遍,这里把man的内容摘录下来不是为了增加本文文字长度,而是强迫读者把英文官方文档看一遍。
man strace
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 com-
mand ‘‘sleep 666’’ is:

sigsuspend([]
--- SIGINT (Interrupt) ---
+++ killed by SIGINT +++

If a system call is being executed and meanwhile another one is being called from a different thread/process
then strace will try to preserve the order of those events and mark the ongoing call as being unfinished. When
the call returns it will be marked as resumed.

[pid 28772] select(4, [3], NULL, NULL, NULL
[pid 28779] clock_gettime(CLOCK_REALTIME, {1130322148, 939977000}) = 0
[pid 28772] <... select resumed> ) = 1 (in [3])

Interruption of a (restartable) system call by a signal delivery is processed differently as kernel terminates
the system call and also arranges its immediate reexecution after the signal handler completes.

read(0, 0x7ffff72cf5cf, 1) = ? ERESTARTSYS (To be restarted)
--- SIGALRM (Alarm clock) @ 0 (0) ---
rt_sigreturn(0xe) = 0
read(0, ""..., 1) = 0
Arguments are printed in symbolic form with a passion. This example shows the shell performing ‘‘>>xyzzy’’
output redirection:

open("xyzzy", O_WRONLY|O_APPEND|O_CREAT, 0666) = 3

Here the three argument form of open is decoded by breaking down the flag argument into its three bitwise-OR
constituents and printing the mode value in octal by tradition. Where traditional or native usage differs from
ANSI or POSIX, the latter forms are preferred. In some cases, strace output has proven to be more readable
than the source.

Structure pointers are dereferenced and the members are displayed as appropriate. In all cases arguments are
formatted in the most C-like fashion possible. For example, the essence of the command ‘‘ls -l /dev/null’’ is
captured as:

lstat("/dev/null", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 3), ...}) = 0

Notice how the ‘struct stat’ argument is dereferenced and how each member is displayed symbolically. In par-
ticular, observe how the st_mode member is carefully decoded into a bitwise-OR of symbolic and numeric values.
Also notice in this example that the first argument to lstat is an input to the system call and the second
argument is an output. Since output arguments are not modified if the system call fails, arguments may not
always be dereferenced. For example, retrying the ‘‘ls -l’’ example with a non-existent file produces the fol-
lowing line:

lstat("/foo/bar", 0xb004) = -1 ENOENT (No such file or directory)

In this case the porch light is on but nobody is home.

Character pointers are dereferenced and printed as C strings. Non-printing characters in strings are normally
represented by ordinary C escape codes. Only the first strsize (32 by default) bytes of strings are printed;
longer strings have an ellipsis appended following the closing quote. Here is a line from ‘‘ls -l’’ where the
getpwuid library routine is reading the password file:

read(3, "root::0:0:System Administrator:/"..., 1024) = 422

While structures are annotated using curly braces, simple pointers and arrays are printed using square brackets
with commas separating elements. Here is an example from the command ‘‘id’’ on a system with supplementary
group ids:

getgroups(32, [100, 0]) = 2

On the other hand, bit-sets are also shown using square brackets but set elements are separated only by a
space. Here is the shell preparing to execute an external command:

sigprocmask(SIG_BLOCK, [CHLD TTOU], []) = 0

Here the second argument is a bit-set of two signals, SIGCHLD and SIGTTOU. In some cases the bit-set is so
full that printing out the unset elements is more valuable. In that case, the bit-set is prefixed by a tilde
like this:

sigprocmask(SIG_UNBLOCK, ~[], NULL) = 0

Here the second argument represents the full set of all signals.

好了,已经把man文档看了下来,strace的功能、用法也有了大概的了解,下面举用几个例子 例子1
[root@localhost ~]# strace ls
execve("/bin/ls", ["ls"], [/* 41 vars */]) = 0
brk(0)                                  = 0xe67000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f1176dfa000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=38574, ...}) = 0
mmap(NULL, 38574, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f1176df0000
close(3)                                = 0
open("/lib64/libselinux.so.1", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0PX`\312=\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=124624, ...}) = 0
mmap(0x3dca600000, 2221912, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3dca600000
mprotect(0x3dca61d000, 2093056, PROT_NONE) = 0
mmap(0x3dca81c000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1c000) = 0x3dca81c000
mmap(0x3dca81e000, 1880, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x3dca81e000
close(3)                                = 0
open("/lib64/librt.so.1", O_RDONLY)     = 3
由于输出内容比较长,我就不全部拷贝下来了,我们可以看看一个简单的ls命令,到底做了哪些系统调用 输出的内容很详细打印了一系列访问各种execve、mmap、access、open、close、read、fstat等系统调用,具体含义得好好看看《UNIX环境高级编程》
例子2 strace命令的-e选项仅仅被用来展示特定的系统调用(例如,open,write等等),-p选项用来指定pid的进程
strace -e 'select' -p 18846
Process 18846 attached - interrupt to quit
select(0, NULL, NULL, NULL, {0, 165000}) = 0 (Timeout)
select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
select(0, NULL, NULL, NULL, {1, 0})     = 0 (Timeout)
select(0, NULL, NULL, NULL, {1, 0} 
Process 18846 detached
上面的例子是对18846进程的select调用的显示,这个功能可以很方便的定位调用的方法

例子3
[root@localhost ~]# strace -o /tmp/a.txt -c hostname 
localhost
[root@localhost ~]# cat /tmp/a.txt 
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
  -nan    0.000000           0         5           read
  -nan    0.000000           0         1           write
  -nan    0.000000           0         6           open
  -nan    0.000000           0         6           close
  -nan    0.000000           0         7           fstat
  -nan    0.000000           0        15           mmap
  -nan    0.000000           0         7           mprotect
  -nan    0.000000           0         2           munmap
  -nan    0.000000           0         3           brk
  -nan    0.000000           0         1         1 access
  -nan    0.000000           0         1           execve
  -nan    0.000000           0         1           uname
  -nan    0.000000           0         1           statfs
  -nan    0.000000           0         1           arch_prctl
------ ----------- ----------- --------- --------- ----------------
100.00    0.000000                    57         1 total
-o选项是把输出到文件,-c选项是统计全部系统调用的耗时和次数,这也是非常实用的功能

还有-t是显示时间戳也是非常实用的选项,这里的例子几乎包括了最实用的方法,定位系统瓶颈的基本方法就是使用strace追踪最忙进程的调用,可以先用-c把次数统计一下,或者用-e指定某种函数如open,看程序阻塞在哪个文件的IO调用

下面轮到ltrace 其实ltrace和strace的大同小异,前文说过ltrace是检测库函数调用的,我们还是按照惯例先看man
DESCRIPTION
       ltrace  is  a  program  that  simply  runs the specified command until it exits.  It intercepts and records the
       dynamic library calls which are called by the executed process and the signals which are received by that  pro-
       cess.  It can also intercept and print the system calls executed by the program.

       Its use is very similar to strace(1).

它的man非常短,直接说和strace非常相似 例子1
[root@localhost ~]# ltrace ls
(0, 0, 0, 0x7fc84b52bac0, 88)                                                    = 0x3dc8c21160
__libc_start_main(0x408480, 1, 0x7fff73282908, 0x412110, 0x412100 
strrchr("ls", '/')                                                               = NULL
setlocale(6, "")                                                                 = "zh_CN.UTF-8"
bindtextdomain("coreutils", "/usr/share/locale")                                 = "/usr/share/locale"
textdomain("coreutils")                                                          = "coreutils"
__cxa_atexit(0x40bb20, 0, 0, 0x736c6974756572, 0x3dc958fee8)                     = 0
isatty(1)                                                                        = 1
getenv("QUOTING_STYLE")                                                          = NULL
getenv("LS_BLOCK_SIZE")                                                          = NULL
getenv("BLOCK_SIZE")                                                             = NULL
getenv("BLOCKSIZE")                                                              = NULL
getenv("POSIXLY_CORRECT")                                                        = NULL
getenv("BLOCK_SIZE")                                                             = NULL
getenv("COLUMNS")                                                                = NULL
ioctl(1, 21523, 0x7fff732827d0)                                                  = 0
getenv("TABSIZE")                                                                = NULL
getopt_long(1, 0x7fff73282908, "abcdfghiklmnopqrstuvw:xABCDFGHI:"..., 0x619040, 0x7fff732827e8) = -1
__errno_location()                                                               = 0x7fc84b5296a0
malloc(56)                                                                       = 0x104d050
memcpy(0x104d050, "", 56)                                                        = 0x104d050
和strace一样先拿ls来测试,可以看出很多库函数的调用如strrchr、setlocale、bindtextdomain等,具体含义可以利用网络搜索

其他选项如-e \ -c\ -p \ -t 等用法和strace一模一样,相当于学会了strace就学会了ltrace,所以本文把这两个工具结合起来一起讲。 它们的输出内容区别就是一个显示系统调用,另外一个显示库函数调用,大家可以写一段简单的c程序,分别用strace和ltrace探测一下,看其输出很容易debug出程序的问题, 多掌握一个工具,debug时可以轻松很多。


相关内容