phptrace 正式版发布啦！

经过小伙伴们的日夜奋斗，phptrace 正式发版了！趁元旦前快把线上的隐患抓出来吧：）

Github：https://github.com/Qihoo360/phptrace

问题反馈：g-infra-webcore@list.qihoo.net

---

介绍

phptrace 是一个追踪（trace）PHP执行流程的工具，你如果用过strace的话，则可能很容易想到phptrace到底实现了什么样的功能。 其实，phptrace是类strace的一个实现，不同的是，strace用来追踪系统调用，而phptrace用来追踪PHP函数调用。无论是开发测试 还是线上追查问题，代码执行流程往往会提供许多有用的信息，大大提高了开发人员的工作效率；对于系统函数，我们可以用strace 来观察其调用信息，然而PHP却长久以来缺少这么一个行之有效的工具，因此我们开发了phptrace。

phptrace 目前包括两部分功能：1. 打印当前PHP调用栈，2. 实时追踪PHP调用

1. 打印当前PHP进程调用栈

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

$ pstack 3130
#0  0x00000035ee6accc0 in __nanosleep_nocancel () from /lib64/libc.so.6
#1  0x00000035ee6acb50 in sleep () from /lib64/libc.so.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/phptrace.so
#5  0x00007f27b38b2c04 in phptrace_execute_internal () from /home/renyongquan/opt/php5.4.35/lib/php/extensions/debug-non-zts-20100525/phptrace.so
#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/block.php
[0x7f27b9a99dc8]  sleep /home/renyongquan/opt/nginx/webapp/block.php:6
[0x7f27b9a99d08]  say /home/renyongquan/opt/nginx/webapp/block.php:3
[0x7f27b9a99c50]  run /home/renyongquan/opt/nginx/webapp/block.php:10

-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/block.php

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

2. 实时追踪PHP调用（trace）

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

安装扩展后，重启fpm，并打开trace

$ phptrace -p 3130

重新访问block.php

curl http://localhost:8804/block.php  

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。

最后

这里举得例子很简单，因为我们的主要目的是展示phptrace的使用方法，以及phptrace可以为我们提供的信息。 后面，我们也会结合实际场景，分别展示phptrace，在开发，测试，以及线上排查问题时如何最大发挥其作用。

phptrace仅仅是一个工具，具体可以用在什么场景，我们考虑的也许不全面，如果你有任何使用心得或改进建议， 欢迎向我们反馈。

360 基础架构-web组件团队 邮箱：g-infra-webcore@list.qihoo.net