プロジェクト

全般

プロフィール

Wiki » Java » Javaプログラミング »

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では、

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配列のシンタックスシュガーです。

また、Java SE 8で導入されたラムダ式を用いて文字列結合を遅延させる方法も登場しました。
ラムダ式の場合、文字列結合の遅延だけでなく、ログ出力メソッドの引数にメソッド呼び出し式がある場合にもその呼び出しを遅延させることが可能です。
log4j2 ではバージョン2.4以降で利用可能に、SLF4Jではバージョン2から利用可能に、Java標準ロギングではJava SE 8（ラムダ式が導入されたJavaバージョン）で利用可能です。

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

  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を使ったツールがあります。

過去の日記より

プログラミング

ログの出し方いろいろ

ログメッセージ

文字コードセットはASCII文字

ログメッセージは、いろいろな環境で見ることになるので、ログメッセージに使用する文字はASCII文字（ISO/IEC 646）に限定するのがよいです。

ログレベル

ログの各レベルは、そのログがどのような時に誰のために行われるかをそのシステム（アプリケーション）内で一貫するために基準を設けます。以下は基準の一例です。

レベル ログ閲覧者 どんな時に
FATAL システムの運用者（管理者） 運用者に可及的速やかに通知し即時の対応が必要な致命的な事象
ERROR 運用者に通知し、何らかの対応が必要な問題事象
WARN 運用者に定期報告等で知らせ、記録に留めておくべき事象
INFO 定常に実行されていることを後の解析1に利用できるよう記録に留めておくべき事象
DEBUG システム保守担当者 問題事象を究明するためにシステム内部の状態や振る舞いを細かく出力する。通常はオフ
TRACE システム開発者、試験担当者 ソフトウェアの開発、試験に使用する。

1 後の解析の例
問題事象が発生したときにログを解析し、どこまで正常に処理が実行され、どこからが正常でないかを切り分ける
システムの運用負荷を調査するため、処理の実行頻度を統計処理する、処理の開始～終了までの時間を測る

システムの運用者（管理者）が閲覧するということは、システムのユーザーインタフェースの一部を成すことになります。したがって、ログに出力するメッセージは、画面に表示するものに準じて作成することが必要です。

パフォーマンスの考慮

ログ出力時に時間のかかる処理要素をいかに省くか、となります。

ほぼ4年前に更新