Log4J徹底解説

Log4phpの使い方

さて、これはオマケだ。Apache Logging プロジェクトでは、フラグシップである Log4J だけではなくて、正規のプロジェクトとして、Chainsaw は別として、log4cxx, log4php, log4net の4プロジェクトを抱えている。それぞれ C++, PHP, .NET 用であることは言うまでもないんだが、以前 C++ 用の log4cxx については書いたので、今回の更新では「自分が良く知ってて、かつお役に立ちそうな」という基準で、Log4php について解説しよう。

実は仕事では結構 PHP を使ってたりする...だって便利なんだもん。けど、愛はないなぁ...これがこのサイトで PHP をメインにしたコンテンツがほとんどない理由じゃなかろうか。要するにハッキーな面白さがあまりないんだよね。あ、筆者は M$ はキライだ。筆者が log4net について書くことを期待せず、他を当たってくれ。

なので、log4J と共通する機能については、ここでは突っ込まない。判らないことがあれば、「使い方(1)」「使い方(2)」あたりを適宜参照してくれ。

目次

概説

まあ、log4cxx の場合には Appender でないのがあるにせよ、ほとんど log4j と同様なかたちで使えたわけである。が、log4php の場合はかなり強烈にサブセットだ。特に大きいのが「ポリモーフィズムや動的ローディングを駆使した、OOPのメリットを活用した技はできない」という制限だ。こりゃ、PHP が「後づけでOOPマガイなことをしている」に過ぎないという言語的制限にひっかかっているわけだ(log4j はそういう「ハッカー臭い」ところが良かったんだけどね....)。また、Appender を入れ子にできないので、AsyncAppender みたいな Appender は定義できない(スレッドは危ないしな...)。そういうわけなのか、log4cxx では log4j.xml でも log4j.properties でもそのまま使えたのが、log4php では専用のファイル(と識別子名)を取ったりする...log4J に慣れていると、意外にギョっとするぞ。

たとえば、簡単な log4php.properties はこんなところだ。

log4php.appender.stdout=LoggerAppenderConsole
log4php.appender.stdout.layout=LoggerPatternLayout
log4php.appender.stdout.layout.ConversionPattern=%d %5p %c{1} - %m%n

### direct messages to file mylog.log ###
log4php.appender.file=LoggerAppenderFile
log4php.appender.file.File=mylog.log
log4php.appender.file.Append=true
log4php.appender.file.layout=LoggerLayoutTTCC

log4php.logger.Sug.Test=debug, file
log4php.rootLogger=debug, stdout

で、ぎょっとするのは、まず先頭の要素が「log4j」じゃなくて「log4php」だ、というあたりはカワイイものだ。また、PHP では FQCN なんて洒落たものはないので、「LoggerAppenderConsole」といった名前が Appender の名前になる。で、Log4J を使い慣れていると、ついつい PatternLayout ばっかり使うクセがついちゃうが、筆者が落したバージョン(0.9)だと、PatternLayout にバグがあって、レイアウトしないんである....これを修正するんだと(PHPだから楽だ)、

log4php-0.9/src/log4php/helpers/LoggerPatternConverter.php の289行
(LoggerDatePatternConverter クラス)
    function convert($event)
    {
        $timeStamp = $event->getTimeStamp();
        $usecs = round(($timeStamp - (int)$timeStamp) * 1000);
#        $this->df = str_replace("\u", "u", ereg_replace("[^\\]u", sprintf(',%03d', $usecs), $this->df));
        $this->df = str_replace("\u", "u", ereg_replace(",u", sprintf(',%03d', $usecs), $this->df));

        return date($this->df, $event->getTimeStamp());
    }

と直すとOKだ....何でこんなバグが生き残ってるんだろう???

これでログ出しをする方は、こんな感じになる。

<?php
# require_once で LoggerManager.php を include するだけで使える
require_once( '../log4php-0.9/src/log4php/LoggerManager.php' );

# ロガーの取得
$logger =& LoggerManager::getLogger('Sug.Test');

# いろいろ出してみる
$logger->info( 'test start' );
$logger->warn( 'Warning Message' );
$logger->error( 'ERROR MESSAGE' );
$logger->fatal( 'FATAL MESSAGE' );
echo "test body\n";
$logger->debug( 'only debug' );
$logger->info( 'test end' );

# 別なロガーで出す
$logger =& LoggerManager::getLogger('Sug.Another');
$logger->info( 'Another Logger!' );

# これは注意!
$logger->shutdown();
?>

そうすると、標準出力への出力(LoggerAppenderConsole)はこういう風になる。

% php mytest.php
2006-04-07 23:18:40,725  INFO Test - test start
2006-04-07 23:18:40,728  WARN Test - Warning Message
2006-04-07 23:18:40,731 ERROR Test - ERROR MESSAGE
2006-04-07 23:18:40,733 FATAL Test - FATAL MESSAGE
2006-04-07 23:18:40,736 DEBUG Test - only debug
2006-04-07 23:18:40,738  INFO Test - test end
2006-04-07 23:18:40,741  INFO Another - Another Logger!
test body

ファイルへは次のように出る(LoggerAppenderFile)。logger で排除した Sug.Another カテゴリは出ないのを確認しよう。

% cat mylog.log
Fri Apr  7 23:18:40 2006,725 [1525] INFO Sug.Test - test start
Fri Apr  7 23:18:40 2006,728 [1525] WARN Sug.Test - Warning Message
Fri Apr  7 23:18:40 2006,731 [1525] ERROR Sug.Test - ERROR MESSAGE
Fri Apr  7 23:18:40 2006,733 [1525] FATAL Sug.Test - FATAL MESSAGE
Fri Apr  7 23:18:40 2006,736 [1525] DEBUG Sug.Test - only debug
Fri Apr  7 23:18:40 2006,738 [1525] INFO Sug.Test - test end

ちなみに [1525] は Log4J だと「スレッド名」だが、PHP にはそういう洒落たものはないので、プロセス番号である。

XML形式設定ファイル

じゃあ、log4php.xml のような、XML 形式の設定ファイルはどう使うんだろう? Log4J の場合は、「クラスパスに log4j.xml があれば、log4j.properties に優先して使われる!」というルールだったので、何となく「log4j.xml の方が強い!」というイメージを持つだろうけど、log4php は逆だ。デフォルトは log4j.properties であり、XML 形式を使う場合には、

<?php
define('LOG4PHP_CONFIGURATION', 'log4php.xml');
# $_ENV{'log4php.configuration'} = 'hogehoge.xml';
# でもイケる。
require_once( '../log4php-0.9/src/log4php/LoggerManager.php' );

でわざわざ指定してやる必要がある。要するに LOG4PHP_CONFIGURATION(優先) か、環境変数 $_ENV{'log4php.configuration'}(劣後)を見て設定ファイルを拾い出し、 それが .xml で終れば XML 形式で解釈する、というやり方だ。XML形式の設定ファイルはこんな感じになる。

<?xml version="1.0" encoding="ISO-8859-1"?>
<log4php:configuration xmlns:log4php="http://www.vxr.it/log4php/" threshold="all" debug="false">
    <appender name="console" class="LoggerAppenderConsole">
        <layout class="LoggerPatternLayout" >
           <param name="ConversionPattern" value="%d %5p %c{1} - %m%n" />
        </layout>
    </appender>

    <appender name="file" class="LoggerAppenderFile">
        <param name="File" value="mylog.log" />
        <param name="Append" value="true" />
        <layout class="LoggerLayoutTTCC" />
    </appender>

    <logger name="Sug.Test">
        <level value="debug" />
        <appender_ref ref="file" />
    </logger>

    <root>
        <level value="all" />
        <appender_ref ref="console" />
    </root>
</log4php:configuration>

..という具合に、ネームスペースからして違ってる。DTD 自体もバージョン違いくらいの違いがある。要するに設定ファイルは Log4J とは互換性がない。

で、利用コードの方でちょいと注記した、

# 別なロガーで出す
$logger =& LoggerManager::getLogger('Sug.Another');
$logger->info( 'Another Logger!' );

# これは注意!
$logger->shutdown();
?>

の shutdown() だが、これは一部の Appender が「ロガーが終了したらフラッシュする」という動作をしていたりする(LoggerAppenderMail)。だから、これは可能な場所で呼んでおいた方がいいようである。意外に馬鹿だ。

サーバサイド・スクリプトでの利用

PHP と言えばサーバサイドのスクリプトで使うのが本来だ。さっきの例はどっちか言えば、テストのためにスタンドアロンで実行した..わけで、ここではサーバサイドの話をしよう。

どうせ PHP を使える環境のセットアップは済んでいることだろうから、ここでは触れない。単にどこかのディレクトリに Log4php のソースを仕込んでおく。ディストリビューションの log4php-0.9/src/log4php ディレクトリをどこかにコピーすればいいのだが、まあこれは DOCUMENT_ROOT から外れたところの方がいいだろう。ここでは、

# cp -R log4php-0.9/src/log4php /usr/local/share/

として、/usr/local/share/log4php に存在することにしておく。

で、PHP のコードはこんな感じだろう。

<?php
# LoggerManager をインクルードして、Log4php を使えるようにする
require_once( '/usr/local/share/log4php/LoggerManager.php' );
# ロガーを取得する
$logger =& LoggerManager::getLogger('My.Php');

# ちょっと TIPS...
$remote = getenv( "REMOTE_ADDR" );
LoggerNDC::push( $remote );
$logger->info( "enter" );

.......
if( たとえば検索がある ) {
    ........
    $query = "select * from テーブル where 何かの動的に構築される条件";
    # 検索条件をログしたい
    $logger->debug( $query );
    $result = mysql_query( $query, $conn );
    ..............
}
$logger->info( "exit" );
LoggerNDC::pop();
?>
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN"
"http://www.w3.org/TR/REC-html40/loose.dtd">
<html>
<head>
<title>タイトル</title>
</head>
<body>
..........
</body></html>

これで、この PHP と同じディレクトリに、次のような log4php.properties を置く。

### direct messages to file cosmo.log ###
# サイズベースのログローテートをする Appender
log4php.appender.file=LoggerAppenderRollingFile
log4php.appender.file.MaxBackupIndex=5
# ログファイル指定。DOCUMENT_ROOT から外しておく
log4php.appender.file.FileName=../../log/cosmolog
log4php.appender.file.Append=true
log4php.appender.file.MaxFileSize=1000
log4php.appender.file.layout=LoggerPatternLayout
log4php.appender.file.layout.ConversionPattern="%d %5p [%x] - %m%n"

# 困った時のデバッグ用
log4php.appender.stdout=LoggerAppenderEcho
log4php.appender.stdout.layout=LoggerPatternLayout
log4php.appender.stdout.layout.ConversionPattern="%d %5p [%x] - %m%n"

log4php.logger.My.Php=info, file
log4php.rootLogger=debug
# log4php.rootLogger=debug, stdout
# log4php.debug = true

まあ、ポイントはいくつかある。

  1. ログファイルは DOCUMENT_ROOT から外した方がセキュリティ上よろしい。
  2. ログファイル・ディレクトリのパーミッションは大丈夫? Apache 経由で書き込めるかな?
  3. NDC をうまく使おうよ。

で、NDC(Nested Diagnostic Context:ネストした診断コンテキスト) だ。これは大変便利なもので、「どのアクセスによるログか?」をログの中で区別したい...というのは人情だが、それを実現するためにあるような武器だ。本来 Log4J ではこれは「スレッドに保存されるデータ」だが、スレッドなんてない log4php の場合は、グローバルな隠し変数 $GLOBALS['log4php.LoggerNDC.ht'] に、スタックモデルで LoggerNDC::push() されたデータを PUSH する。というわけで、ここに REMOTE_ADDR を保存しておけば、たとえ PHP のアクセスが同時に交錯したところで、それらの吐いたログを区別できちゃうわけである。

2006-04-08 10:54:48,443  INFO [133.32.99.99] - enter
2006-04-08 10:54:48,964 DEBUG [133.32.99.99] - select name,year,format,dtime,artist,id from cosmowork where format like '%P%' order by id
2006-04-08 10:54:49,102  INFO [222.85.14.11] - enter
2006-04-08 10:54:49,512  INFO [222.85.14.11] - exit
2006-04-08 10:54:49,747  INFO [133.32.99.99] - exit

で、これはグローバル変数なので、たとえ別ファイルを include したとしても、影響が及ぶに決まってる....そういう具合に筆者が「アクセスを区別するための武器」だと言ったのは伊達じゃないくらいに重要なフィーチャーなのである。ぜひぜひ活用されたい。あと、同様に連想配列に保存する MDC(Mapped Diagnostic Context) というのもあるが、これも同様に、

$remoteAddr = getenv( "REMOTE_ADDR" );
$remoteHost = getenv( "REMOTE_HOST" );
LoggerMDC::put( 'REMOTE_ADDR', $remoteAddr );
LoggerMDC::put( 'REMOTE_HOST', $remoteHost );
$logger->info( "enter" );

のようにして使え、log4php.properties でのレイアウト指定は、

log4php.appender.file.layout.ConversionPattern="%d %5p [addr=%X{ADDR} host=%X{HOST}] - %m%n"

の要領で使える。

Log4php の Appender 一覧

で、問題は存在する Appender だ。以下の Appender が存在する。が、「似てるのは名前と大まかな機能だけ!」というものも多い....感覚的には「log4Jの初期バージョンってこんなんだったんだろうね...」と思いを馳せるような、原始的な Appender が多い。

LoggerAppenderConsole
標準出力 or 標準エラー出力にログを出す。これは LoggerAppenderEcho とは違い、マジメに php://stdout などを開いて出す。ConsoleAppenderを参照。
LoggerAppenderDailyFile
ファイル出力の Appender。これはDailyRollingAppenderとは似て非なるものである。要するに起動時の時間からファイル名を作り上げるだけのもので、ローテーションはまったくしない。
LoggerAppenderDb
JDBCAppenderを参照。JDBCAppender に近い、SQL を自分で構築してDBに出力するものである。が、なぜか推奨テーブルがあったりするあたり中途半端だなあ。
LoggerAppenderEcho
これは標準出力にログが出るんだが、PHP の echo を使って出す。ログの出具合が少し違うわけで、LoggerAppenderConsole よりもこっちの方が好きな人が多かろう。
LoggerAppenderFile
ファイルに出力する。FileAppenderを参照。
LoggerAppenderMail
SMTPAppenderを参照。なぜかメール送信Appender が2つもあるが、こっちはロガーが終るまでログをメール本文に貯めておいて、ロガーが終了(shutdown)したら、一気にメールを送る。
LoggerAppenderMailEvent
こっちはログイベントが発生したらメールをその都度送る。debug レベルで送ったりしたらメチャうざいと思うよ。
LoggerAppenderNull
NullAppenderを参照。何もしない。これは完璧に Log4J と機能が共通する(苦笑)。
LoggerAppenderPhp
これは PHP 独自の仕様。要するに PHP が持っているエラー処理の機構を使ってログをする。trigger_error() を呼ぶわけだ。
LoggerAppenderRollingFile
ファイルに出力し、サイズベースのローテーションをする。RollingAppenderを参照。
LoggerAppenderSocket
SocketAppenderを参照。ソケットで送信する。
LoggerAppenderSyslog
SyslogAppenderを参照。これは唯一能力的に Log4J に勝ってるものかな? 要するに PHP の syslog() を呼んで、syslog する Appender である。Java はプラットフォーム・インデペンデントを謳っているので、OS 依存の syslog(2) は使えず、その代わりに UDP でリモートログサーバにネット越しに配信するだけである(そっちがプラットフォーム独立なのは何か矛盾してるような...)。が、PHPは PHP の関数の側でネイティブコードサポートをしちゃってるわけで、堂々とローカル syslog の出来る syslog() を持っている。それをこれは使う。

まあ、Log4J(1.2系) にあって Log4php にない Appender というと、

AsyncAppender, JMSAppender, LF5Appender, SocketHubAppender, TelnetAppender, DailyRolingFileAppender, ExernallyRolledFileAppender

となるが、これは致し方のないものがほとんどだ。そう見てみりゃ、「よく頑張ってる!」とホメてあげるべきなのかなあ....



copyright by K.Sugiura, 1996-2006