Java™ Logging API 詳細

2008年01月29日

クラスの構成と概要

Logging API 概要

コードを記述しているときは基本的に LoggerLevel クラスに注目していれば十分です。しかし柔軟な出力を行おうとすると各クラスの関係を理解していくつかサブクラスを作成する必要があります。

クラス 役割
LoggerJava™ API リファレンス アプリケーションから見た直接的なログ出力先。
LevelJava™ API リファレンス ログのレベル。
HandlerJava™ API リファレンス 実際の (物理的な) ログ出力先。
FormatterJava™ API リファレンス ログを出力用の文字列に変換。
FilterJava™ API リファレンス ログが出力対象かどうかを判定。
LogRecordJava™ API リファレンス 1 つのログを表す情報。
LogManagerJava™ API リファレンス Logger を名前で一元管理。設定の読み込みなど。
ErrorManagerJava™ API リファレンス Handler で例外が発生したときに使用。

Log4j に比べて役割分担がシンプルな構成です。各クラスの関係は以下の通りです。

クラス図

階層構造と出力の伝播

Logger のインスタンスはそれぞれコンストラクタや getLogger() で指定した名前を持っています。これはピリオドで区切ったドメインで階層化されており、ルートに存在するものはルートロガーと呼ばれます。

出力フォーマット

Formatter のサブクラスは、Handler オブジェクトがファイルなどのストリーム型のデバイスに出力を行うために使用するクラスです。名前の通り LogRecord オブジェクトから実際に出力する文字列を生成します。

Logging API は標準では 2 つの Formatter が用意されていますが、本格的な利用ではどちらも実用性に欠けると言わざるを得ません。Formatter は自分たちで実装するものと考えておいて下さい。

SimpleFormatterJava™ API リファレンス

1~2 行の簡単なフォーマットです。Formatter が指定されていない場合のデフォルトとして使用されます。

2008/01/29 23:49:51 biz.moyo.lab.MyClass main
情報: hello, world
XMLFormatterJava™ API リファレンス

XML 書式のフォーマットです。プログラム的に解析する前提のログを出力したい場合に有用ですが、人が読むのには向いておらず、またファイルサイズも大きくなりがちです。


<?xml version="1.0" encoding="windows-31j" standalone="no"?>
<!DOCTYPE log SYSTEM "logger.dtd">
<log>
<record>
  <date>2008-01-29T23:52:59</date>
  <millis>1201618379969</millis>
  <sequence>0</sequence>
  <logger>biz.moyo.lab.MyClass</logger>
  <level>INFO</level>
  <class>biz.moyo.lab.MyClass</class>
  <method>main</method>
  <thread>10</thread>
  <message>hello, world</message>
</record>
</log>


正常/異常問わずプログラムが終了した時にルートの <log> 要素が閉じられないため、解析プログラム側では DOM ではなく SAX を使用するなどの対処が必須です。

カスタムフォーマット

標準の Formatter で満足できない場合は FormatterJava™ API リファレンス のサブクラスを自作する必要があります。サブクラスは format() メソッドをオーバーライドして LogRecord の情報を元に出力用の文字列を作成するだけです。

public class MyFormatter extends Formatter{
    public String format(LogRecord record) {
        return String.format("[%tF %tT] %s%n",
            record.getMillis(), record.getMillis(),
            record.getMessage());
    }
}
出力結果
[2008-01-30 05:29:09] hello, world

LogRecordgetSourceClassName()Java™ API リファレンスgetSourceMethodName()Java™ API リファレンス は呼び出し側が意識しなくてもクラス名/メソッド名を取得できるため非常に便利ですが、例外のスタックトレースからスタックフレームを解析して取得しておりパフォーマンスが良くないので注意してください。

開発フェーズは Formatter の呼び出し頻度がかなり高くなると予想されます。 MessageFormatJava™ API リファレンスString#format()Java™ API リファレンス を使用したところでディスク I/O に比べれば小さいかも知れませんが、特にサーバサイドが前提の場合は必ず事前に SimpleFormatter や NOOP*1 Formatter とパフォーマンスを比較して問題がない事を確認して下さい。

*1 NO OPeration: ここでは何もせず "" を返す Formatter の事。

出力ハンドラ

Logging API は標準で以下のハンドラクラスを用意しています。

FileHandlerJava™ API リファレンス

ローカルファイルシステムへ出力するハンドラです。ログファイルが特定の大きさに達したらファイルを切り替える機能が備わっています。また %u パターンを使用することで複数のプロセスが同じファイルパターンを使用した場合でも物理的に別ファイルにし整合性を保障するよう設計されています。

このような柔軟性を持たせるため、出力先のファイル名は固定ではなくパターンとして指定します。パターン中で使用できるプレースホルダは以下の通りです。

/ プラットフォーム依存のファイルセパレータ (システムプロパティ file.separator の値)。Windows は '\\'、Unix は '/' など。
%t プラットフォーム依存の一時ディレクトリ (システムプロパティ java.io.tmpdir の値)。Windows は C:\Document and Settings\{username}\Local Setting\temp、Unix は /tmp など。
%h ユーザのホームディレクトリ (システムプロパティ user.home の値)。
%g ログを循環させるときに付けられる番号。
%u 同一ファイルパターンを複数プロセスで使用しようとした時の番号。
%% パーセント記号のエスケープ。

ログファイルをサイズではなく日付で循環させたい場合や、切り替えと同時に圧縮スレッドを起動したいような場合は新しく Handler クラスを作成する必要があります。この場合、FileHandler はサブクラスでの出力先再設定をサポートしていないため StreamHandler のサブクラスにしてください。

設定ファイルでは以下のプロパティを使用するができます。

java.util.logging.FileHandler.level (デフォルト: ALL)
このハンドラを使用したログの出力レベル。
java.util.logging.FileHandler.filter (デフォルト: Filterなし)
出力レベルよりも詳細な出力判定を行うためのフィルタクラス名。
java.util.logging.FileHandler.formatter (デフォルト: java.util.logging.XMLFormatter)
ファイル出力時に使用する Formatter クラス名。
java.util.logging.FileHandler.encoding (デフォルト: プラットフォーム依存)
ログファイルの文字エンコーディング。
java.util.logging.FileHandler.limit (デフォルト: 無制限)
ファイルを切り替える閾値 (0は無制限)
java.util.logging.FileHandler.count (デフォルト: 1)
ファイル切り替え時に循環して残しておくファイル数。
java.util.logging.FileHandler.pattern (デフォルト: %h/java%u.log)
出力ファイル名のパターン。 APIJava™ API リファレンス 参照。
java.util.logging.FileHandler.append (デフォルト: false)
既存ファイル追加
ConsoleHandlerJava™ API リファレンス

標準エラー (System.err) へ出力するハンドラです。特にハンドラを指定していない場合のデフォルトとして使用されます。

設定ファイルでは以下のプロパティを使用できます。

java.util.logging.ConsoleHandler.level (デフォルト: INFO)
このハンドラを使用したログの出力レベル。
java.util.logging.ConsoleHandler.filter (デフォルト: Filterなし)
出力レベルよりも詳細な出力判定を行うためのフィルタクラス名。
java.util.logging.ConsoleHandler.formatter (デフォルト: java.util.logging.SimpleFormatter)
ファイル出力時に使用する Formatter クラス名。
java.util.logging.ConsoleHandler.encoding (デフォルト: プラットフォーム依存)
コンソール出力の文字エンコーディング。
SocketHandlerJava™ API リファレンス

ログを TCP/IP 経由で別のサーバに転送します。ログはファイルに出力するのと同じようにフォーマットされストリームに出力されます。

ソケットハンドラは構築時からクローズまでの間ずっとサーバとの接続を維持します。切断による再接続等のリカバリ処理は行われないため、実用的な耐障害性を持たせるには独自に実装する必要があります。

設定ファイルでは以下のプロパティを使用できます。

java.util.logging.SocketHandler.level (デフォルト: ALL)
このハンドラを使用したログの出力レベル。
java.util.logging.SocketHandler.filter (デフォルト: Filterなし)
出力レベルよりも詳細な出力判定を行うためのフィルタクラス名。
java.util.logging.SocketHandler.formatter (デフォルト: java.util.logging.XMLFormatter)
ファイル出力時に使用する Formatter クラス名。
java.util.logging.SocketHandler.encoding (デフォルト: プラットフォーム依存)
ソケット出力の文字エンコーディング。
java.util.logging.SocketHandler.host (必須)
接続先のホスト名。
java.util.logging.SocketHandler.port (必須)
接続先のポート番号。
MemoryHandlerJava™ API リファレンス

メモリ上の循環バッファに一定個数のログを保持するハンドラです。上限を超えたログは最も古い LogRecord を上書きすることで保持する個数を維持します。

MemoryHandler

メモリハンドラは下層に別のハンドラを持っており、あるレベル以上のログが書き込まれようとした時に、循環バッファが保持しているすべてのログを下層のハンドラに出力します (push)。

この意図は何か? 例えば SEVERE より低いログはバッファリングするだけで push しないよう構成した場合、プログラムが正常に動いている状態なら FINE などのログは出ないわけですが、いざ SEVERE レベルのログを出そうとした時に直近のいくつかの詳細なログも出力されるといった仕組みです。

push は明示的に push() メソッドを呼ぶことでも行うことができます。

一定量のメモリを常に占有することになりますが、これは実運用と問題分析の両方を考慮したなかなか優れた機能です。名前からしてバッファリングや蓄積したログのプログラム内で再利用を意図したものと思っている人も多いかもしれません (実際、きちんと説明できている日本語サイトは現時点で皆無)。これは Log4j にもない機能です。

設定ファイルでは以下のプロパティを使用できます。

java.util.logging.MemoryHandler.level (デフォルト: ALL)
このハンドラを使用したログの出力レベル。
java.util.logging.MemoryHandler.filter (デフォルト: Filterなし)
出力レベルよりも詳細な出力判定を行うためのフィルタクラス名。
java.util.logging.MemoryHandler.size (デフォルト: 1000)
循環バッファに保持するログの個数。
java.util.logging.MemoryHandler.push (デフォルト: SEVERE)
push のトリガーとなるログのレベル。
java.util.logging.MemoryHandler.target (必須)
下層の Handler クラス名。

設定ファイル詳細

Logging API の設定ファイルは Java のプロパティファイル形式で記述します。各ハンドラに対する設定はそれぞれのハンドラの説明を参照してください。

handlers
ルートロガーが使用するハンドラクラス名をコンマまたは空白文字で区切って指定します。
.level
ルートロガーの出力レベルを OFF, SEVERE, WARNING, INFO, FINE, FINER, FINEST, ALL からひとつ指定します。
logger-name.handlers
特定のロガー名固有のハンドラクラス名をコンマまたは空白文字で区切って指定します。
logger-name.level
特定のロガー名固有の出力レベルを指定します。設定可能な値は .level と同じです。
logger-name.useParentHandlers
上位のロガーにログ出力を伝播させるかどうか true/false で指定します (Log4j の additivity と似ています)。 true を指定した場合、このロガー名固有のハンドラに行われたログ出力要求が上位のロガーにも行われます。
config
設定ファイル読み込み後にインスタンス化されるクラス名をコンマまたは空白で区切って指定します。このクラスのコンストラクタは設定ファイルでは記述できないロギング構成を行います。

logger-nameLogger のコンストラクタや getLogger() で指定した名前です。これは Java のパッケージのようなピリオド区切りの階層構造として認識され、上位ドメインの設定はサブドメインとなる下位のロガー設定を包含します。

Log4j のように追加で設定されるのではなく、ひとつの設定ファイルを読み込むと以前の設定がリセットされるため、設定ファイルを分割することはできません。

ところで、Handler の指定がクラス名単位になっていることにお気づきでしょうか? これは Logging API の設定ファイルでは出力先の異なる 2 つの FileHandler を記述できないことを意味しており、明らかに設定ファイルのスキームミスです。これを行おうと思ったらコード上のどこかで個別に FileHandler を指定してやるしか方法がありません。

Handler h = new FileHandler("%h/toolkit.log", true);
h.setLevel(Level.INFO);
Logger.getLogger("biz.moyo.tk").addHandler(h);
h = new FileHandler("%h/application.log", true);
h.setLevel(Level.FINEST);
Logger.getLogger("biz.moyo.app").addHandler(h);

さすがにこのままではまずいと思ったのか、プロパティファイルの config という項目に列挙したクラスのコンストラクタでこのような構成処理を行える付け焼刃的な仕様になっています。

他にも各ハンドラの formatter で指定したフォーマッターはデフォルトコンストラクタが呼ばれるだけでパラメータやプロパティを渡せない (汎用フォーマットのパターンが指定できない) など、この設定ファイルに関しては少々機能不備が多い気がします。フレームワークや共通機能に担当を付けられる程度の大きなプロジェクトであれば、標準の設定ファイルの代わりに Log4j の DOMConfiguratorJava™ API リファレンス のような機能を作ってしまった方が良いかもしれません。

以下のような設定ファイルを使用した場合:

# ルートロガー
handlers = java.util.logging.FileHandler
.level = INFO

# ロガー名 biz.moyo.lab.* 固有設定
biz.moyo.lab.handlers = java.util.logging.ConsoleHandler
biz.moyo.lab.level = FINEST

# ロガー名 biz.moyo.app.* 固有設定
biz.moyo.app.handlers = java.util.logging.ConsoleHandler
biz.moyo.app.level = INFO
biz.moyo.app.useParentHandlers = false

java.util.logging.FileHandler.level = ALL
java.util.logging.FileHandler.pattern = %h/application.log
java.util.logging.FileHandler.formatter \
    = java.util.logging.SimpleFormatter
java.util.logging.FileHandler.append = true

java.util.logging.ConsoleHandler.level = ALL
java.util.logging.ConsoleHandler.formatter \
    = java.util.logging.SimpleFormatter

config = biz.moyo.lab.sample.MyClass

getLogger("org.koiroha.example").fine("hello, world") はどこにも出力されません。この名前の対象となるルートロガーが INFO レベルであるためです。

getLogger("biz.moyo.lab.foo.bar").fine("hello, world") はコンソールに "hello, world" と表示しますがファイルには何も出力しません。 FINEST レベルを持つ上位のロガー biz.moyo.lab は有効ですが、さらにその上位であるルートロガーは INFO のためです。

getLogger("biz.moyo.lab.foo.bar").warning("hello, world") はコンソールとファイルに "hello, world" 出力します。上位のロガー全てが WARNING を出力するためです。

getLogger("biz.moyo.app.foo.bar").warning("hello, world") はコンソールに "hello, world" と表示しますがファイルには何も出力しません。 biz.moyo.appuseParentHandlers が false に設定したことにより上位のロガーを起動しないためです。

biz.moyo.lab.sample.MyClass が以下のようなコンストラクタを持つ場合:

public MyClass() {
    System.out.println("コンストラクタ");
}

設定ファイルを読み込ませるたびに標準出力には "コンストラクタ" と表示されます。

CVS 2008/01/30