使用strace跟踪多进程程序

跑马溜溜的球

发布于 2020-12-07 15:31:43

3.2K0

文章被收录于专栏：日积月累1024日积月累1024

1. 简介

strace可以跟踪到一个进程产生的系统调用,包括参数，返回值，执行消耗的时间。

2. 常用参数

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

3. 跟踪多进程的实例

要跟踪的Taskdemo.php代码如下（即之前使用swoole实现的生产者消费者模型）。

<?php
require('./Schedule.php');
class Taskdemo extends Schedule{
    protected $_consumerNum = 1;
    protected function doProduce($worker){
        $all = 5;
        for($i=0; $i<$all; $i+=1){
            yield json_encode(array('data'=>$i));
        }
    }

    protected function doConsume($data, $worker){
        sleep(1);
        echo "consumer:{$worker->pid} recv {$data}\n";
    }
}

$t = new Taskdemo();
$t->run();

Schedule.php详见这里
为方便讲述，将消费者的个数设为1。

执行如下命令，开始跟踪

strace -ff -o task php Taskdemo.php

执行后我们得到三个文件

task.28203  task.28204  task.28205

熟悉代码的同学应该可以猜到，这三个文件分别对应主进程，生产者子进程和消费者子进程。下面我们分别来看下。 - task.28203（主进程，通常来说进程号最小的文件就是主进程对应的文件）

/*生成生产者和消费者进程各一个*/
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x2b6ea214c810) = 28204
clone(child_stack=0, clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x2b6ea214c810) = 28205

write(1, "msgqkey:1053566\n", 16) = 16

/*等待并回收子进程*/
epoll_wait(7, 3841680, 4096, 4294967295) = -1 EINTR (Interrupted system call)
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG, NULL) = 28204
write(1, "master clear pid:28204, code:0\n", 31) = 31
epoll_wait(7, 3841680, 4096, 4294967295) = -1 EINTR (Interrupted system call)
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG, NULL) = 28205
write(1, "master clear pid:28205, code:0\n", 31) = 31

task.28204 消费者进程

/*从消息队列中取数据，输出*/
msgrcv(7176192, 7176192{2, "{\"data\":0}\0\0\0\0\0\0R7\247r8\0\0\0HJ\325r8\0\0\0"...}, 8192, 0, 0) = 10
write(1, "consumer:28204 recv {\"data\":0}\n", 31) = 31
msgrcv(7176192, 7176192{2, "{\"data\":1}\0\0\0\0\0\0R7\247r8\0\0\0HJ\325r8\0\0\0"...}, 8192, 0, 0) = 10
write(1, "consumer:28204 recv {\"data\":1}\n", 31) = 31
msgrcv(7176192, 7176192{2, "{\"data\":2}\0\0\0\0\0\0R7\247r8\0\0\0HJ\325r8\0\0\0"...}, 8192, 0, 0) = 10
write(1, "consumer:28204 recv {\"data\":2}\n", 31) = 31
msgrcv(7176192, 7176192{2, "{\"data\":3}\0\0\0\0\0\0R7\247r8\0\0\0HJ\325r8\0\0\0"...}, 8192, 0, 0) = 10
write(1, "consumer:28204 recv {\"data\":3}\n", 31) = 31
msgrcv(7176192, 7176192{2, "{\"data\":4}\0\0\0\0\0\0R7\247r8\0\0\0HJ\325r8\0\0\0"...}, 8192, 0, 0) = 10
write(1, "consumer:28204 recv {\"data\":4}\n", 31) = 31
msgrcv(7176192, 7176192{1, "ALLDONE:4}\0\0\0\0\0\0R7\247r8\0\0\0HJ\325r8\0\0\0"...}, 8192, 0, 0) = 7
write(1, "consumer 28204 exit\n", 20) = 20

task.28205 生产者进程

write(1, "producer begin:\n", 16) = 16
/*向队列中放入任务*/
msgsnd(7176192, {2, "{\"data\":0}"}, 10, 0) = 0
msgsnd(7176192, {2, "{\"data\":1}"}, 10, 0) = 0
msgsnd(7176192, {2, "{\"data\":2}"}, 10, 0) = 0
msgsnd(7176192, {2, "{\"data\":3}"}, 10, 0) = 0
msgsnd(7176192, {2, "{\"data\":4}"}, 10, 0) = 0
/*放入完成标识*/
msgsnd(7176192, {1, "ALLDONE"}, 7, 0) = 0
/*标签队列长度*/
msgctl(7176192, IPC_STAT, 0x7fffd6dbedb0) = 0
/*删除队列*/
msgctl(7176192, IPC_RMID, 0) = 0

4. 另一个十分有用的功能参数-c

统计每种系统调用所执行的时间，调用次数，出错次数。

strace -c php Taskdemo.php

我们执行上面的命令，看下主进程进行的系统调用。

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 59.06    0.000857         429         2           clone
 10.34    0.000150           1       153           mmap
  6.20    0.000090           1       109        42 open
  3.72    0.000054           1        78           fstat
  3.72    0.000054           1        62           mprotect
  3.58    0.000052           2        33        27 stat
  3.51    0.000051           1        74           close
  3.45    0.000050           1        66           read
  2.14    0.000031           1        26           brk
  1.79    0.000026           7         4         1 wait4
  ... ...
  0.00    0.000000           0         1           epoll_create
  0.00    0.000000           0         2         2 epoll_wait
------ ----------- ----------- --------- --------- ----------------
100.00    0.001451                   754        82 total

各项含义如下： - % time：执行耗时占总时间百分比 - seconds：执行总时间 - usecs/call：单个命令执行时间 - calls：调用次数 - errors: 出错次数 - syscall: 系统调用

说明： - clone是主进程生成子进程时的系统调用。 - epoll_create， epoll_wait，wait4用于创建信号处理函数，回收僵尸子进程。

本文参与腾讯云自媒体同步曝光计划，分享自作者个人站点/博客。

原始发表：2017/02/14 ，如有侵权请联系 cloudcommunity@tencent.com 删除

linux

php

本文分享自作者个人站点/博客前往查看

如有侵权，请联系 cloudcommunity@tencent.com 删除。

本文参与腾讯云自媒体同步曝光计划，欢迎热爱写作的你一起参与！

linux

php

登录后参与评论

0 条评论

热度