PHP執行跟蹤工具phptrace介紹


PHP執行跟蹤工具phptrace介紹

phptrace簡介

phptrace 是一個追蹤(trace)PHP執行流程的工具,你如果用過strace的話,則可能很容易想到phptrace到底實現了什么樣的功能。其實,phptrace是類strace的一個實現,不同的是,strace用來追蹤系統調用,而phptrace用來追蹤PHP函數調用。無論是開發測試還是線上追查問題,代碼執行流程往往會提供許多有用的信息;

對於系統函數,我們可以用strace來觀察其調用信息,然而PHP卻長久以來缺少這么一個行之有效的工具,因此我們開發了phptrace。

 

phptrace 目前包括兩部分功能:
1. 打印當前PHP調用棧。
2. 實時追蹤PHP調用。
地址:https://github.com/Qihoo360/phptrace

 

 打印當前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調用。

 

 

實時追蹤PHP調用(trace)

trace功能依賴於我們實現的PHP模塊,模塊作為后端實時獲取PHP調用信息,前端程序phptrace則解析並打印調用信息,因此,在使用這個功能之前需要先安裝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執行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。

應用場景

1

開發環境下, 觀察php函數調用及參數

step 1:phptrace這個php-fpm的worker進程

./phptrace -p 10665

step 2:點擊進入logs目錄(會顯示出logs目錄下的文件)

step 3:查看到對應的php函數調用和參數

例如, opendir的參數為“/home/*/nginx_d”;

2

開發環境下debug

 

當要查看/home/**3 這個目錄時,顯示沒有文件?

 

根據trace結果可以發現,其實是打開目錄失敗。

 

 

這里舉了幾個簡單的例子,因為我們的主要目的是展示phptrace的使用方法,以及phptrace可以為我們提供的信息。phptrace在開發,測試,以及線上排查問題時可以幫助我們解決很多問題。


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM