マルチスレッドおよび Web アプリケーションにおけるロギング

1. ロギングのスレッドセーフ性

単一スレッドのプログラムは簡単です。1 本のスレッドがログを書き、誰にも邪魔されません。しかし実際のアプリケーション（Web サービス、マイクロサービス）では、同時に数十、数百のスレッドが動作します。複数の人が同じノートの同じ行に同時に手書きしているところを想像してください——結果はお世辞にも読みやすいとは言えません。

スレッドセーフティ（thread safety）とは、たとえ 100500 本のスレッドが同時にログを書いても、メッセージが取り違えられたり、混ざり合ったり、失われたりしないことの保証です。

ライブラリではどう実現されているか？

現代的なロギングライブラリ（Log4j 2、Logback、java.util.logging）は、最初からスレッドセーフになるよう設計されています。これは次のことを意味します。

• 各スレッドは安全にロガーのメソッドを呼び出せます。
• ライブラリ内部では同期やキューが使われ、メッセージ同士が干渉しません。
• 複数のスレッドが同じファイルに同時に書き込んでも、ログは取り違えられません。

重要: ロガー自体（たとえば SLF4J や Log4j の Logger オブジェクト）は、どのクラスでも static final フィールドとして使って問題ありません——スレッドに関する不具合にはつながりません。

例

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class MultiThreadedLoggerExample {
    private static final Logger logger = LoggerFactory.getLogger(MultiThreadedLoggerExample.class);

    public static void main(String[] args) {
        Runnable task = () -> {
            for (int i = 0; i < 5; i++) {
                logger.info("スレッド {} はメッセージ {} を書き込んでいます", Thread.currentThread().getName(), i);
            }
        };

        Thread t1 = new Thread(task, "一番目");
        Thread t2 = new Thread(task, "二番目");
        t1.start();
        t2.start();
    }
}

ログには両方のスレッドからのメッセージがきれいに並び、ぐちゃぐちゃに混ざったり重なったりしません。

2. ロギングのコンテキスト: MDC（Mapped Diagnostic Context）

あなたのアプリが同時に何百ものリクエストを処理しているとします。各リクエストはそれぞれのスレッドで処理されます。ログにはメッセージが次々と流れますが、どのメッセージがどのリクエストに対応しているのか分かりません。単に「何が起きたか」だけでなく、「誰に対して」「どのリクエストで」起きたのかを知りたいところです。

MDC（Mapped Diagnostic Context）は、現在のスレッドに関連する追加情報をログに「付与」できる仕組みです。そのスレッドが書くすべてのメッセージに、この追加データが自動的に付与されます。

例: リクエスト ID をログに入れる

Web アプリでは各リクエストに一意の ID（たとえば UUID）を割り当てられます。MDC を使うと、その ID がリクエストを処理するスレッドの全ログに自動付与されます。

コードではこうなります（SLF4J + Logback）:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

import java.util.UUID;

public class MdcExample {
    private static final Logger logger = LoggerFactory.getLogger(MdcExample.class);

    public static void main(String[] args) {
        Runnable task = () -> {
            // 一意のリクエスト ID を生成する
            String requestId = UUID.randomUUID().toString();
            MDC.put("requestId", requestId); // MDC に追加

            logger.info("リクエストを処理中");
            doSomeWork();
            logger.info("処理を完了しました");

            MDC.clear(); // 終了後は必ずクリア！
        };

        Thread t1 = new Thread(task, "スレッド-1");
        Thread t2 = new Thread(task, "スレッド-2");
        t1.start();
        t2.start();
    }

    static void doSomeWork() {
        logger.debug("作業を実行しています...");
    }
}

ログフォーマットの設定（例: logback.xml）:

<encoder>
    <pattern>%d{HH:mm:ss} [%thread] %-5level %logger{36} [requestId=%X{requestId}] - %msg%n</pattern>
</encoder>

出力例:

12:01:23 [スレッド-1] INFO  MdcExample [requestId=ad8d...f3] - リクエストを処理中
12:01:23 [スレッド-1] DEBUG MdcExample [requestId=ad8d...f3] - 作業を実行しています...
12:01:23 [スレッド-1] INFO  MdcExample [requestId=ad8d...f3] - 処理を完了しました

重要!

• MDC は単一スレッド内でのみ機能します。別スレッドへ処理を渡す（たとえばスレッドプール経由で）場合は、MDC の値を手動で引き継ぐ必要があります（自動で行う専用ライブラリを使う方法もあります）。
• MDC をクリアし忘れないでください。クリアしないと、同じスレッドで次のリクエスト（たとえば Web サーバーのスレッドプール）にデータが「漏れ」てしまいます。finally ブロックで MDC.clear() を使いましょう。

3. Web アプリケーションでのロギング

Web アプリは、起動して動くだけの単なるプログラムではありません。まさにコンベヤーです。リクエストが飛んできて処理され、レスポンスが返されます。それが同時に、何百件も進みます。ここでのロギングは贅沢ではなく必需品です。

Web アプリで何をログに取るべきか

• HTTP リクエストとレスポンス：メソッド、URL、パラメータ、ステータス、処理時間。
• エラーと例外：予期しない障害、スタックトレース。
• ビジネスイベント：ユーザー登録、ログイン、注文、決済など。
• 技術的詳細：データベースや外部サービスとのやり取り、各処理の実行時間。

大原則: ログは「1 か月後、夜中の 3 時に何かが壊れたときに、何がまずかったのかを突き止められる」ように記録しましょう。

例: HTTP リクエストのロギング（Spring Boot）

最も簡単なのは、着信リクエストごとにログを取るフィルタやアスペクトを使うことです。

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;

import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
import java.io.IOException;
import java.util.UUID;

@Component
public class RequestLoggingFilter implements Filter {
    private static final Logger logger = LoggerFactory.getLogger(RequestLoggingFilter.class);

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
            throws IOException, ServletException {
        String requestId = UUID.randomUUID().toString();
        MDC.put("requestId", requestId);

        HttpServletRequest httpRequest = (HttpServletRequest) request;
        logger.info("リクエスト: {} {}", httpRequest.getMethod(), httpRequest.getRequestURI());

        long start = System.currentTimeMillis();
        try {
            chain.doFilter(request, response); // チェーンを次へ（コントローラへ）
        } finally {
            long duration = System.currentTimeMillis() - start;
            logger.info("レスポンス送信、処理時間: {} ミリ秒", duration);
            MDC.clear();
        }
    }
}

エラーと例外のロギング

Web フレームワーク（たとえば Spring）では、想定外の障害を見やすくログに残すための専用エラーハンドラ（@ExceptionHandler）を使うのが一般的です。

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.ControllerAdvice;
import org.springframework.web.bind.annotation.ExceptionHandler;

@ControllerAdvice
public class GlobalExceptionHandler {
    private static final Logger logger = LoggerFactory.getLogger(GlobalExceptionHandler.class);

    @ExceptionHandler(Exception.class)
    public String handleException(Exception ex) {
        logger.error("エラーが発生しました: ", ex); // フルスタックトレースでログ！
        return "error"; // エラーページを返す
    }
}

Web フレームワークとの統合

ほとんどのモダンな Web フレームワーク（Spring、Jakarta EE、Micronaut など）は、ロガーと「最初から」統合されています。通常はプロジェクトに SLF4J/Logback の依存関係を追加するだけで、標準のメッセージ（アプリ起動、リクエスト処理、エラーなど）が自動的にログに記録されます。

4. 実践: マルチスレッドタスクでのロギング例

学習用アプリ（たとえば注文処理サービス）にマルチスレッド処理を加え、ロギングがどのように役立つかを見てみましょう。

例: 複数スレッドでの注文処理（MDC 付き）

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

import java.util.UUID;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;

public class OrderProcessingApp {
    private static final Logger logger = LoggerFactory.getLogger(OrderProcessingApp.class);

    public static void main(String[] args) {
        ExecutorService executor = Executors.newFixedThreadPool(3);

        for (int i = 1; i <= 5; i++) {
            final int orderId = i;
            executor.submit(() -> {
                String requestId = UUID.randomUUID().toString();
                MDC.put("requestId", requestId);

                try {
                    logger.info("注文 {} の処理を開始します", orderId);
                    processOrder(orderId);
                    logger.info("注文 {} は正常に処理されました", orderId);
                } catch (Exception ex) {
                    logger.error("注文 " + orderId + " の処理中にエラーが発生しました", ex);
                } finally {
                    MDC.clear();
                }
            });
        }
        executor.shutdown();
    }

    static void processOrder(int orderId) throws InterruptedException {
        if (orderId % 2 == 0) {
            throw new RuntimeException("偶数の注文のエラーをシミュレート");
        }
        Thread.sleep(500); // 処理の模擬
    }
}

何が起きているか:

• 各注文は別々のスレッドで処理されます。
• 各スレッドに一意の requestId（MDC）が作られます。
• 1 件の注文に関するログを、この ID でまとめて辿れます。
• エラーはフルスタックトレースで記録されます。

ログのフォーマットは requestId を表示するように設定されています。

5. 重要な注意点と特性

• スレッド、プール、そして MDC。 スレッドプールを使っている（多くの場合そうです）なら覚えておきましょう。プール内のスレッドは再利用されます。MDC をクリアし忘れると、あるリクエストのデータが別のリクエストのログに紛れ込みます。処理の最後に必ず MDC.clear() を呼びましょう。
• MDC と非同期タスク。 非同期の Web フレームワーク（例: Spring WebFlux）では、リクエスト処理がスレッド間を飛び回るため、MDC が「最初から」うまく動かない場合があります。そうしたケース向けの拡張やアダプターが存在します。
• マイクロサービスでのロギング。 マイクロサービスでは、ローカルなリクエスト ID だけでなく、サービス間で引き継ぐグローバルな traceId も記録するのが一般的です。これにより、システム全体でリクエストの経路（分散トレーシング）を追えます。Zipkin、Jaeger、OpenTelemetry などのシステムがよく使われます。

6. デモ: System.out.println とロギングの違い

System.out.println は、単にコンソールへ文字列を出力するだけです。マルチスレッド環境では次のような問題があります。

• メッセージが混ざり合うことがあります。
• 時刻、スレッド、レベル、コンテキストといった情報がありません。
• ファイル出力、フォーマット、レベルによるフィルタリングを設定できません。

ロガーは構造化されたメッセージを書き、スレッドやレベル、フォーマットを考慮し、ファイル・コンソール・ネットワークなどさまざまな出力先をサポートします。

比較例

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class PrintVsLogger {
    private static final Logger logger = LoggerFactory.getLogger(PrintVsLogger.class);

    public static void main(String[] args) {
        Runnable task = () -> {
            for (int i = 0; i < 3; i++) {
                System.out.println("System.out: " + Thread.currentThread().getName() + " ステップ " + i);
                logger.info("Logger: ステップ {}", i);
            }
        };
        new Thread(task, "T1").start();
        new Thread(task, "T2").start();
    }
}

結論:

• System.out — メッセージは時刻やレベルなしで混在しがちです。
• ロガー — 各メッセージに時刻・スレッド・レベルが含まれ、フィルタリングして目的の情報を素早く見つけられます。

7. マルチスレッドおよび Web アプリでのロギングのよくあるミス

誤り No.1: System.out.println をロガーの代わりに使う。 マルチスレッド環境ではコンソールが「ぐちゃぐちゃ」になり、メッセージをフィルタできず、コンテキスト情報も失われます。

誤り No.2: MDC を無視、または誤用する。 リクエスト／ユーザーの識別子を渡すために MDC を使わないと、ログは意味を失い、どのリクエストと関連するか分からなくなります。MDC をクリアし忘れると、データが別のリクエストへ「漏洩」します。

誤り No.3: ロガーをローカル変数として作成する。 最適なのは private static final な Logger を使うことです。クラスごとに 1 回だけ生成され、メモリも無駄にせず、誤りのリスクも減ります。

誤り No.4: 機微情報のロギング。 パスワード、クレジットカード、個人情報などをログに残してはいけません——セキュリティ違反です。

誤り No.5: 「INFO」だけ、または「ERROR」だけを記録する。 適切なレベルを使い分けましょう。DEBUG はデバッグ用、INFO はビジネスイベント用、ERROR はエラー用です。すべてを 1 つのレベルで記録してはいけません——ログの意味が薄れます。

誤り No.6: 例外のスタックトレースを記録しない。 単に logger.error("エラー: " + ex.getMessage()) のようにすると、原因情報が失われます。常に例外オブジェクト全体を渡して記録しましょう: logger.error("エラー", ex)。

誤り No.7: スレッドセーフでない自作ロガー。 同期なしで「自作ロガー」を作ると、マルチスレッド環境ではほぼ確実にログの欠落や破損を招きます。