2018.06.04 Mon

【PHP】error_log関数を利用した応用的ロギング方法をご紹介

みなさんこんにちは、はじめまして。

今回はPHP言語のerror_log関数の応用的な使い方についてご紹介致します。
当記事の対象者としましては、以下のとおりです。

PHP言語の経験者
PHP言語で上手にログ出力をしたいと考えている方
PHP言語の原因不明なシステム障害の調査に困っている方

初めてのブログ記事ですが、どうぞ最後までよろしくお願いいたします。

error_log関数でログ出力させる理由

気をつけてプログラムを組んでいても想定をしていなかったバグだったりエラーだったりは発生してしまいます。そして、その障害は想定外のエラーなためプログラムから原因を調査するのはとても難しかったりします。そういった障害のときに、調査の助けとなるのがログファイルです。

何時に、どの画面で、どういう状態で、どんな操作をしたのか…等がログに残っていれば、プログラムエラーの原因究明に役立ち、早い対応ができると思います。

error_log関数は好きなタイミングでログを吐き出すことができる便利関数になります。それではerror_log関数を応用してもっと便利にログ吐き出しができるようにしてみましょう。

error_log関数の基本的な使い方

bool error_log (
  string $message [, int $message_type = 0 [, string $destination [, string $extra_headers ]]]
)

error_log関数の引数は4つ持っており、第1引数は必須で、第2引数は指定がない場合デフォルトで0がセットされ、それ以降の引数は任意となります。戻り値はbool型で正常にエラーメッセージが書き込まれたらtrueを返します。

サンプルプログラム index.php

<?php
if(check($value) === FALSE){
  error_log("条件を満たしておりません value : {$value}");
}

サンプルプログラムのようなプログラムを実行したとき、$value変数の中身をチェックする関数がFALSEを返した(条件を満たさなかった)ときに第1引数の内容がエラーログとして出力されます。

※エラーログの出力先はPHPの設定ファイルが記載された php.ini の中の `error_log` に指定したファイルとなります。

error_log関数の応用的な使い方

好き勝手にエラーログを出力させるだけでは、後々の調査を困難にさせてしまいます。ログを整理して出力させることが上手なロギングです。それではerror_log関数の応用例を紹介いたします。

以下のようなサンプルプログラムを作成しました。

Log.class.php はログを出力させるためのクラスです。index.php はアカウントが存在するかを確認するプログラムで、確認の結果に応じてLog.class.phpのログ書き込み用の関数を呼び出してます。

サンプルプログラム Log.class.php

<?php
class Log{
  // ログ出力関数 INFOログを出力する
  public static function info($text){
    self::write($text, "INFO");
  }

  // ログ出力関数 ERRORログを出力する
  public static function error($text){
    self::write($text, "ERROR");
  }

  // /log/log-年月日.log ファイルを出力する
  private static function write($text, $log_type){
    $datetime = self::getDateTime();
    $date = self::getDate();
    $file_name = __DIR__ . "/log/log-{$date}.log";
    $text = "{$datetime} [{$log_type}] {$text}" . PHP_EOL;
    return error_log(print_r($text, TRUE), 3, $file_name);
  }

  // 日付を返す(ファイル名用)
  private static function getDate(){
    return date('Ymd');
  }

  // 日時を返す(出力ログ用)
  private static function getDateTime(){
    $datetime = explode(".", microtime(true));
    $date = date('Y-m-d H:i:s', $datetime[0]);
    $time = $datetime[1];
    return "{$date}.{$time}";
  }
}

サンプルプログラム index.php

<?php
require_once __DIR__ . '/Log.class.php';

// アカウントID取得
$account_id = $_GET['account_id'];

if (existAccount($account_id)) {
  Log::info("アカウントは存在します(account_id : {$account_id})");
} else {
  Log::error("アカウントは存在しませんでした(account_id : {$account_id})");
}

// アカウントが存在するかを確認する
function existAccount($account_id) {...}

index.php はアカウントが存在するかを確認しております。確認した結果、存在する場合も存在しない場合もログを出力させています。存在する場合にはINFOログ、存在しない場合にはエラーログです。

ログは log ディレクトリに log-{日付}.log のように保存され、何年何月何日に記録されたログかをファイル名から判断できます。そして、出力されるログは何年何月何日の何時何分何秒にどんなログでどんなメッセージだったかを記録させております。

そして実際に記録されるログとしては以下の通り。

2018-05-23 11:08:10.0000 [INFO] アカウントは存在します(account_id : 1)
2018-05-23 11:45:14.1000 [ERROR] アカウントは存在しません(account_id : 100)

いつどのアカウントがどうだったかと言うのがひと目で分かるようになります。[ERROR]だけを絞って検索をすれば、どのアカウントがエラーだったのかも抽出することができます。