デバッグの第一歩
問題個所を見つけ解決する「デバッグ」は「プログラミング」と対のものです。はじめから問題のないプログラムを書ける人などいませんので、問題個所を素早く発見する手段を持っているかどうかが、効率良くプログラミング出来るか否かの分かれ道でもあります。
まずは最も簡単なところで、変数が想定した値かどうか確かめることから始めましょう。
変数の値を表示させる
最も簡単に出来るデバッグは、変数の値を表示させ確かめることです。デバッグプリントというやつです。
問合せ前のSQL文や関数が受け取った引数の型など、次の関数を使って想定した値かどうか自分の目で確かめてみましょう。
- var_dump( mix $val )
- 引数に与えた変数 $val の型とサイズ、値を表示する関数です。値がリファレンスの時は値の前に「&」が付きますので、実体かリファレンスかも確かめられます。最も汎用的に使える関数です。
- var_export( mix $val )
- 引数に与えた変数 $val を PHPのコードを書く時と同じ表現で表示する関数です。文章にすると難しそうですが、値を確かめるだけならこちらの方が見た目にわかりやすいと思います。
ブラウザでこれらの出力を表示すると改行されてないので正直見難いです。そこで変数を <pre> タグで囲んで出力する関数をつくっておくと重宝します。
/**
* 変数の値を表示する
*
* @var mix $val : 表示する変数
* @var bool $break : 同時に処理を終了するか? true:終了、false:終了しない(default)
*/
function vdump ( $val, $break = false )
{
echo '<pre><code>';
var_dump($val);
echo '</code></pre>';
if ($break) {
exit();
}
}
変数の値を後でまとめて表示させる
処理の途中で表示するとロジックが保てなくなったり、処理を途中で止めたくないといった時は、確かめたい変数を蓄積しておいて、最後にまとめて表示させればよいわけです。
グローバル変数をひとつ使いこんなコードでできます。
<?php
/**
* デバッグ時は true、運用時は false を指定
*/
define('DEBUG', true);
/**
* デバッグ用バッファを初期化
*/
if (DEBUG) {
$GLOBALS['debug'] = array();
}
/**
* ここで通常の処理
*/
/**
* 確認したい変数 $foo->name にラベルをつけて
* $GLOBALS['debug'] に保存
*/
$GLOBALS['debug'][] = array(
'label' => 'class foo->name',
'value' => $foo->name,
);
/**
* 処理の最後に $GLOBALS['debug'] を表示
*/
if (DEBUG) {
echo '<pre><code>';
var_dump($GLOBALS['debug']);
echo '</code></pre>';
}
?>
ログに記録する
運用中のデバッグなど値を表示出来ないこともあるでしょう。こんな時はログに記録します。
エラーメッセージを送信する error_log を使えば簡単にログを取ることが出来ます。error_log の第二引数に「3」を指定すれば、第一引数のメッセージが、第三引数で指定したファイルに記録されます。毎度これらを設定するのは面倒なので以下のような関数にまとめ必要な時に呼び出して使います。
/**
* 変数の値をファイルに保存する
*
* @var string $label : ラベル
* @var mix $val : 変数
* @return void
*/
function saveDebug ( $label, $val )
{
// ログのファイル名(適当に変える)
static $filename = '/home/*****/debug.csv';
// タイムスタンプを日付文字列に整形
$timeStmp = explode(' ', microtime())
$time = date('Y-m-d H:i:s', (int)$timeStmp[1]);
$mtime = '0.'. substr($timeStmp[0], 0, 5);
// $val をデコード
$val = var_export($val, true);
$val = str_replace(array("\r\n", "\r"), "\n", $val);
$val = str_replace('"', '""', $val);
// $message を整形
$message = '"'. $time. '","'. $mtime. '","'. $label. '","'. $val. '"'. "\r\n";
// 保存
error_log($message, 3, $filename);
}
ログのフォーマットはエクセルでも読めるCSV形式を用いています。ログファイルは予め作成しておく必要はありませんが、対象のディレクトリは予めウェブサーバの権限で書き込める属性を設定してないとエラーになります。
デバッグクラス
ここまでの処理をクラスにまとめておくとさらに便利です。スコープに関係なくどこからでも呼び出せるよう静的メソッドばかりで構成したデバッグのユーティリティクラスです。
debug.php
<?php
/**
* debug.php - デバッグクラス for PHP4
*/
class debug
{
// ログのファイル名
var $filename = '';
// デバッグレポート(showReport)で表示するグローバル変数名のリスト
var $reports = array();
// 値を書式化するデコーダ名
var $decoder = '__decode_var_export';
// 処理の開始時間
var $startTime = null;
// 変数の保存用バッファ
var $__buff = array();
/**
* このdebugクラスのインスタンスを返す:
* 必要があればコンストラクタの代わりに使用する。
*
* @return &object
*/
function & getInstance ()
{
static $instance = null;
if (null === $instance) {
$instance = new debug;
$instance->startTime = $instance->getMicrotime();
}
return $instance;
}
/**
* public: 初期設定
*/
/**
* ログのファイル名を設定する
*
* @var string $path : log filename
* @return bool
*/
function setLogfile ( $path )
{
$dir = dirname($path);
if (is_dir($dir) && is_writable($dir)) {
$debug =& debug::getInstance();
$debug->filename = $path;
return true;
} else {
return false;
}
}
/**
* 値を書式化するのデコーダの名前を設定する
*
* @var string $decoder : decoder name. 'var_export' or 'var_dump'
* @return bool
*/
function setDecoder ( $decoder = 'var_export' )
{
if (in_array($decoder, array('var_export','var_dump'))) {
$debug =& debug::getInstance();
$debug->decoder = '__decode_'.$decoder;
return true;
} else {
return false;
}
}
/**
* デバッグレポートで表示するグローバル変数名のリストを設定する
*
* @var array $reports : super global valiable names
* exp) array('_SERVER', '_GET', '_POST')
*/
function setReportingList ( $reports )
{
if (is_array($reports) && count($reports)) {
$debug =& debug::getInstance();
$debug->reports = $reports;
return true;
} else {
return false;
}
}
/**
* 終了時にデバッグレポートを表示するよう設定する
*
* @var array $reports : super global valiable names
* exp) array('_SERVER', '_GET', '_POST')
* 未指定時は debug::setReportingList で設定した値
*/
function setReporting ( $reports = null )
{
$debug =& debug::getInstance();
// debug::showReport を終了時の処理に登録
if (register_shutdown_function(array(&$debug, 'showReport'))) {
if (null !== $reports) {
if (is_array($reports) && count($reports)) {
$debug->reports = $reports;
return true;
} else {
return false;
}
}
return true;
} else {
return false;
}
}
/**
* public: ユーティリティ
*/
/**
* 変数の値を表示する:
*
* @var mix $val : 表示する変数
* @var bool $break : 同時に処理を終了するか? true:終了、false:終了しない(default)
*/
function dump ( $val, $break = false )
{
$debug =& debug::getInstance();
$decoder = $debug->decoder;
echo '<pre><code>', $debug->$decoder($val), '</code></pre>';
if ($break) {
exit();
}
}
/**
* 変数の値をバッファに保存する:
*
* @var string $label : ラベル
* @var mix $val : 変数
*/
function regist ( $label, $val )
{
$debug =& debug::getInstance();
$debug->__buff[] = array(
'time' => $debug->getMicrotime(),
'label' => $label,
'value' => $val,
);
}
/**
* 変数の値をログに保存する:
*
* @var string $label : ラベル
* @var mix $val : 変数
*/
function save ( $label, $val )
{
$debug =& debug::getInstance();
if (!$debug->filename) {
return false;
}
// 現在時刻をフォーマット。小数点で分ける
$time = explode('.', $debug->formatMicrotime($debug->getMicrotime(), 'Y-m-d H:i:s'));
// 変数をデコード
$decorder = $debug->decoder;
$val = $debug->$decorder($val);
$val = str_replace(array("\r\n", "\r"), "\n", $val);
$val = str_replace('"', '""', $val);
// $message を整形
$message = '"'. $time[0]. '","0.'. $time[1]. '","'. $label. '","'. $val. '"'. "\r\n";
// 保存
error_log($message, 3, $debug->filename);
}
/**
* デバッグレポートを表示する:
*
* @var array $reports : 表示するグローバル変数名のリスト
* exp) array('_SERVER', '_GET', '_POST')
* 省略時は setReportingList で指定した値
*/
function showReport ( $reports = null )
{
$debug =& debug::getInstance();
$decorder = $debug->decoder;
// タイトル、開始時間、実行時間を表示
echo '<hr><h3>Debug Report</h3>';
echo '<p>Start: ',
$debug->formatMicrotime($debug->startTime, 'Y-m-d H:i:s'), '</p>';
echo '<p>Action time: ',
$debug->formatMicrotime($debug->getMicrotime() - $debug->startTime),
' sec</p><br>';
// バッファにためた変数を表示
echo '<h4>Debug values</h4>';
if (count($debug->__buff)) {
echo '<table border="1">';
echo '<tr><td>time</td><td>label</td><td>value</td></tr>';
foreach ($debug->__buff as $val) {
echo '<tr><td><code>',
$debug->formatMicrotime($val['time'] - $debug->startTime),
'</code></td><td><code>',
htmlspecialchars($val['label']),
'</code></td><td><pre><code>',
htmlspecialchars($debug->$decorder($val['value'])),
'</code></pre></td></tr>';
}
echo '</table><br>';
} else {
echo '<p>(none)</p><br>';
}
// スーパーグローバル変数を表示
if (null === $reports) {
$reports = $debug->reports;
}
if (!count($reports)) {
return;
}
foreach ($reports as $val) {
echo '<h4>$', $val, '</h4>';
if (!array_key_exists($val, $GLOBALS)) {
echo '<p>(none)</p><br>';
} else {
echo '<pre><code>',
htmlspecialchars($debug->$decorder($GLOBALS[$val])),
'</code></pre><br>';
}
}
}
/**
* 現在時刻をマイクロ秒で返す:
*/
function getMicrotime ()
{
list($msec, $sec) = explode(' ', microtime());
return ((float)$sec + (float)$msec);
}
/**
* マイクロ秒を書式化して返す。少数点未満は第5位まで
*
* @var float $time : タイムスタンプ.マイクロ秒
* @var string $format : タイムスタンプのフォーマット(date関数の仕様による)
* 省略時は 秒数.マイクロ秒
* @return string
*/
function formatMicrotime ( $time, $format = null )
{
if (is_string($format)) {
$sec = (int)$time;
$msec = (int)(($time - $sec) * 100000);
$formated = date($format, $sec). '.'. $msec;
} else {
$formated = sprintf('%0.5f', $time);
}
return $formated;
}
/**
* private:
*/
/**
* 変数を var_export 形式でデコードする:
*
* @var mix $val : 変数
* @return string
*/
function __decode_var_export ( $val )
{
$buff = var_export($val, true);
return trim($buff);
}
/**
* 変数を var_dump 形式でデコードする:
*
* @var mix $val : 変数
* @return string
*/
function __decode_var_dump ( $val )
{
ob_start();
var_dump($val);
$buff = ob_get_contents();
ob_end_clean();
return trim($buff);
}
} // End of debug class
?>
この debug クラスの簡単な使い方
まずはこの debug クラスを、require_once で読み込んでおくことが第一。値($var)を表示させる時は debug::dump($var) を呼べばいいだけです。
後でまとめて表示する時は、確かめたい値($var)を debug::regist('label', $var) で登録し、処理の最後に debug::showReport() をコールすれば変数のレポートが表示されます。または明示的に debug::showReport() を呼ばなくても、予め debug::setReporting() をコールしておけば処理終了時に debug::showReport() が呼ばれレポートが表示されます。
ログに保存する時は、予め debug::setLogfile($path) でログファイルのパスを指定しておきます。あとは保存したい変数($var)を debug::save('label', $var) とすればログに保存されます。
あとデバッグレポートのおまけで、グローバル変数も確かめたい時は、予め debug::setReportingList(array('_GET','_POST','_SERVER')) のように「$」を除いた変数名の配列を設定すれば、レポート出力時に一緒に表示されます。
実際の使い方はこんな感じです。
<?php
// 運用時は DEBUG を false にする
define('DEBUG', true);
// デバッグ時
if (DEBUG) {
require_once 'debug.php';
debug::setLogfile('/home/***/tmp/debug***.csv');
debug::setReporting();
debug::setReportingList(array('_GET','_POST','_COOKIE'));
}
/**
* ここからは通常の処理
*
* debug::dump、debug::regist、debug::save を
* 必要に応じて使い分ける
*/
// 変数 $var の 値を表示する
debug::dump($var);
// 表示したあと強制終了
debug::dump($var, true);
// 変数 $str を登録
debug::regist('$str', $str);
// ファイル名と行番号なんかもラベルに入れとく
debug::regist(__FILE__.':'.__LINE__.': $str', $str);
// 表示できない時はログに保存
debug::save('$db->query($sql)', $sql);
/**
* 予め debug::setReporting() を設定してるので
* debug::showReporting() は呼ばなくてもレポートが表示されます。
* 処理の途中 exit() で強制終了した時もレポートは表示されます。
*/
?>
一人でサイトを管理してる私には、このくらいがちょうどいい感じです。
