デバッグし易くしよう！ 6: ログファイルに処理記録を残す

ここまでは、処理の進行状況や、変数の値などを表示する方法を紹介してきましたが、実際に本番サーバー上で、botの運用を開始してしまうと、毎回の処理状況を付きっきりで目視できる訳ではありません。
PHPのerror_log関数（マニュアル）を利用すると、ログとして任意のエラーメッセージをファイルに書きだすことができます。
これを利用して、処理のログをファイルに書き出してみることにします。*1

Step6 ログファイルに処理記録を残す

error_log関数を利用してログをファイルに書き出す方法は簡単です。例えば、syori.txtというファイルに"プログラムを実行しました”というメッセージを書き出したいのであれば、下記のように書くだけでOKです。

<?php

error_log("プログラムを実行しました",3,'syori.txt');

?>

これを今までも利用しているサンプルコードに埋め込むんで、step1で追加した、echo文をログファイルに出力するようにしてみると例えば、次のようになります。

<pre>
<?php

//DEBUG処理の切り替え     本番運用時にはFALSEに変更すること
define('DEBUG', TRUE);  //デバッグ時
//define('DEBUG', FALSE); //本番運用時

//エラー表示レベル制御 デバッグ時：E_ALL, 本番運用時:0
if(DEBUG) { error_reporting(E_ALL); } else{
            error_reporting(0);
}


$start_time=microtime(true);
$log_msg= "開始時間： ".formatMicrotime($start_time,'Y-m-d H:i:s')."\n";
echo $log_msg;
error_log($log_msg, 3 , 'syori.txt');


if (DEBUG) { error_log( "プログラム開始\n",3, 'syori.txt');}
//ユーザー名、パスワード
$username='Twitterユーザ‐名';
$password='Twitterパスワード';
if (DEBUG) { error_log(  "     ユーザー名、パスワードセット完了\n",3, 'syori.txt'); }

$message='Twitter投稿テストのメッセージ !!';
if (DEBUG) { error_log(  "     投稿メッセージをセット完了\n",3, 'syori.txt'); }

$ret= tweet_fop($message, $username, $password);


if (DEBUG) { error_log(  "プログラム終了\n",3, 'syori.txt'); }
$end_time=microtime(true);
$log_msg= "終了時間： ".formatMicrotime($end_time,'Y-m-d H:i:s')."\n";
echo $log_msg;
error_log($log_msg, 3 , 'syori.txt');
$syori_zikan=$end_time - $start_time;
$log_msg= "処理時間：".formatMicrotime($syori_zikan)."秒\n";
echo $log_msg;
error_log($log_msg, 3 , 'syori.txt');
exit();


//fopenを利用したtweet function
function tweet_fop($message, $username, $password)
{
if (DEBUG) { error_log(  "     関数tweet_fop：START\n",3, 'syori.txt'); }

    $url = "http://twitter.com/statuses/update.json?";
    $params = "status=". rawurlencode($message);

    $st = stream_context_create(array(
        "http" => array(
            "method" => "POST",
            "header" => "Authorization: Basic ". base64_encode($username. ":". $password)
        )
    ));
    
if (DEBUG) { error_log(  "     fopen実行\n",3, 'syori.txt'); }

if(($fp = fopen($url.$params, 'r', false, $st)) == false){
     if (DEBUG) { error_log(  "     fopen 失敗のため 関数tweet_fopから戻る \n",3, 'syori.txt'); }
      return(false);
}

if (DEBUG) { error_log(  "     fopen成功\n",3, 'syori.txt'); }

$contents=stream_get_contents($fp);

if (DEBUG) { error_log(  "     fclose実行\n",3, 'syori.txt');}
fclose($fp);

if (DEBUG) { error_log(  "     関数tweet_fop：END\n",3, 'syori.txt'); }
return ($contents);

}

//デバッグ用、時間フォーマット変換
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;
}
?>
</pre>

これを実行した場合、画面上の表示は次のようになります。

開始時間： 2010-01-12 01:47:38.99464
終了時間： 2010-01-12 01:47:39.53045
処理時間：0.53582秒

しかし、ログデータを書き出した　'syori.txt'ファイルを見るとより詳細な処理の流れを確認することができます。

開始時間： 2010-01-12 01:47:38.99464
プログラム開始
     ユーザー名、パスワードセット完了
     投稿メッセージをセット完了
     関数tweet_fop：START
     fopen実行
     fopen成功
     fclose実行
     関数tweet_fop：END
プログラム終了
終了時間： 2010-01-12 01:47:39.53045
処理時間：0.53582秒

*1:error_log ( string $message [, int $message_type = 0 [, string $destination [, string $extra_headers ]]] )関数
エラーメッセージを Web サーバのエラーログ、 TCP ポート、あるいはファイルに送ります
第2引数$mesage_typeに"3"をセットした場合に、第3引数Rdestinationで指定したログファイルに第1引数で指定したエラーメッセージが書き出されます。