PHP Profile research

カバレッジ計測も楽しんだことだし、がしがし作成。

一通り基本機能ができたのでこれらを使用するメイン関数を作成する。

問題なく動作する。こういうときはXUnitを使用していると気持ちがいい。

とりあえず規模を100倍にしてみる。

うん、帰ってこない。いきなり100倍は問題ありすぎたか。

とりあえず10倍。ちょっと遅いかな？って感じ。

さてどうしよう？心当たりはある。

あそこのアルゴリズムはO(n^2)だから多分あそこ。

けど本当にそうかはわからない。

こういうときにプロファイラーがあるといいんだけど。

早速調査。なんだPHPUnitの時に導入したXdebugがPHPのプロファイラーらしい。

PHP.iniに以下を追加。

xdebug.profiler_enable = 1
xdebug.profiler_output_name = cachegrind.out.%s
xdebug.profiler_output_dir = "c:\www\log"

ディレクトリはこのために作成。出力ファイル名はdefaultだとプロセス毎らしいのでとりあえずスクリプト毎に変更。webで動作するスクリプトの場合はapacheの再起動をすると反映される。以上で動作したが何がなにやらさっぱりわからないログができあがった。しかも12Mもある。

これじゃあ、役に立たないのでこれを視覚化してくれるソフトを探したらあった。wincachegrindってやつ。教えてくれたblogからリンク先へ移動してダウンロード。そしてインストール。そうしたらAd-Awareが「マルウエアを検出した」とのたまわった。一応ウイルスバスターでチェックはしたけど見逃したか?

---* Ad-Aware log* ---

Quarantined items:
Description: [fullpath].tmp Family Name: Win32.Monitor.PowerSpy Clean status: Success Item ID: 1375741 Family ID: 3283

いかにもな感じ。さてどうしよう。いったん再起動してプロセスを削除。考えられるのは以下の幾つかか。

１）blogが改ざんされて変なリンク先に飛んだ。

２）最近sourceforgeが改ざんされて変なファイルに改変された。

３）そもそも変なファイルがアップロードされて見逃された。

４）自分の使用しているDNSが汚染されて変なところに飛んだ。

５）Ad-Awareの誤検知。

５を除けば上から順番に可能性がありそう。そこでsourceforgeのtopへ行き、そこからwincachegrindのページへ移動。ダウンロード。先ほどダウンロードしたファイルと比較。サイズは1バイトたりとも異ならず、diffをとっても問題なし。はい1番はずれ。

wincachegrindは2006年あたりに更新されてそれから放置プレイの様子。であれば長期に変なファイルが存在する可能性も低いので3番を除外。

２，４番は本当に昨日今日の問題でなければ何かニュースになっているはず。チェックしてみたがそのようなニュースは見あたらない。よってひとまず除外。

５についてはさすがにwincachegrindで検出した人はいなかったが、昨日別のソフトで同じマルウエアを誤検知した人がいた様子。定義ファイルも同じ。(0149.0038)実に怪しい。そういうわけで定義ファイルを更新して(0149.0039)現在再チェック中。

ちなみにwincachegrindはちょっと使い方がわかりづらいけどlogを直接読むのに比べたら楽勝。原因となる関数も想定していたとおり。およそ全体の4割をそこで消費している。メモリを倍使用するけど、O(n)ぐらいですみそうなアルゴリズムへ変更しよう。目標は現在の使用時間の1/10。

こんな感じで開発環境は少しずつ便利になっています。

注意：

Xdebugは重いので本番用では動作しないようにした方がいいそうです。下手するとサーバーが落ちます。

つまり同じサーバーで本番/テストと使用する場合、php.iniを書き換える必要があります。