PHP 8.3 の CLI で xdebug.mode=profile を本番相当データに当てたら遅すぎた話

PHP 8.3.4、Ubuntu 22.04、CLI からバッチスクリプトを叩く構成。DB から 40 万行を読んで集計し、結果を CSV に落とす処理で、本番相当のデータセットだと 1 実行 11 分かかっていた。ボトルネックの当たりを付けたくて、ローカルの同じデータで Xdebug のプロファイラを有効にした。

やったことは単純で、php.ini ではなく実行時オプションで切り替えた。

php -d xdebug.mode=profile \
    -d xdebug.output_dir=/tmp/xdebug \
    -d xdebug.profiler_output_name=cachegrind.out.%p \
    bin/aggregate.php --input=/tmp/rows.csv

出力は KCachegrind ではなく、まず callgrind_annotate で関数ごとの inclusive time を並べた。

callgrind_annotate --inclusive=yes /tmp/xdebug/cachegrind.out.12345 | head -40

上位に来たのは PDO の fetch ではなく、array_multisort を呼んでいる自前のソート関数だった。40 万行を連想配列のまま usort で 3 キー比較していた箇所で、比較関数の中で毎回 strcmp を 2 回呼んでいた。ここを、キーを連結した文字列を事前に作って array_multisort に渡す形へ変えたら、プロファイル込みでも 2 分台まで落ちた。

プロファイラを入れると当然オーバーヘッドが出る。手元では同じ処理が約 3 倍遅くなった。だから絶対時間は信用せず、比率だけを見る。あと xdebug.mode=profile は develop と併用するとさらに重いので、プロファイル時は単独にしたほうがいい。CLI なら -d で都度切り替えられるので、php.ini を書き換えて戻し忘れる事故も避けられる。

効かない場面もはっきりしている。I/O 待ちが支配的な処理、たとえば外部 API を 1 行ごとに叩くバッチでは、プロファイラは「PHP 側は暇」としか言わない。あと OPcache の JIT が効いている前提のコードは、Xdebug 有効時に JIT が無効化されるので、プロファイル結果が実際の挙動とずれる。自分はこれで「JIT を切ると遅い関数」を最適化対象だと誤認しかけた。

みんなは本番相当のデータ量でプロファイルを取るとき、Xdebug と何を組み合わせて関数単位の時間を測っている？