PHP執(zhí)行跟蹤工具phptrace介紹2017

　　phptrace 是一個追蹤（trace）PHP執(zhí)行流程的工具，你如果用過strace的話，則可能很容易想到phptrace到底實現(xiàn)了什么樣的功能。其實，phptrace是類strace的一個實現(xiàn)，不同的是，strace用來追蹤系統(tǒng)調(diào)用，而phptrace用來追蹤PHP函數(shù)調(diào)用。無論是開發(fā)測試還是線上追查問題，代碼執(zhí)行流程往往會提供許多有用的信息；

　　對于系統(tǒng)函數(shù)，我們可以用strace來觀察其調(diào)用信息，然而PHP卻長久以來缺少這么一個行之有效的工具，因此我們開發(fā)了phptrace。

　　phptrace 目前包括兩部分功能：

　　1. 打印當(dāng)前PHP調(diào)用棧。

　　2. 實時追蹤PHP調(diào)用。

　　地址：https://github.com/Qihoo360/phptrace

　　打印當(dāng)前PHP進程調(diào)用棧

　　C程序的調(diào)用棧，我們通過pstack或gdb可以很容易獲取到。PHP作為一種非編譯型的語言，實際運行在C編寫的PHP虛擬機之上。當(dāng)我們用pstack 或 gdb來打印PHP的調(diào)用棧時，實際是打印的虛擬機的執(zhí)行信息。

　　比如：

　　$ 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虛擬機調(diào)用棧，然而對于一個PHP開發(fā)者來說，更感興趣的是PHP的調(diào)用棧，你可以通過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 參數(shù)指定進程pid， -s表示我們需要獲取stack信息； -p參數(shù)是必需的，并且只能是PHP相關(guān)進程（php,php-cli,php-fpm）的pid，這很好理解，因為我們獲取的是PHP的調(diào)用信息。-s 如果省略，則phptrace不會打印調(diào)用棧，而是實時獲取PHP函數(shù)執(zhí)行流程，即phptrace的第二個功能，也是其主要功能�，F(xiàn)在我們?nèi)匀换氐絪tack上來。

　　程序輸出的第一行，是版本信息，第二行顯示了其進程PID，第三行是當(dāng)前執(zhí)行的PHP腳本，從第四行開始就是調(diào)用棧信息，從打印的信息可以看出，最外層run函數(shù)調(diào)用了say函數(shù)，最終調(diào)用了sleep函數(shù)。這時我們curl訪問以下這個php腳本，顯然會被堵塞住：

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

　　我們知道，block.php在sleep，但是我們卻不知道其到底要sleep多長時間，如果能獲取到sleep的參數(shù)，問題便迎刃而解了，這時，就需要用到我們的第二個功能：實施追蹤PHP調(diào)用。

　　實時追蹤PHP調(diào)用(trace)

　　trace功能依賴于我們實現(xiàn)的PHP模塊，模塊作為后端實時獲取PHP調(diào)用信息，前端程序phptrace則解析并打印調(diào)用信息，因此，在使用這個功能之前需要先安裝phptrace擴展。安裝擴展后，重啟fpm，并打開trace。

　　$ phptrace -p 3130

　　curl http://localhost:8804/block.php   #重新訪問block.php

　　phptrace 打印：

　　1417486170.247324 run(<Null>)

　　1417486170.247336     say($msg = "hello world")

　　1417486170.247356         sleep($seconds = "3600")

　　可以看到-p執(zhí)行PID后，默認執(zhí)行的就是trace功能，輸出的第一列為函數(shù)調(diào)用的時間，后面則是調(diào)用信息，phptrace按照PHP調(diào)用順序，依此打出run, say, sleep;此時，我們可以看到sleep的參數(shù)為3600s，因此curl請求要在1小時后才能返回。

　　實際上phptrace還可以打印函數(shù)返回值及調(diào)用耗時，，由于run，say，sleep函數(shù)都沒有返回，在上面的例子中無法看到這個效果，我們改一下代碼，使其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函數(shù)的調(diào)用信息，后三行則表明了對應(yīng)函數(shù)的返回值以及調(diào)用耗時：sleep 返回0 ，耗時1.000100s， say 返回 "hello world"，耗時1.000122s，之所以這么長時間，是因為其調(diào)用了sleep函數(shù)，同樣run 返回nil，及沒有返回值，耗時1.000135s。

【PHP執(zhí)行跟蹤工具phptrace介紹】相關(guān)文章：

php外部執(zhí)行命令函數(shù)10-10

PHP執(zhí)行Linux系統(tǒng)命令函數(shù)的方法10-17

PHP的變量的介紹08-15

幾種流行PHP集成開發(fā)工具的比較09-10

政策執(zhí)行情況跟蹤審計方法10-08

php在服務(wù)器執(zhí)行exec命令失敗的解決方法-php技巧09-08

如何在dos命令下執(zhí)行PHP文件09-14

php定時執(zhí)行任務(wù)的設(shè)置方法參考07-01

介紹PHP Hash算法06-16

PHP的基本語法的介紹10-08