プロジェクト

全般

プロフィール

Javaプログラミング ロギング

何をログするかをまず決める

ロギングは、プログラムの挙動を記録に残し、動作状況、問題が発生したときの原因探求などの手がかりに使います。
よって、誰が何のための手がかりに使うかを意識して、何をログ(記録)するかを決める必要があります。
これを明確にしないままやみくもにログをしてしまったら、理解不能なログが残るだけです。

複数の開発者が共同で作るソフトウェアであれば、共通設計の一つとしてログ設計を行います。

何をログするのか、ログ設計の一案

ログする内容は、ログの利用者に応じて次のものとする。

システムの利用者/運用者が見るもの

  • システムが運用継続を断念する事象とそのときの状況
  • システムが運用継続可能であるが問題が発生したこととそのときの状況
    問題とは、保守等の処置が必要となる事象、運用/操作の誤り、システム外部との連携におけるエラー等
  • システムが正常に運用しているときの活動
    • 運用観点での処理のシーケンスを追える情報(処理が正常に実行されたこと)
    • 運用の分析に使う事象(リクエスト回数、正常応答回数、データサイズ、など)

開発者がみるもの

  • システム障害の原因を究明するための情報(障害に至る経緯など)
  • ロジックの動作状況(条件分岐のどちらを通ったか、またその分岐の判断材料、など)
  • 開発者観点での処理シーケンス

ロギング方式

ロギングライブラリ

ロギングライブラリの経緯

Javaが登場した1990年代後半は、プロジェクト(アプリケーション、システム)毎に専用のロギングが作られていましたが、2001年にオープンソースライブラリであるlog4jの登場によって共通化が進みました。
このlog4jは実に大ヒットし、C、C++、.NET、Perl、PHPなどさまざまな言語に移植されています。また、log4j以外にも、Logging Toolkit、Logkitなどいくつか汎用なロギングライブラリが登場しました。
Java SEにも標準でロギングAPIを搭載しようとJCPにおいてJSR 47の仕様策定が進められた結果、Java SE 1.4にロギングAPIが搭載されました。

このJSR 47の検討においては、当時広く使われていたlog4jをベースとしてほしいとのプログラマーの声が高かったのですが、残念ながらlog4jベースではなく、IBM logging toolkit for Javaをベースとしたものになりました。そのあたりの経緯は次のURLにあります。

しかし、まだ現場ではJava標準ロギングが搭載されていないJava SE 1.3も使われており、Java SE 1.4以降でも使い勝手がいまいちな点のあるJava標準ロギングよりも手馴れたlog4jの人気は根強く、log4jが引き続き使われていました。

また、Apacheから共通のロギングAPIだけを提供しログライブラリを切り替えるCommons loggingライブラリが登場しました。Commons loggingは、log4j、Java標準ロギング、Logkitに対応しています。この共通APIと複数の実装という設計は、Javaの標準APIの設計ポリシーにマッチしており、Commons loggingとlog4jの組み合わせもよく使われるようになりました(実際にロギング実装を切り替えることは稀だったようですが)。

その後、log4jの開発チーム内で、log4jの開発の方向性をめぐってごたごたがあり、log4jの創始者がlog4jプロジェクトを飛び出し新たにlogbackを開発したり、log5jが作られたり、Commons loggingに続き共通APIライブラリとしてSLF4Jが登場したり、log4jの2.0開発が進められたりと、オープンソースのロギングライブラリは、群雄割拠の様相を呈しながら、APIの洗練・高機能化が進んでいます。

ところが、Java標準ロギングはほとんど進化していないため、次第に機能/性能面で見劣りがしてきています。Java全体としては、EoD(開発の容易化)を進めているのに、開発に重要なロギングが取り残されているのは残念なことです。

ロギングライブラリの主要機能

ロギングライブラリの主要な概念は、ログレベル、ログ種類によるログの制御です。

一般的なロギングライブラリでは、ログの記録に際してログレベル、ログ種類(カテゴリ、ロガー名など)を指定します。
指定したログレベルとログ種類によって、ログの出力有無、ログ出力先(ファイル、ネットワーク、など)、出力書式を制御することができます。
制御には設定ファイルが使われることが多いです。

ログレベルの例

log4jでは、FATAL、ERROR、WARN、INFO、DEBUG、TRACEの6段階です。
Java SE標準では、SEVERE、WARNING、INFO、CONFIG、FINE、FINER、FINESTの7段階です。

ログ種類の例

カテゴリ、ロガー名などで種類を指定します。

  • 開発者がデバッグで使用する場合は、パッケージ名・クラス名を種類の識別子として使用することが大半です。
  • 運用者が使用する場合は、業務シーケンス名などを使用することがあります(あまり広まっていないかもしれない)。
  • 試験/性能計測で使用する場合は、例えば"TEST"とか"ANALYZE"などの名称を識別子として使用することがあります。

パフォーマンスの考慮

システム・アプリケーションにおいてロギングが及ぼす影響として性能のオーバーヘッドがあります。
ロギングは、ログに出力する文字列の合成処理、実行スレッドからクラス名、メソッド名の抽出、ファイル等へのI/Oを行うので、性能への影響があります。

最初に登場したlog4j(バージョン1.x)では、性能対策があまりなく、API利用側で工夫する必要がありました。

log4jで普通にログを出すときは次のコードを書いてしまいますが、これはデバッグレベルのログが無効であっても毎回引数の文字列結合が発生します。

logger.debug("Input A=" + a + ", B=" + b + " Output C=" + c);

そのため、log4jで性能を考慮するには次のように記述することが推奨されています。

if (logger.isDebugEnabled()) {
    logger.debug("Input A=" + a + ", B=" + b + " Output C=" + c);
}

SLF4J(logbackを使うときのアプリケーション側から使用するAPI)では、

logger.debug("Input A={}, B={} Output C={}", a, b, c);

と書くことができ1、文字列の結合をログライブラリの中でログが有効であるときに遅延させることができます。
これはJava SE 5で導入された可変長引数をAPI定義に使用しているからです。

Java標準ロギング(java.util.logging)では、

logger.log(Level.FINE, "Input A={0}, B={1} Output C={2}", new Object[] {a, b, c});

と書くことができ、同様に文字列の結合をログライブラリの中でログが有効であるときに遅延させることができます。
Java SE 5で可変長配列が導入された際、ロギングAPIには見直しが入らなかったのが少々残念です。

Object配列で書く手間を少しでも減らしたいときは、可変長引数配列アダプタのテクニックを紹介した日記 を参照ください。

1 SLF4Jが3つ以上の引数をコード例のように指定できるようになったのは、APIに可変長引数を使用するようになったVer. 1.7.0以降です。それ以前は、2つまではコード例のように記述でき、3つ以上はJava標準ロギングと同様Object型配列に詰めて渡します。なお、可変長引数はObject配列のシンタックスシュガーです。

ロギングライブラリの選択

  1. Java標準ロギングAPI
    外部のライブラリに依存しないので、Java SE単独で動くアプリケーションや、プラグイン構成のアプリケーションなどで依存関係が厳しい場合に有用です。
  2. SLF4J + logback
    ロギングライブラリでモダンな機能を活用したいというときに有用です。依存するライブラリ(JAR)が多いので、実行可能JARファイル1つで配布したいというアプリケーション用途には不向きです。
  3. log4j 2.x
    Ver.1.xはもう古いので、今後使うことを検討するならVer.2.0(2014年2月時点でRC1版)が対象になります。SFL4Jとの組み合わせも可能です。

アスペクト指向ツール

アプリケーションコード中にロギングAPI呼び出しを埋め込むロギングライブラリ方式とは違い、外部ツールから任意の箇所にフックをかけるようにログを出力させる方式です。アスペクト指向プログラミングという、関心事の分離によってログを切り出し指定するものです。

代表的なツールには、AspectJなどの汎用的なアスペクト指向処理ツール、LimpidLog、ByteMan、BTraceなどのBytecode Instrumentationを使ったツールがあります。

過去の日記より

プログラミング

クリップボードから画像を追加 (サイズの上限: 1 GB)