Java : ロギング(ログ出力)の基本

Tweet

ロギング(ログ出力)は、不具合の解析においてとても重要な要素です。
特に再現度の低い不具合なんかは、ログがないと解析が難航することも多いでしょう。

本記事では、Javaの標準APIを使ったロギングの基本を解説します。

概要

上記はロギングについての公式ドキュメントになります。

ロギングとは、プログラムでなにかが起こったときに、その情報を時系列順に出力していくことをいいます。
出力された情報をログといいます。

ロギングというと、少し難しそうに感じるかもしれません。
しかし、Javaを触ったことのあるかたは、ロギングっぽいことは経験していると思います。

それは System.out.println メソッドです。
使ったことがあるかたも多いのではないでしょうか。

final var s = "abcde";
System.out.println("変換前 :" + s);

final var upperCase = s.toUpperCase();
System.out.println("変換後 :" + upperCase);

// 結果
// ↓
//変換前 :abcde
//変換後 :ABCDE

これも大きな意味ではログといってもいいでしょう。
コンソールに対して、時系列順に情報を出力しているためです。

そして、ロギングAPIとは、System.out.println をもう少し便利に、高機能にしたものです。
コンソール以外には、ファイルやネットワーク(ソケット)へ出力することもできます。

簡単なコード例

それでは実際にコード例を見てみましょう。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);

logger.addHandler(new ConsoleHandler());

logger.log(Level.INFO, "ログテスト！");

// 結果
// ↓
//10月 07, 2021 1:30:06 午後 com.example.logging.LoggingBasicTest codeExample
//情報: ログテスト！

ログ出力の大まか流れは…

1. Logger.getLogger で、ロガーの名前を指定して Logger オブジェクトを取得
2. addHandler メソッドで、Handler を追加
3. log メソッドでログを出力

となります。

Handlerは、ログをどこに出力するのか？を表すクラスです。
上記の例では ConsoleHandler を使い、ログをコンソールに出力させています。

logger.log(Level.INFO, "ログテスト！");

logメソッドに、ログの Level とメッセージを指定すると、

10月 07, 2021 1:30:06 午後 com.example.logging.LoggingBasicTest codeExample
情報: ログテスト！

という感じで、コンソールにログが出力されます。
指定したログレベル(Level.INFO = "情報") とメッセージ以外にも

• 日時
• ログを出力したクラス名とメソッド名

が付加情報として出力されます。

Logger は、ロギングAPIの中心となるクラスです。

ログをどこに出力するのか？を表すハンドラを持ち、どのレベルまでのログを出力するのか？を表すログレベル を持ちます。
ちなみに、ハンドラは複数持てます。(例えば、コンソールとファイル両方に出力させたい場合など)

そして、実際にログ出力を要求するメソッドを持ちます。
ログ出力用のメソッドはさまざまなものが用意されています。

基本となるのは log メソッドです。
ログレベルとメッセージを指定してログ出力を要求します。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);
logger.setLevel(Level.ALL); // すべてのレベルのログを出力させます。

final var handler = new ConsoleHandler();
handler.setLevel(Level.ALL); // すべてのレベルのログを出力させます。
logger.addHandler(handler);

logger.log(Level.SEVERE, "SERVERログ！");
logger.log(Level.WARNING, "WARNINGログ！");
logger.log(Level.INFO, "INFOログ！");
logger.log(Level.CONFIG, "CONFIGログ！");
logger.log(Level.FINE, "FINEログ！");
logger.log(Level.FINER, "FINERログ！");
logger.log(Level.FINEST, "FINESTログ！");

// 結果
// ↓
//9月 30, 2021 3:51:56 午後 com.example.logging.LoggerTest log
//重大: SERVERログ！
//9月 30, 2021 3:51:56 午後 com.example.logging.LoggerTest log
//警告: WARNINGログ！
//9月 30, 2021 3:51:56 午後 com.example.logging.LoggerTest log
//情報: INFOログ！
//9月 30, 2021 3:51:56 午後 com.example.logging.LoggerTest log
//構成: CONFIGログ！
//9月 30, 2021 3:51:56 午後 com.example.logging.LoggerTest log
//普通: FINEログ！
//9月 30, 2021 3:51:56 午後 com.example.logging.LoggerTest log
//詳細: FINERログ！
//9月 30, 2021 3:51:56 午後 com.example.logging.LoggerTest log
//最も詳細: FINESTログ！

もしくは、各ログレベルに応じたメソッドも用意されています。
例えば、Level.INFO には info、Level.FINE には fine といった感じです。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);
logger.setLevel(Level.ALL); // すべてのレベルのログを出力させます。

final var handler = new ConsoleHandler();
handler.setLevel(Level.ALL); // すべてのレベルのログを出力させます。
logger.addHandler(handler);

logger.severe("SERVERログ！");
logger.warning("WARNINGログ！");
logger.info("INFOログ！");
logger.config("CONFIGログ！");
logger.fine("FINEログ！");
logger.finer("FINERログ！");
logger.finest("FINESTログ！");

// 結果
// ↓
//9月 30, 2021 1:26:00 午後 com.example.logging.LoggerTest info
//重大: SERVERログ！
//9月 30, 2021 1:26:00 午後 com.example.logging.LoggerTest info
//警告: WARNINGログ！
//9月 30, 2021 1:26:00 午後 com.example.logging.LoggerTest info
//情報: INFOログ！
//9月 30, 2021 1:26:00 午後 com.example.logging.LoggerTest info
//構成: CONFIGログ！
//9月 30, 2021 1:26:00 午後 com.example.logging.LoggerTest info
//普通: FINEログ！
//9月 30, 2021 1:26:00 午後 com.example.logging.LoggerTest info
//詳細: FINERログ！
//9月 30, 2021 1:26:00 午後 com.example.logging.LoggerTest info
//最も詳細: FINESTログ！

他には、例外を出力するためのメソッドもあります。
スタックトレースも出力してくれるのでとても便利ですね。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);
logger.addHandler(new ConsoleHandler());

try {
    final var path = Path.of("R:", "java-work", "sample.txt");

    // 意図的に例外を発生させます。
    Files.readString(path);

} catch (IOException e) {
    logger.log(Level.WARNING, "ファイル読み込み失敗", e);
}

// 結果
// ↓
//10月 11, 2021 8:28:16 午後 com.example.logging.LevelGuideline testWarning
//警告: ファイル読み込み失敗
//java.nio.file.NoSuchFileException: R:\java-work\sample.txt
//	at java.base/sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:85)
// ... 省略 ...

ロギングAPIでは、Level によってログを出力する/しないを制御できます。

例えば、

• 開発中は詳細なログまで出力
• リリース版では必要最低限のログのみ出力

という制御が可能になります。

ログの１件１件にレベルを紐づけて、それらのログを、ロガーとハンドラがどのレベルまで出力するのか？という判断をします。

Levelクラスには、以下のレベルが定義されています。
上から順に優先度 (重要度) が高くなります。

• SEVERE (最高値)
• WARNING
• INFO
• CONFIG
• FINE
• FINER
• FINEST (最低値)

他には、ALL (すべてのログを出力) と OFF (すべてのログを出力しない) があります。

ログレベルの使い分け…どんなときにどのレベルのログを出力するべきか？という指針については、別途記事にしました。

• ログレベルの指針 (使い分け)

こちらもご参照ください。

コード例

ログレベルは、ロガーとハンドラそれぞれに設定できます。
レベルを設定すると、設定したレベル以上のログが出力されるようになります。（つまり設定したレベル未満のログは出力されません）

ハンドラごとにログレベルが設定できるので、

• コンソールには重要なログだけ出力
• ファイルにはすべてのログを出力

というような制御が可能です。

ログレベルは、まずロガーのレベルで判定され、次にハンドラのレベルが判定されます。

コード例で見ていきましょう。
下記のコードは、ロガーとハンドラともに、レベルを ALL に設定した例です。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);

// コンソールハンドラ
final var consoleHandler = new ConsoleHandler();
logger.addHandler(consoleHandler);

// ファイルハンドラ
final var pattern = Path.of("R:", "java-work", "log.txt");
final var fileHandler = new FileHandler(pattern.toString());
fileHandler.setFormatter(new SimpleFormatter());
logger.addHandler(fileHandler);

logger.setLevel(Level.ALL);
consoleHandler.setLevel(Level.ALL);
fileHandler.setLevel(Level.ALL);

logger.log(Level.SEVERE, "SERVERログ！");
logger.log(Level.WARNING, "WARNINGログ！");
logger.log(Level.INFO, "INFOログ！");
logger.log(Level.CONFIG, "CONFIGログ！");
logger.log(Level.FINE, "FINEログ！");
logger.log(Level.FINER, "FINERログ！");
logger.log(Level.FINEST, "FINESTログ！");

// 結果 (コンソール)
// ↓
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//重大: SERVERログ！
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//警告: WARNINGログ！
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//情報: INFOログ！
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//構成: CONFIGログ！
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//普通: FINEログ！
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//詳細: FINERログ！
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//最も詳細: FINESTログ！

// 結果 (ファイル)
// ↓
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//重大: SERVERログ！
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//警告: WARNINGログ！
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//情報: INFOログ！
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//構成: CONFIGログ！
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//普通: FINEログ！
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//詳細: FINERログ！
//10月 14, 2021 1:24:05 午後 com.example.logging.LoggingBasicTest level1
//最も詳細: FINESTログ！

すべてのレベルのログが出力されました。
次に、個別にレベルを設定してみます。

logger.setLevel(Level.ALL);
consoleHandler.setLevel(Level.INFO);
fileHandler.setLevel(Level.FINE);

... 省略 ...

// 結果 (コンソール)
// ↓
//10月 14, 2021 1:25:20 午後 com.example.logging.LoggingBasicTest level2
//重大: SERVERログ！
//10月 14, 2021 1:25:20 午後 com.example.logging.LoggingBasicTest level2
//警告: WARNINGログ！
//10月 14, 2021 1:25:20 午後 com.example.logging.LoggingBasicTest level2
//情報: INFOログ！

// 結果 (ファイル)
// ↓
//10月 14, 2021 1:25:20 午後 com.example.logging.LoggingBasicTest level2
//重大: SERVERログ！
//10月 14, 2021 1:25:20 午後 com.example.logging.LoggingBasicTest level2
//警告: WARNINGログ！
//10月 14, 2021 1:25:20 午後 com.example.logging.LoggingBasicTest level2
//情報: INFOログ！
//10月 14, 2021 1:25:20 午後 com.example.logging.LoggingBasicTest level2
//構成: CONFIGログ！
//10月 14, 2021 1:25:20 午後 com.example.logging.LoggingBasicTest level2
//普通: FINEログ！

コンソールには INFO まで、ファイルには FINE まで出力されます。

logger.setLevel(Level.OFF);
consoleHandler.setLevel(Level.INFO);
fileHandler.setLevel(Level.FINE);

... 省略 ...

// 結果（コンソール）
// ↓
//<なにも出力されません>

// 結果（ファイル）
// ↓
//<なにも出力されません>

ロガーのレベルが OFF なので、コンソールにもファイルにもなにも表示されません。

補足

ロガーのレベルには null を設定できます。
その場合、親ロガーのレベルが使われます。(親ロガーのレベルもnullであればさらに親をたどります)
また、logger.setUseParentHandlers(false) を設定していても親ロガーのレベルが使われます。

ハンドラのレベルには null は設定できません。
必ず何かしらのレベルが設定されています。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);

final var parent = Logger.getLogger("com.example");
System.out.println(logger.getParent() == parent); // true

// ロガー(子)のデフォルトのレベルは null
System.out.println(logger.getLevel()); // null

// 親のロガーのレベルを WARNING に設定します。
parent.setLevel(Level.WARNING);
System.out.println(parent.getLevel()); // WARNING

// コンソールハンドラのデフォルトのレベルは INFO
final var handler = new ConsoleHandler();
System.out.println(handler.getLevel()); // INFO

logger.addHandler(handler);

logger.log(Level.SEVERE, "SERVERログ！");
logger.log(Level.WARNING, "WARNINGログ！");
logger.log(Level.INFO, "INFOログ！");
logger.log(Level.CONFIG, "CONFIGログ！");
logger.log(Level.FINE, "FINEログ！");
logger.log(Level.FINER, "FINERログ！");
logger.log(Level.FINEST, "FINESTログ！");

// 結果 (コンソール)
// ↓
//10月 15, 2021 12:48:47 午後 com.example.logging.LoggingBasicTest level_parent
//重大: SERVERログ！
//10月 15, 2021 12:48:47 午後 com.example.logging.LoggingBasicTest level_parent
//警告: WARNINGログ！

ロガー(子)のレベルは null ですが、ロガー(親)のレベルの WARNING まで出力されます。

Handlerは、どこにログを出力するのか？を表すクラスです。

標準APIにはサブクラスがいくつか用意されています。
よく使うのは

• ConsoleHandler : コンソールへ出力
• FileHandler : ファイルへ出力

この２つかな、と思います。

また、Handlerクラスは独自実装がしやすい設計となっています。
例えば、重要なエラーが発生したときにメールで通知したい…という場合、MailHandlerを独自に作るのもよいかもしれませんね。

ハンドラは、ロガーと同じようにログレベルを持ちます。
そして、どのようにログを整形して出力するのか？を表すフォーマッタを持ちます。

コンソールハンドラ

ConsoleHandler は、ログを

• コンソール (標準エラー出力 : System.err )

に出力するハンドラです。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);

final var handler = new ConsoleHandler();
logger.addHandler(handler);

// デフォルトの設定
System.out.println(handler.getLevel()); // INFO
System.out.println(handler.getFormatter()); // java.util.logging.SimpleFormatter@4280b7c4

logger.log(Level.INFO, "ログテスト！");

// 結果 (コンソール)
// ↓
//10月 07, 2021 5:00:11 午後 com.example.logging.LoggingBasicTest consoleHandler
//情報: ログテスト！

コンソールハンドラのデフォルト設定は

• レベル : INFO
• フォーマッタ : SimpleFormatter

となっています。

よって、デフォルトのままだと Level.FINE のログが出力されず、あれれ？となるのでご注意ください。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);
logger.setLevel(Level.ALL);

final var handler = new ConsoleHandler();
logger.addHandler(handler);

logger.fine("FINEテスト : 1");

// 結果
// ↓
//<なにも表示されません>

handler.setLevel(Level.FINE);

logger.fine("FINEテスト : 2");

// 結果
// ↓
//10月 07, 2021 5:40:20 午後 com.example.logging.LoggingBasicTest consoleHandler2
//普通: FINEテスト : 2

ファイルハンドラ

FileHandler は、ログを

• ファイル

へ出力するハンドラです。

設定により、

• 1つのファイルへ、サイズ無制限にログを書き込む
• サイズを制限した複数のファイルへ、ローテーションしてログを書き込む

ということが可能です。

どちらかというと、後者で使うことが多いのかなと思います。
(前者だと、いずれストレージ容量が足りなくなるため)

final var pattern = Path.of("R:", "java-work", "log.txt");
final var handler = new FileHandler(pattern.toString(), true);

// デフォルトの設定
System.out.println(handler.getLevel()); // ALL
System.out.println(handler.getFormatter()); // java.util.logging.XMLFormatter@6c3916e7

ファイルハンドラのデフォルト設定は

• レベル : ALL
• フォーマッタ : XMLFormatter

となります。

出力がXML形式なので、テキストエディタで見るにはちょっとつらいですね。
具体的には次のような形式で出力されます。

<!DOCTYPE log SYSTEM "logger.dtd">
<log>
<record>
  <date>2021-10-08T04:10:59.037527700Z</date>
  <millis>1633666259037</millis>
  <nanos>527700</nanos>
  <sequence>1</sequence>
  <logger>com.example.logging</logger>
  <level>INFO</level>
  <class>com.example.logging.LoggingBasicTest</class>
  <method>fileHandler1</method>
  <thread>16</thread>
  <message>ログテスト！</message>
</record>
</log>

XMLFormatterを使うのであれば、なにかしらのログ解析用のツールを使って読み込むのが前提になりそうです。

１つのファイル（サイズ無制限）の例

１つのファイル（サイズ無制限）の例を見てみましょう。
フォーマッタは見やすさのために SimpleFormatter に変更します。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);

final var pattern = Path.of("R:", "java-work", "log.txt");
System.out.println(pattern); // R:\java-work\log.txt

final var handler = new FileHandler(pattern.toString(), true);
handler.setFormatter(new SimpleFormatter());
logger.addHandler(handler);

logger.info("ログテスト！");

// 結果 (PowerShell)
// ↓
//PS R:\java-work> cat .\log.txt
//10月 08, 2021 1:35:02 午後 com.example.logging.LoggingBasicTest fileHandler1
//情報: ログテスト！

final var pattern = Path.of("R:", "java-work", "log.txt");
System.out.println(pattern); // R:\java-work\log.txt

final var handler = new FileHandler(pattern.toString(), true);

まずは FileHandler のコンストラクタで、ファイル名と追加モード(append = true)を指定してインスタンスを作成します。
追加モードを true にしないと、アプリを再起動してログを書き込むと、前回のログは上書きで削除されてしまうのでご注意ください。

あとは、コンソールハンドラと同じように、Loggerでログ出力を要求すると、ログはファイルへと出力されます。

複数のファイル（サイズ制限あり）の例

例として、"log_%g.txt" というファイル名のパターンを使います。
%g は、ローテーションを識別する番号です。0からの連番が振られます。

ログファイルは最大３つ使うようにしてみます。

流れとしては…

1. まずは最初のファイル(log_0.txt)へログを出力
2. log_0.txt がサイズ制限になったら…
   1. log_0.txt を log_1.txt へリネーム
   2. log_0.txt を新規作成
3. log_0.txt へログを出力
4. log_0.txt がサイズ制限になったら…
   1. log_1.txt を log_2.txt へリネーム
   2. log_0.txt を log_1.txt へリネーム
   3. log_0.txt を新規作成

という感じで繰り返します。
…言葉ではわかりづらいかもなので、下記の図もご参照ください。

ロガーは常に最初のログファイル名(log_0.txt)に対してログを出力します。
よって、%g の番号が小さいファイルほど、新しいログが出力されていることになります。

具体的なコード例でも見てみましょう。
ファイルサイズは 1024バイト、ファイル数は 3、あと分かりやすさのためにフォーマッタを独自実装しています。

// SimpleFormatterよりさらに見やすさを重視したフォーマッタを定義します。
class MoreSimpleFormatter extends Formatter {
    @Override
    public String format(LogRecord record) {
        final var message = formatMessage(record);
        return record.getLevel() + " : " + message + "\n";
    }
}

final var pattern = Path.of("R:", "java-work", "log_%g.txt");
System.out.println(pattern); // R:\java-work\log_%g.txt

// ファイルサイズ 1024 バイト、ファイル数は 3、append = true
final var handler = new FileHandler(pattern.toString(), 1024, 3, true);
handler.setFormatter(new MoreSimpleFormatter());

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);
logger.addHandler(handler);

for (int i = 0; i < 30; i++) {
    logger.info("ログテスト : " + i);
}

// この時点でのファイルの状態。
// --- PowerShell ---
//PS R:\java-work> ls
// ...
//Mode                 LastWriteTime         Length Name
//----                 -------------         ------ ----
//-a---          2021/10/15    13:23            830 log_0.txt
//-a---          2021/10/15    13:22              0 log_0.txt.lck
//
//PS R:\java-work> cat .\log_0.txt
//INFO : ログテスト : 0
//INFO : ログテスト : 1
// ... 省略 ...
//INFO : ログテスト : 28
//INFO : ログテスト : 29

for (int i = 30; i < 60; i++) {
    logger.info("ログテスト : " + i);
}

// この時点でのファイルの状態。
// --- PowerShell ---
//PS R:\java-work> ls
// ...
//Mode                 LastWriteTime         Length Name
//----                 -------------         ------ ----
//-a---          2021/10/15    13:24            644 log_0.txt
//-a---          2021/10/15    13:24              0 log_0.txt.lck
//-a---          2021/10/15    13:24           1026 log_1.txt
//
//PS R:\java-work> cat .\log_0.txt
//INFO : ログテスト : 37
//INFO : ログテスト : 38
// ... 省略 ...
//INFO : ログテスト : 58
//INFO : ログテスト : 59
//
//PS R:\java-work> cat .\log_1.txt
//INFO : ログテスト : 0
//INFO : ログテスト : 1
// ... 省略 ...
//INFO : ログテスト : 35
//INFO : ログテスト : 36

for (int i = 60; i < 90; i++) {
    logger.info("ログテスト : " + i);
}

// この時点でのファイルの状態。
// --- PowerShell ---
//PS R:\java-work> ls
// ...
//Mode                 LastWriteTime         Length Name
//----                 -------------         ------ ----
//-a---          2021/10/15    13:24            448 log_0.txt
//-a---          2021/10/15    13:24              0 log_0.txt.lck
//-a---          2021/10/15    13:24           1036 log_1.txt
//-a---          2021/10/15    13:24           1026 log_2.txt
//
//PS R:\java-work> cat .\log_0.txt
//INFO : ログテスト : 74
//INFO : ログテスト : 75
// ... 省略 ...
//INFO : ログテスト : 88
//INFO : ログテスト : 89
//
//PS R:\java-work> cat .\log_1.txt
//INFO : ログテスト : 37
//INFO : ログテスト : 38
// ... 省略 ...
//INFO : ログテスト : 72
//INFO : ログテスト : 73
//
//PS R:\java-work> cat .\log_2.txt
//INFO : ログテスト : 0
//INFO : ログテスト : 1
// ... 省略 ...
//INFO : ログテスト : 35
//INFO : ログテスト : 36

for (int i = 90; i < 120; i++) {
    logger.info("ログテスト : " + i);
}

// この時点でのファイルの状態。
// --- PowerShell ---
//PS R:\java-work> ls
// ...
//Mode                 LastWriteTime         Length Name
//----                 -------------         ------ ----
//-a---          2021/10/15    13:24            261 log_0.txt
//-a---          2021/10/15    13:24              0 log_0.txt.lck
//-a---          2021/10/15    13:24           1047 log_1.txt
//-a---          2021/10/15    13:24           1036 log_2.txt
//
//
//PS R:\java-work> cat .\log_0.txt
//INFO : ログテスト : 111
//INFO : ログテスト : 112
// ... 省略 ...
//INFO : ログテスト : 118
//INFO : ログテスト : 119
//
//PS R:\java-work> cat .\log_1.txt
//INFO : ログテスト : 74
//INFO : ログテスト : 75
// ... 省略 ...
//INFO : ログテスト : 109
//INFO : ログテスト : 110
//
//PS R:\java-work> cat .\log_2.txt
//INFO : ログテスト : 37
//INFO : ログテスト : 38
// ... 省略 ...
//INFO : ログテスト : 72
//INFO : ログテスト : 73

Formatter は、ログをどのように整形して出力するのか？を表すクラスです。
標準APIでは、SimpleFormatter と XMLFormatter が用意されています。

SimpleFormatterの例です。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);

// コンソールハンドラのデフォルトのフォーマッタはSimpleFormatterとなります。
final var handler = new ConsoleHandler();
System.out.println(handler.getFormatter()); // java.util.logging.SimpleFormatter@d76b01a

logger.addHandler(handler);

logger.info("ログテスト : 1");
logger.info("ログテスト : 2");
logger.info("ログテスト : 3");

// 結果
// ↓
//10月 14, 2021 2:18:21 午後 com.example.logging.LoggingBasicTest simpleFormatter
//情報: ログテスト : 1
//10月 14, 2021 2:18:21 午後 com.example.logging.LoggingBasicTest simpleFormatter
//情報: ログテスト : 2
//10月 14, 2021 2:18:21 午後 com.example.logging.LoggingBasicTest simpleFormatter
//情報: ログテスト : 3

1件のログに対して、2行のプレーンテキストが出力されます。
ログメッセージの他に、ログレベル、日時、クラス名、メソッド名が付加情報として出力されます。

次にXMLFormatterの例です。
Handler の setFormatter メソッドでフォーマッタを指定します。

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);

final var handler = new ConsoleHandler();
handler.setFormatter(new XMLFormatter());
System.out.println(handler.getFormatter()); // java.util.logging.XMLFormatter@5b982a69

logger.addHandler(handler);

logger.info("ログテスト : 1");
logger.info("ログテスト : 2");

// 結果
// ↓
//<?xml version="1.0" encoding="UTF-8" standalone="no"?>
//<!DOCTYPE log SYSTEM "logger.dtd">
//<log>
//<record>
//  <date>2021-10-14T05:19:12.080218800Z</date>
//  <millis>1634188752080</millis>
//  <nanos>218800</nanos>
//  <sequence>1</sequence>
//  <logger>com.example.logging</logger>
//  <level>INFO</level>
//  <class>com.example.logging.LoggingBasicTest</class>
//  <method>xmlFormatter</method>
//  <thread>16</thread>
//  <message>ログテスト : 1</message>
//</record>
//<record>
//  <date>2021-10-14T05:19:12.086216300Z</date>
//  <millis>1634188752086</millis>
//  <nanos>216300</nanos>
//  <sequence>2</sequence>
//  <logger>com.example.logging</logger>
//  <level>INFO</level>
//  <class>com.example.logging.LoggingBasicTest</class>
//  <method>xmlFormatter</method>
//  <thread>16</thread>
//  <message>ログテスト : 2</message>
//</record>

1件のログに対して、1件の record 要素が出力されます。
sequenceやthreadが追加されるなど、SimpleFormatterより詳細な情報となります。

独自のフォーマッタを使う例

個人的にですが、SimpleFormatter は１件のログに対して２行出力されるのが、ちょっと見づらく感じます。
grep するときにも使いづらいのですよね。

そんなときは独自のフォーマッタを定義してみましょう。
Formatterクラスを継承して、formatメソッドをオーバーライドします。

// １件のログを１行で出力するフォーマッタ。
class MyFormatter extends Formatter {
    private static final DateTimeFormatter DATE_TIME_FORMATTER =
            DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss.nnnnnnnnn");

    @Override
    public String format(LogRecord logRecord) {
        final var message = formatMessage(logRecord);
        final var time = ZonedDateTime.ofInstant(logRecord.getInstant(), ZoneId.systemDefault());
        return "%s (%s) : %s\n".formatted(
                time.format(DATE_TIME_FORMATTER), logRecord.getLevel().getName(), message);
    }
}

final var logger = Logger.getLogger("com.example.logging");
logger.setUseParentHandlers(false);

final var handler = new ConsoleHandler();
logger.addHandler(handler);

handler.setFormatter(new MyFormatter());

for (int i = 0; i < 10; i++) {
    logger.info("ログテスト : " + i);
}

// 結果
// ↓
//2021-10-08 17:48:11.858628000 (INFO) : ログテスト : 0
//2021-10-08 17:48:11.858628000 (INFO) : ログテスト : 1
//2021-10-08 17:48:11.859628400 (INFO) : ログテスト : 2
//2021-10-08 17:48:11.859628400 (INFO) : ログテスト : 3
//2021-10-08 17:48:11.860627600 (INFO) : ログテスト : 4
//2021-10-08 17:48:11.860627600 (INFO) : ログテスト : 5
//2021-10-08 17:48:11.860627600 (INFO) : ログテスト : 6
//2021-10-08 17:48:11.861626900 (INFO) : ログテスト : 7
//2021-10-08 17:48:11.861626900 (INFO) : ログテスト : 8
//2021-10-08 17:48:11.861626900 (INFO) : ログテスト : 9

無事に、１件のログが１行として出力されました。

Loggerは、ロガー名による名前空間によって階層構造を作ります。
例えば、"com.example.logging" という名前のロガーは、下記の図のような親子構造を持ちます。

ただし、ロガーの階層構造は、必要となった時に初めて作られます。
少しわかりづらいので、コード例で見てみましょう。

final var loggerA = Logger.getLogger("com.example.logging");
System.out.println(loggerA.getName()); // "com.example.logging"

// 最初はルートロガーが親となります。
final var root = loggerA.getParent();
System.out.println(root.getName()); // ""

final var loggerB = Logger.getLogger("com.example");
System.out.println(loggerB.getName()); // "com.example"

// 名前空間として親となるロガーが作成されると、自動的に親が設定されます。
final var parentA = loggerA.getParent();
System.out.println(parentA.getName()); // "com.example"
System.out.println(parentA == loggerB); // true

final var parentB = loggerB.getParent();
System.out.println(parentB.getName()); // ""
System.out.println(parentB == root); // true

さて、ロガーが名前空間で階層構造(親子関係)を持つことは分かりました。

親子関係を持つロガーは、子ロガーでログ出力の要求がされると、その要求は親にも伝わります。
つまり、子ロガーがハンドラを持っていなくても、親のロガーがハンドラを持っていれば、親ロガーのハンドラでログが出力されます。

実はルートロガーはデフォルトでコンソールハンドラを持っています。
そのため、親への要求を無効にしないとルートロガーのハンドラでログが出力さます。

// 子のロガー
final var logger = Logger.getLogger("com.example.logging");
System.out.println(logger.getName()); // "com.example.logging"

// ハンドラは持っていません。
System.out.println(Arrays.toString(logger.getHandlers())); // []

// ルートロガー
final var root = logger.getParent();
System.out.println(root.getName()); // ""

// コンソールハンドラを持ちます。
System.out.println(Arrays.toString(root.getHandlers())); // [java.util.logging.ConsoleHandler@43e05848]

// 子のロガーでログ出力を要求します。
logger.info("ログテスト！");

// 結果
// ↓
//10月 19, 2021 1:04:02 午後 com.example.logging.LoggingBasicTest namespace4
//情報: ログテスト！

今までのコード例の多くでは、setUseParentHandlers(false) で意図的に親への要求を無効にしていました。
(そのほうがコード例が分かりやすくなるかなと思い…)

例えば、setUseParentHandlers(false) を設定せずに、子のロガーにハンドラを追加してみます。
すると、ルートロガーと子ロガーの両方のハンドラでログが出力されます。

final var logger = Logger.getLogger("com.example.logging");
System.out.println(logger.getName()); // "com.example.logging"

logger.addHandler(new ConsoleHandler());

logger.info("ログテスト！");

// 結果
// ↓
//10月 19, 2021 1:10:06 午後 com.example.logging.LoggingBasicTest namespace5
//情報: ログテスト！
//10月 19, 2021 1:10:06 午後 com.example.logging.LoggingBasicTest namespace5
//情報: ログテスト！

ログ出力の要求は１回ですが、ログが２回出力されることが分かりますね。

推奨されるロガー名

公式のAPI仕様では、

• ロギング対象のパッケージ名
• ロギング対象の(パッケージ名を含む)クラス名

が推奨されています。

パッケージ名を使う例です。

package com.example.logging;

import java.util.logging.Logger;

public class SampleA {

    public void func() {

        final var logger = Logger.getLogger(SampleA.class.getPackageName());
        System.out.println(logger.getName()); // com.example.logging

        logger.info("ログテスト！");

        // 結果
        // ↓
        //10月 07, 2021 3:37:41 午後 com.example.logging.SampleA func
        //情報: ログテスト！
    }
}

クラス名を使う例です。

package com.example.logging;

import java.util.logging.Logger;

public class SampleB {

    public void func() {

        final var logger = Logger.getLogger(SampleB.class.getName());
        System.out.println(logger.getName()); // com.example.logging.SampleB

        logger.info("ログテスト！");

        // 結果
        // ↓
        //10月 07, 2021 3:38:10 午後 com.example.logging.SampleB func
        //情報: ログテスト！
    }
}

メリット

名前空間による階層構造をとっておけば、例えば…

• "com.example.aaa" パッケージだけログをOFFにしたい
• "com.example.bbb" パッケージだけ詳細なログがとりたい

という制御がやりやすくなります。
名前空間のない単一の名前だけを使っていると、このような制御は難しいですね。

もちろん、プログラムが分かりやすいパッケージ構成になっていることが前提になります。

構成ファイル

今までは、

• ロガーにハンドラを設定
• ロガーやハンドラにレベルを設定

という各種設定はコード上で直接行いました。

これを設定ファイル（構成ファイル）から読み込むようにすることができます。

デフォルトの構成ファイル

デフォルトの構成ファイルは、以下の場所に格納されています。

　java-home/conf/logging.properties

実は、今までの本記事のコード例は、上記のデフォルトの構成が使われていました。

OpenJDK 17.0.1 の logging.properties を、参考までに一部抜粋します。

############################################################
#  	Global properties
############################################################

handlers= java.util.logging.ConsoleHandler

# Default global logging level.
.level= INFO

############################################################
# Handler specific properties.
# Describes specific configuration info for Handlers.
############################################################

# Limit the messages that are printed on the console to INFO and above.
java.util.logging.ConsoleHandler.level = INFO
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter

• ルートロガー : ConsoleHandlerを持ち、レベルは INFO
• ConsoleHandler : レベルは INFO で、フォーマッタは SimpleFormatter

ということがわかりますね。

実際にコードでも確認してみましょう。

// ルートロガー
final var logger = Logger.getLogger("");
System.out.println("RootLogger level : " + logger.getLevel());

// ハンドラとレベル
for (final var handler : logger.getHandlers()) {
    System.out.println("--- handler ---");
    System.out.println("handler : " + handler);
    System.out.println("format : " + handler.getFormatter());
    System.out.println("level : " + handler.getLevel());
}

// 結果
// ↓
//RootLogger level : INFO
//--- handler ---
//handler : java.util.logging.ConsoleHandler@195387a0
//format : java.util.logging.SimpleFormatter@63c73faa
//level : INFO

独自の構成ファイル

よくありそうな構成として、

• コンソールとファイル両方にログ出力
  • コンソールには重要なログだけ出力
  • ファイルには詳細なログまで出力

を例に考えていきましょう。

R:\java-work\sample.properties に下記の構成ファイルを作成します。

# ルートロガー
handlers= java.util.logging.ConsoleHandler, java.util.logging.FileHandler
.level= ALL

# ファイルハンドラ
java.util.logging.FileHandler.level = FINE
java.util.logging.FileHandler.pattern = R:\\java-work\\log.txt
java.util.logging.FileHandler.formatter = java.util.logging.SimpleFormatter
java.util.logging.FileHandler.append = true

# コンソールハンドラ
java.util.logging.ConsoleHandler.level = INFO
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter

Javaのメインクラスを作成します。

public class Main {

    public static void main(String[] args) {

        // ルートロガー
        final var logger = Logger.getLogger("");
        System.out.println("RootLogger level : " + logger.getLevel());

        // ハンドラとレベル
        for (final var handler : logger.getHandlers()) {
            System.out.println("--- handler ---");
            System.out.println("handler : " + handler);
            System.out.println("formatter : " + handler.getFormatter());
            System.out.println("level : " + handler.getLevel());
        }

        System.out.println("----------------");

        logger.severe("SEVEREログ！");
        logger.info("INFOログ！");
        logger.fine("FINEログ！");
        logger.finer("FINERログ！");
    }
}

そして、javaコマンドのオプション(-D)で

• java.util.logging.config.file

プロパティに構成ファイルのパスを指定します。

PowerShell で実行した例です。

PS R:\java-work> java -D"java.util.logging.config.file=R:\java-work\sample.properties" Main
RootLogger level : ALL
--- handler ---
handler : java.util.logging.ConsoleHandler@6e8cf4c6
formatter : java.util.logging.SimpleFormatter@12edcd21
level : INFO
--- handler ---
handler : java.util.logging.FileHandler@34c45dca
formatter : java.util.logging.SimpleFormatter@52cc8049
level : FINE
----------------
10月 15, 2021 2:01:22 午後 Main main
重大: SEVEREログ！
10月 15, 2021 2:01:22 午後 Main main
情報: INFOログ！

PS R:\java-work> cat .\log.txt
10月 15, 2021 2:01:22 午後 Main main
重大: SEVEREログ！
10月 15, 2021 2:01:22 午後 Main main
情報: INFOログ！
10月 15, 2021 2:01:22 午後 Main main
普通: FINEログ！

無事に、コンソールとファイルの両方にログが出力されました。
コンソールは INFO レベルまで、ファイルは FINE レベルまでのログが出力されます。

もし、プログラム実行中に構成ファイルを切り替えたい場合は、LogManagerの updateConfiguration メソッドを使います。

// ルートロガー
final var logger = Logger.getLogger("");
System.out.println("RootLogger level : " + logger.getLevel());

// ハンドラとレベル
for (final var handler : logger.getHandlers()) {
    System.out.println("--- handler ---");
    System.out.println("handler : " + handler);
    System.out.println("formatter : " + handler.getFormatter());
    System.out.println("level : " + handler.getLevel());
}

// 結果
// ↓
//RootLogger level : INFO
//--- handler ---
//handler : java.util.logging.ConsoleHandler@615f2c9e
//formatter : java.util.logging.SimpleFormatter@1786984c
//level : INFO

// 構成を更新
final var path = Path.of("R:", "java-work", "sample.properties");
try (final var ins = Files.newInputStream(path)) {
    final var logManager = LogManager.getLogManager();
    logManager.updateConfiguration(ins, null);
}

// 構成を再確認
System.out.println("RootLogger level : " + logger.getLevel());

for (final var handler : logger.getHandlers()) {
    System.out.println("--- handler ---");
    System.out.println("handler : " + handler);
    System.out.println("formatter : " + handler.getFormatter());
    System.out.println("level : " + handler.getLevel());
}

// 結果
// ↓
//RootLogger level : ALL
//--- handler ---
//handler : java.util.logging.ConsoleHandler@37ec40f5
//formatter : java.util.logging.SimpleFormatter@2fa6505b
//level : INFO
//--- handler ---
//handler : java.util.logging.FileHandler@3162a2a7
//formatter : java.util.logging.SimpleFormatter@6c481adf
//level : FINE

構成ファイルの詳細

java.util.logging.config.file プロパティや、ロガーの基本的なプロパティについては、上記の LogManager API仕様をご参照ください。

各種ハンドラのプロパティについては、それぞれのAPI仕様をご参照ください。

• ConsoleHandler (Java SE 17 & JDK 17)
• FileHandler (Java SE 17 & JDK 17)

プラットフォーム・ロギングAPIとサービス

Java 9 からプラットフォーム・ロギングAPIとサービスが追加されました。

代表的なクラスは LoggerFinder となります。

とてもおおざっぱなイメージとしては、Java標準ロギングAPIに依存しない、汎用的なロギングAPIです。

例えば、プラットフォーム・ロギングAPIを使っておけば、

• 最初はJava標準のロギングAPIを使ってアプリを開発
• 開発途中で、標準のロギングAPIでは機能不足になったので、外部ライブラリ(例えばlog4j)に変更

ということがやりやすくなります。

本記事では割愛しますが、もし興味がありましたら上記のAPI仕様をご確認ください。

まとめ

ロギングの基本、いかがでしたでしょうか。

ログは、アプリやサービスの開発中はもちろん、保守していくためにもとても重要な情報となります。
特に複数人で開発するような大きなアプリやサービスでは、ほぼ必須になるのではないでしょうか。

Java標準のロギングAPIはちょっと癖があるなと個人的には感じますが、ぜひ有効に活用していきたいですね。

関連記事

• スレッドで発生した例外は忘れずに処理しよう
• ログレベルの指針 (使い分け)

• API 使用例
  • Formatter
    • SimpleFormatter
    • XMLFormatter
  • Handler
    • ConsoleHandler
    • FileHandler
    • StreamHandler
  • Level
  • Logger
  • LogManager
  • System