2014-02-09

var_dump に頼らないPHPデバッグとおすすめログフォーマット

IDEのブレークポイントや var_dump は強力ですがブラウザの画面やシェルの標準出力に出力した場合、後から確認することが困難になります。

そんなときはファイルに書き出してそれを tail -f するなどして開発を進めるとよいです。

PHPでは error_log (第三引数に3を渡す) と var_export (第二引数に true を渡す) の組み合わせが便利です。



PHPおすすめログフォーマット


さて、ここまではよくある話ですが、今回はおすすめのログフォーマットを紹介します。

// $foo に確認したい値が入っている

error_log(sprintf("%s\n%s %s %s %s (%d)\n=====\n\n", var_export(
$foo
,1), uniqid(), date(DATE_RFC822), __FILE__, __METHOD__, __LINE__), 3, '/var/tmp/my_errors.log');

このログフォーマットを使うと下記のような出力結果になります。

array (
  'one' => 1,
  'two' => 2,
)
53cf3c77a5f88 Sun, 09 Feb 14 01:13:10 +0900 /home/ymkjp/workspace/20140209_ErrorLog.php Foo::bar (10)
=====


この方法の利点を5つあげてみます。

  • 簡易的なフィンガープリントが付いているのであとから探すのが容易
  • ログが書き出された日時が分かるのであとから確認するときに便利
  • ログが書き出された箇所で設定されているPHPのタイムゾーンも分かる
  • ログを仕込んだ箇所が分かる (ファイル名、クラスとメソッド、行数)
  • ログが ===== で区切られて読みやすい

僕はこのスニペットを Alfred Powerpack のクリップボードClipMenu に登録して使っています。



var_export の限界に達することもわりとある


今回紹介した var_export によるデバッグは便利なものの注意点もあります。

例えば "Fatal error: Nesting level too deep - recursive dependency?" というエラーが出ることがあります。

その場合は var_dump を使ったり、値を serialize してから出力してみるといいかもしれません。



使用例


ちなみに文中で例として使った出力結果を得るために書いたPHPコードはこちらです。



※事前に /var/tmp/my_errors.log の作成と権限付与、および php.ini で timezone の設定を行う必要があります



ログの確認方法


$ tailf /var/tmp/my_errors.log

tailf は tail -f に比べてどうやらディスクにやさしいコマンドである だけでなく、約29%のタイプ数削減効果もあります。