日期:2014-05-16  浏览次数:20666 次

(转)Linux利器 strace
原文:http://www.perfgeeks.com/?p=501

今天才发现strace是个好东西呀
strace常用来跟踪进程执行时的系统调用和所接收的信号。 在Linux世界,进程不能直接访问硬件设备,当进程需要访问硬件设备(比如读取磁盘文件,接收网络数据等等)时,必须由用户态模式切换至内核态模式,通过系统调用访问硬件设备。strace可以跟踪到一个进程产生的系统调用,包括参数,返回值,执行消耗的时间。

strace使用参数
-p 跟踪指定的进程
-f 跟踪由fork子进程系统调用
-F 尝试跟踪vfork子进程系统调吸入,与-f同时出现时, vfork不被跟踪
-o filename 默认strace将结果输出到stdout。通过-o可以将输出写入到filename文件中
-ff 常与-o选项一起使用,不同进程(子进程)产生的系统调用输出到filename.PID文件
-r 打印每一个系统调用的相对时间
-t 在输出中的每一行前加上时间信息。 -tt 时间确定到微秒级。还可以使用-ttt打印相对时间
-v 输出所有系统调用。默认情况下,一些频繁调用的系统调用不会输出
-s 指定每一行输出字符串的长度,默认是32。文件名一直全部输出
-c 统计每种系统调用所执行的时间,调用次数,出错次数。
-e expr 输出过滤器,通过表达式,可以过滤出掉你不想要输出

应用场景
#1.跟踪你的web服务器系统调用
系统调用优化,也是web性能优化的一个较为重要的方向,尤其是在I/O密集型web应用的情况。我们这里的测试环境是CentOS5.4+Nginx+FastCGI。

<?php
//file:hello.php
define('DOCUMENT_ROOT', dirname(__FILE__));
include("hello.inc");
include("./hello.inc");
include(DOCUMENT_ROOT . "/hello.inc");
?>
#strace -f -F -o strace_nginx strace /wwwchroot/nginx/sbin/nginx -c /wwwchroot/nginx/nginx.conf
... (有部分不重要的数据影响排版,在这里使用...代替)
//--接受来自客户端的http请求
4165  recv(16, "GET /hello.php HTTP/1.1\r\nHost: f"..., 32768, 0) = 391
4165  epoll_ctl(9, EPOLL_CTL_MOD, 16, {EPOLLIN|EPOLLOUT|EPOLLET, {u32=3081162952, u64=698098541354471624}}) = 0
//--进行DNS查找
4165  getsockname(16, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("222.73.211.214")}, [16]) = 0
//--新建一个socket,连接Fast-CGI,端口号为9000
4165  socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 17
4165  ioctl(17, FIONBIO, [1])           = 0
4165  epoll_ctl(9, EPOLL_CTL_ADD, 17, {EPOLLIN|EPOLLOUT|EPOLLET, {u32=3081163048, u64=697886249710965032}}) = 0
4165  connect(17, {sa_family=AF_INET, sin_port=htons(9000), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 )
4165  epoll_wait(9, {{EPOLLOUT, {u32=3081163048, u64=697886249710965032}}, {...}, 5\
12, 300000) = 2
4165  gettimeofday({1295420285, 130967}, NULL) = 0
4165  recv(16, 0xbfdd7d8b, 1, MSG_PEEK) = -1 EAGAIN (Resource temporarily unavailable)
4165  getsockopt(17, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
//--将用户http请求交给Fast-CGI
4165  writev(17, [{"\1\1\0\1\0\10\0\0\0\1\0\0\0\0\0\0\1\4\0\1\3\30\0\0\21\7GATEWA"..., 832}], 1) = 832
4165  epoll_wait(9, {{EPOLLIN|EPOLLOUT, {u32=3081163048, u64=697886249710965032}}}, 512, 300000) = 1
4165  gettimeofday({1295420285, 131559}, NULL) = 0
//--接收Fast-CGI响应
4165  recv(17, "\1\6\0\1\0V\2\0X-Powered-By: PHP/5.2.10"..., 65536, 0) = 112
4165  readv(17, [{"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 65424}], 1) = 0
4165  mmap2(NULL, 274432, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7514000
4165  close(17)                         = 0
4165  munmap(0xb7514000, 274432)        = 0
//-- 响应客户端http请求,即http响应
4165  writev(16, [{"HTTP/1.1 200 OK\r\nServer: nginx/0"..., 228}, {"22\r\n", 4}, ..., 5) = 273
4165  write(5, "116.66.34.82 - - [19/Jan/2011:14"..., 191) = 191
4165  setsockopt(16, SOL_TCP, TCP_NODELAY, [1], 4) = 0
4165  recv(16, 0x9b024e8, 32768, 0)     = -1 EAGAIN (Resource temporarily unavailable)
...

通过这些,我们只能够大概地了解,Nginx这里启用了epoll。同时,还可以了解到Nginx和Fast-CGI底层是如何运作的。奇怪,hello.php文件中有三个inclue,即加载了三次文件,这里没有看到相应的i/o逻辑操作,是为什么呢?这是因为,Nginx并没解析处理PHP脚本,而是交给Fast-CGI去做这部事情了。

#strace -f -F -o php-cgi-strace /wwwchroot/php/bin/php-cgi --fpm-config /wwwchroot/php/etc/php-fpm.conf
//--接收来自Nginx发出的请求
4510  <... accept resumed> {sa_family=AF_INET, si