プロジェクト

全般

プロフィール

Java標準ロギング

Java SE標準搭載ライブラリのロギングAPI(java.util.loggingパッケージ)です。JSR 47で仕様化され、Java SE 1.4から搭載されました。
Javaのロギング事情全般については、Javaプログラミング ロギングを参照ください。

Java SE標準ロギングAPIについて以前 Java Logging API として書きました。

Java標準ロギングの機能駆け足説明

Java標準ロギングは、ログレベルによる出力制御およびログ出力先の制御の2つが提供されています。

ログレベル

ログレベルは、次の7段階です。

  • SEVERE
  • WARNING
  • INFO
  • CONFIG
  • FINE
  • FINER
  • FINEST

また、ALL(すべてのレベルを出力)とNONE(すべてのレベルを非出力)があります。

ログ出力先(ハンドラー)

Java標準ロギングがログ出力先として提供するHandlerには次があります。

  • StreamHandler
  • ConsoleHandler
  • FileHander
  • SocketHandler
  • MemoryHandler

なお、ハンドラーにもレベルが設定されます。

ロガー

名前階層を持ったツリーとして構成され、固有のログレベルおよびハンドラーを持つかツリーの親に委譲します。

ロガーの階層

  • デフォルトでルートロガーが生成されます。ルートロガーの名前は""(空文字列)です。
  • グローバルロガーが1つ存在します。グローバルロガーの名前は"global"です。ルートロガーの子です。
  • アプリケーションでLogger.getLogger("com.torutk.hello.HelloApp") とロガーを生成すると、次の階層でロガーが生成されます。
    ルートロガー("")
      +-- ロガー("com")
        +-- ロガー("torutk")
          +-- ロガー("hello")
            +-- ロガー("HelloApp")
    
  • デフォルトでルートロガーにはConsoleHandlerが登録されています。

設定方法(概要)

ロギングの制御は、アプリケーションプログラム内でAPIを呼んで設定する他に、設定ファイルや設定クラスに記載し実行時に指定する方法があります。

APIを使って設定

verboseオプション的な設定

UNIX系のプログラムでは、コマンドラインオプションで例えば"-v"(--verbose)を指定すると詳細なメッセージ(デバッグメッセージ)が出力される、といったものがあります。これを実現するには、プログラム中でコマンドラインを解析してログレベルを設定するコードを書きます。

以下のコードは、ルートロガーとそのハンドラーのレベルを設定する例です。

import java.util.logging.Handler;
import java.util.logging.Level;
import java.util.logging.Logger;

public class MyApp {
    private static final Logger logger = Logger.getLogger(MyApp.class.getName());

    public static void main(String... args) {
        for (int i = 0; i < args.length; i++) {
            if ("-v".equals(args[i]) || "--verbose".equals(args[i])) {
                verboseLogging();
            }
        }
        logger.fine("Hello, MyApp");
    }

    private static void verboseLogging() {
        final Level verbose = Level.FINEST;
        Logger root = Logger.getLogger(""); // ルートロガーの名前は"" 
        root.setLevel(verbose);
        for (Handler handler : root.getHandlers()) {
            handler.setLevel(verbose);
        }
    }
}

設定ファイルを使って設定

Java標準ロギングは、システムプロパティ

java.util.logging.config.file
で指定したパスのファイルからログ設定を読み込むことができます。
システムプロパティのパスは、カレントディレクトリからの相対パスまたは絶対パスで指定します。クラスパスから取得したい場合は、設定クラスを使って設定ファイルを読むという方法があります。

Javaのデフォルト設定ではログはコンソールにINFO以上しか出ないので、それ以外の設定を望むなら自前の設定を定義します。

お決まり設定

まず、handlerでログ出力先を指定します。一般的にはコンソールとファイルの両方に出力します。

handlers = java.util.logging.ConsoleHandler, java.util.logging.FileHandler

次にロガーのレベルを指定します。一般的には全体のレベルをルートロガーに設定しておき、それとは違うレベルを適用したいロガーがあれば個別に設定するやり方を取ります。

ルートロガーにINFOレベル以上(INFO, WARNING, SEVERE)を通すように設定

.level = INFO

アプリケーションの一部のロガーにFINEレベル以上を通すように設定

com.torutk.myapp.control.communication.level = FINE

コンソール出力の設定

java.util.logging.ConsoleHandler.level = FINE

設定ファイルの制約

同一種類のハンドラーを複数設定することができない

設定ファイルの記述は、ハンドラーのクラスに対して内容を記述します。
そのため、ロガーの種類によって異なるファイルにログを出力するといった設定を設定ファイルから行うことができません。
このような場合、プログラム中からAPIを呼び出して設定する必要があります。

設定クラスを使って設定

Java標準ロギングは、システムプロパティ

java.util.logging.config.class
で指定したクラスを呼び出してログ設定を行うことができます。
このクラスはクラスパスに存在する必要があります。

設定クラスの中から設定ファイルを読み込む

設定ファイルの場合、ファイルのパスがカレントディレクトリからの相対パスまたは絶対パスなので、例えば実行可能JARで配布するアプリケーションや、Web Startで実行するアプリケーション、またはWebブラウザ上で実行するアプリケーションなどでは設定ファイルの置き場所を確定させることができません。
そこで、設定ファイルをリソースとして読み込む処理を書いたクラスを設定クラスとして使用するというテクニックが有用です。

次のブログを参考にしました。
今日のAPI: java.util.logging

実行可能JARファイルにおけるログ設定ファイルの適用

実行可能JARファイルでプログラムを作成するととても便利なのですが、ログの設定ファイルを利用すると不便なことがあります。

  • JavaVMのコマンドラインオプションでログ設定ファイルのパスを指定しなければならない

これでは、せっかくダブルクリックで実行できるメリットが失われてしまいます。

そこで、ログ設定ファイルをコマンドラインで指定しないときはJARファイル内に含めたデフォルトのログ設定を適用し、ログ設定ファイルをコマンドラインオプションで指定した場合はそれを適用するという実装をするのがよいです。

実装方針

  • mainメソッドを提供するクラスと同じ場所にデフォルトのログ設定ファイルを作成
  • mainメソッドで、JavaVMコマンドラインオプションでログ設定の指定があるかを判別し、なければデフォルトのログ設定を適用

実装

Mainクラスのソースファイルと同じ場所に、logging.propertiesファイル(名前は一例で、別な名前でも可)を作成します。
NetBeansのデフォルトのプロジェクト構成(Ant)では次の場所になります。

Alfa
  +-- src
        +-- com
              +-- torutk
                    +-- alfa
                          +-- Main.java
                          +-- logging.properties

logging.propertiesにデフォルトの設定を記述します。ここでは、コンソールおよびファイルにログを出力することとし、それぞれレベルをCONFIGおよびALLとします。
ログファイルは、ローテーションなしで固定(再起動時は前のファイルを上書き)とします。

# java.util.logging config file

handlers = java.util.logging.FileHandler, java.util.logging.ConsoleHandler
.level = INFO

java.util.logging.ConsoleHandler.level = CONFIG
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter

java.util.logging.SimpleFormatter.format = %1$tT.%1$tL %4$s %3$s - %5$s %6$s%n

java.util.logging.FileHandler.level = ALL
java.util.logging.FileHandler.pattern = Alfa.log
java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter

com.torutk.alfa.level = ALL
  • handlersで、ファイルおよびコンソールへログを出力するよう指定しています。
  • .levelは、ルートロガーのログ出力レベルをINFOに指定しています。後ほど、個別に名前付きロガーでレベルを指定しない場合これが適用されます。
  • コンソールへの出力は、ロガーのレベルに関わらずCONFIG以上としています(詳細なログはコンソールには出さない)。
  • コンソールへの出力形式は、java.util.logging.SimpleFormatterを適用し、出力する文字列を次のように指定しています。
    YYYY-mm-ddTHH:MM:SS.SSS レベル ロガー名 - メッセージ 例外メッセージ

    書式については、java.util.logging.SimpleFormatterクラスのformatメソッドのjavadoc APIを参照
  • ファイルへの出力は、ロガーのレベルに関わらずALLとしています。
  • ログファイルの名前は、Alfa.logとし、カレントディレクトリに生成します。
  • ファイルへの出力形式は、java.util.logging.SimpleFormatterを適用します。出力する文字列は上述の設定が適用されます。
  • com.torutk.alfaのロガー名とそれ以下の階層のロガー名については出力レベルをALLとしています。(指定しないと、ルートロガーの出力levelが適用される)

mainメソッドにログ初期化コードを記述します。

package com.torutk.alfa;

public class Main {

    public static void main(String[] args) {
        if (System.getProperty("java.util.logging.config.file") == null && System.getProperty("java.util.logging.config.class") == null) {
            try (InputStream resource = Main.class.getResourceAsStream("logging.properties")) {
                if (resource != null) {
                    LogManager.getLogManager().readConfiguration(resource);
                }
            } catch (IOException ex) {
                // continue processing with default logging configuration.
            }
        }
        :
    }
    :
}
  • logging.propertiesファイルを置き忘れると、readConfigurationメソッドの中でNullPointerExceptionが発生します。
    → getResourceAsStream()の戻り値を変数に受けてnullチェックを追加
  • getResourceAsStream()の戻り値は明示的にcloseを呼ばないとリソースリークになります。
    → try-with-resource構文で確実にcloseされるように置き換え

デフォルトのログ出力様式を変えたい

Javaの標準ロギングは、デフォルトでは次のようになっています。

11月 12, 2022 3:35:49 午後 com.torutk.weather.ui.SensorDistributorUi startSensing
情報: start distributing

  • タイムスタンプがロケールにより書式が変わる
  • 2行に渡る

ログファイルを検索・抽出・加工する際、タイムスタンプの書式が扱いずらい、2行に渡るので処理が手間、とあまりうれしい形式ではありません。

出力様式をシステムプロパティで指定

デフォルトのログは、java.util.logging.SimpleFormatterクラスのデフォルト設定で出力されます。この設定は、システムプロパティで変更することができます。

D:\work> java "-Djava.util.logging.SimpleFormatter.format=%1$tY-%1$tm-%1$tdT%1$tH:%1$tM:%1$tS %4$s %2$s %5$s%6$s%n" Main

2022-11-12T15:49:46 情報 com.torutk.weather.ui.SensorDistributorUi startSensing start distributing

ログの使い方

ロガー名について

通常は、ログするクラスのFQCN(Fully Qualified Class Name)をロガー名にします。こうすることで、ログの出力有無を制御するときに、パッケージ名・クラス名の階層単位で制御が可能となります。

パッケージ名・クラス名の階層とは異なる制御をしたいログ事象、例えば性能計測用のログでまとめて出力有無を制御したいとき、などは、専用のロガー名を使います。

ログレベルについて

ログレベルは7段階(ALLとNONEを除いて)あるので、使い分けの基準を決めておかないと都度悩んでしまいます。
ぜひプロジェクト、組織でログ基準を策定しましょう。

ログレベル基準の例

  • アプリケーション層
    • エラーが発生した場合:WARNING
    • チェックポイントの通過を記録(正常系):INFO
    • アプリケーション全体で使用するデバッグ:FINE
    • パッケージ、クラス単体でのデバッグ:FINERおよびFINEST
      • 頻繁に呼ばれる箇所(短時間の周期的)に呼ばれる箇所はFINEST
  • フレームワーク層やシステム層
    • システム障害:SEVERE
    • システムの構成、設定のログ:CONFIG

運用ではINFO以上とし、必要に応じてCONFIG、FINEとレベルを下げます。

コーディング例

System.out.printの代替としてのログ(ログレベルだけの制御)

小さなアプリケーションを作成していて、printデバッグをしているところ(個人または組織)にいきなり正式なロギングを持ち込んでも「面倒くさい」となるだけなので、そのときは設定ファイルも事前のLogger定義も不要なglobalロガーを使ったログを行います(ロギングAPIを使いこなす第一歩として)。

import java.util.logging.Logger;

public class MyApp {
    public static void main(String[] args) {
        Logger.getGlobal().info("Starting MyApp");
        // ...
    }
}
  • 注記)Java SE 7では既知のバグとしてこのコード例ではコンソールにログが出力されません。

printデバッグの問題点に、ある程度開発が進んで一通り動作するようになったらprint文が邪魔になるのでprint文をコメントアウトするか削除する、何かバグが発生したらprint文を再度有効にする(か入れなおす)ということを繰り返すということがあります。
ロギングAPIを使用していれば、不要になった時点で設定ファイルにログレベルを指定して読ませる(コードの追加不要)ことで、ログ出力の有効/無効が制御できます。

ラムダ式

よくあるバグ

Loggerをstaticフィールドに定義したクラスをコピー&ペーストしたのでロガー名を間違えた

Logger名を文字列でハードコードした

文字列のプレースホルダ


ほぼ2年前に更新