网站首页 语言 会计 电脑 医学 资格证 职场 文艺体育 范文

PHP执行跟踪工具phptrace介绍2017

栏目: 网页设计 / 发布于: / 人气:1.51W

phptrace 是一个追踪(trace)PHP执行流程的工具,你如果用过strace的话,则可能很容易想到phptrace到底实现了什么样的功能。其实,phptrace是类strace的一个实现,不同的是,strace用来追踪系统调用,而phptrace用来追踪PHP函数调用。无论是开发测试还是线上追查问题,代码执行流程往往会提供许多有用的信息;

PHP执行跟踪工具phptrace介绍2017

对于系统函数,我们可以用strace来观察其调用信息,然而PHP却长久以来缺少这么一个行之有效的工具,因此我们开发了phptrace。

  phptrace 目前包括两部分功能:

1. 打印当前PHP调用栈。

2. 实时追踪PHP调用。

地址:

  打印当前PHP进程调用栈

C程序的调用栈,我们通过pstack或gdb可以很容易获取到。PHP作为一种非编译型的语言,实际运行在C编写的PHP虚拟机之上。当我们用pstack 或 gdb来打印PHP的调用栈时,实际是打印的虚拟机的执行信息。

比如:

$ pstack 3130

#0 0x00000035ee6accc0 in __nanosleep_nocancel () from /lib64/.6

#1 0x00000035ee6acb50 in sleep () from /lib64/.6

#2 0x0000000000714f23 in zif_sleep ()

#3 0x00000000008e36cd in execute_internal ()

#4 0x00007f27b38b2b77 in phptrace_execute_core () from /home/renyongquan/opt/php5.4.35/lib/php/extensions/debug-non-zts-20100525/

#5 0x00007f27b38b2c04 in phptrace_execute_internal () from /home/renyongquan/opt/php5.4.35/lib/php/extensions/debug-non-zts-20100525/

#6 0x00000000008e44bc in zend_do_fcall_common_helper_SPEC ()

3130 为php-fpm的进程ID,通过pstack我们看到了PHP虚拟机调用栈,然而对于一个PHP开发者来说,更感兴趣的是PHP的调用栈,你可以通过phptrace获取:

$ ./phptrace -p 3130 -s

phptrace 0.1 demo, published by infra webcore team

process id = 3130

script_filename = /home/renyongquan/opt/nginx//webapp/

[0x7f27b9a99dc8] sleep /home/renyongquan/opt/nginx/webapp/:6

[0x7f27b9a99d08] say /home/renyongquan/opt/nginx/webapp/:3

[0x7f27b9a99c50] run /home/renyongquan/opt/nginx/webapp/

-p 参数指定进程pid, -s表示我们需要获取stack信息; -p参数是必需的`,并且只能是PHP相关进程(php,php-cli,php-fpm)的pid,这很好理解,因为我们获取的是PHP的调用信息。-s 如果省略,则phptrace不会打印调用栈,而是实时获取PHP函数执行流程,即phptrace的第二个功能,也是其主要功能。现在我们仍然回到stack上来。

程序输出的第一行,是版本信息,第二行显示了其进程PID,第三行是当前执行的PHP脚本,从第四行开始就是调用栈信息,从打印的信息可以看出,最外层run函数调用了say函数,最终调用了sleep函数。这时我们curl访问以下这个php脚本,显然会被堵塞住:

curl http://localhost:8804/

我们知道,在sleep,但是我们却不知道其到底要sleep多长时间,如果能获取到sleep的参数,问题便迎刃而解了,这时,就需要用到我们的第二个功能:实施追踪PHP调用。

  实时追踪PHP调用(trace)

trace功能依赖于我们实现的PHP模块,模块作为后端实时获取PHP调用信息,前端程序phptrace则解析并打印调用信息,因此,在使用这个功能之前需要先安装phptrace扩展。安装扩展后,重启fpm,并打开trace。

$ phptrace -p 3130

curl http://localhost:8804/ #重新访问

phptrace 打印:

1417486170.247324 run(<Null>)

1417486170.247336 say($msg = "hello world")

1417486170.247356 sleep($seconds = "3600")

可以看到-p执行PID后,默认执行的就是trace功能,输出的第一列为函数调用的时间,后面则是调用信息,phptrace按照PHP调用顺序,依此打出run, say, sleep;此时,我们可以看到sleep的参数为3600s,因此curl请求要在1小时后才能返回。

实际上phptrace还可以打印函数返回值及调用耗时,,由于run,say,sleep函数都没有返回,在上面的例子中无法看到这个效果,我们改一下代码,使其sleep 1s :

$ ./phptrace -p 2459

1417506346.727223 run(<Null>)

1417506346.727232 say($msg = "hello world")

1417506346.727241 sleep($seconds = "1")

1417506347.727341 sleep => 0 1.000100

1417506347.727354 say => hello world 1.000122

1417506347.727358 run => nil 1.000135

输出的前三行跟上面的例子相同,仍然是PHP函数的调用信息,后三行则表明了对应函数的返回值以及调用耗时:sleep 返回0 ,耗时1.000100s, say 返回 "hello world",耗时1.000122s,之所以这么长时间,是因为其调用了sleep函数,同样run 返回nil,及没有返回值,耗时1.000135s。