Javaのログ設計入門 — SLF4Jで「どこに何を出力するか」を考える

はじめに

新人の頃、よくこんなコードを書いていました。

public Order create(OrderRequest req) {
    System.out.println("注文作成開始: " + req);
    // ...
    System.out.println("注文作成完了: " + order.getId());
    return order;
}

System.out.println でとりあえずデバッグ出力。動いてはいるんですが、現場で先輩から「それ本番でも出続けるよ？」と言われて初めて気づきました。

ログは「書けばいい」ものではなく、「いつ・どこで・どのレベルで・何を」出すかを設計するものです。

この記事では、Javaのログ出力の標準である SLF4J + Logback の使い方と、初心者がつまずきがちな「ログレベルの使い分け」を整理します。

まず結論: System.out.println を卒業しよう

System.out.println でログを書くのが NG な理由はシンプルです。

問題	詳細
本番でも常に出力される	「DEBUGの時だけ出す」みたいな制御ができない
出力先がコンソール固定	ファイル出力やログ集約サービス（Datadog等）に流せない
ログレベルの概念がない	ERRORもINFOも同じ扱い
構造化できない	あとから「ERRORだけ抽出」「特定のIDだけ追跡」がやりにくい

これを全部解決してくれるのが SLF4J + Logback です。

SLF4J + Logback とは

SLF4J: ログ出力の「インターフェース」を提供するライブラリ
Logback: SLF4J の代表的な「実装」

Java のログ周りは歴史的に Log4j / java.util.logging / Logback など複数あって混乱しがちですが、コード側は SLF4J のインターフェースに依存して、実装は Logback などを差し替え可能にする、というのが今の標準的なやり方です。

Spring Boot を使っているなら、最初から Logback がデフォルトで入っています。何もしなくて使えます。

1. 最低限の使い方

1-1. Logger を取得

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

public class OrderService {
    private static final Logger log = LoggerFactory.getLogger(OrderService.class);

    public Order create(OrderRequest req) {
        log.info("注文作成開始");
        // ...
        log.info("注文作成完了");
        return order;
    }
}

ポイント:

private static final で1クラス1ロガー
クラスを getLogger に渡す（自動でクラス名が出力される）
慣習的に変数名は log か logger

1-2. プレースホルダで埋め込む

NG パターン（文字列結合）:

log.info("注文作成: id=" + order.getId() + ", amount=" + order.getAmount());

OK パターン（{} プレースホルダ）:

log.info("注文作成: id={}, amount={}", order.getId(), order.getAmount());

なぜプレースホルダが良いかと言うと:

ログレベルが OFF の時に文字列結合のコストが発生しない
構造化ログとの相性が良い（後述）

地味ですが、ログが大量に出る本番では効いてきます。

2. ログレベルの使い分け

ここが一番大事。間違えると「本番でログが洪水になる」「重要な情報が埋もれる」みたいな事故になります。

レベル	いつ使う	例
ERROR	即対応が必要なエラー	DB接続失敗、外部APIから500が返ってきた
WARN	何か変だが、処理は続行できる	リトライした、デフォルト値で補完した
INFO	業務的な節目	注文作成完了、ユーザー登録完了
DEBUG	開発時に追いたい詳細	リクエストパラメータ、SQL クエリ
TRACE	DEBUG より細かい	ループの各ステップ

よくある混乱: INFO と DEBUG の境目

迷ったらこう考えるといいです。

本番運用で見たいかどうか

本番でも見たい → INFO
開発・調査の時だけ見たい → DEBUG

例えば「注文作成完了」は 業務的なイベント なので INFO。一方「呼び出されたメソッドの引数全部」は調査用なので DEBUG。

実例で比較

public Order create(OrderRequest req) {
    log.debug("注文作成リクエスト受信: {}", req);   // 詳細パラメータ

    try {
        Order order = orderRepository.save(...);
        log.info("注文作成完了: orderId={}", order.getId());   // 業務イベント
        return order;
    } catch (DataAccessException e) {
        log.error("注文の保存に失敗: req={}", req, e);   // 即対応案件
        throw new ServiceException("注文作成失敗", e);
    } catch (Exception e) {
        log.warn("予期せぬエラー、リトライ可能か判定: {}", e.getMessage());
        // ...
    }
}

3. 例外をログに出すときの落とし穴

NG パターン:

log.error("エラー発生: " + e.getMessage());   // ❌ スタックトレースが消える

OK パターン:

log.error("注文の保存に失敗: orderId={}", id, e);   // ✅ 最後にThrowableを渡す

最後の引数として Throwable を渡すと、スタックトレースが自動的に整形されて出力されます。

e.getMessage() だけだと「null」だったり一行しか出ず、調査でブチギレることになります。

4. logback.xml の最低限の設定

Spring Boot ならデフォルト設定で十分動きますが、ファイル出力やレベル調整は src/main/resources/logback-spring.xml で行います。

<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>logs/app.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>logs/app.%d{yyyy-MM-dd}.log</fileNamePattern>
            <maxHistory>30</maxHistory>
        </rollingPolicy>
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="STDOUT" />
        <appender-ref ref="FILE" />
    </root>

    <!-- 自分のアプリだけは DEBUG レベルにしたい時 -->
    <logger name="com.example.myapp" level="DEBUG" />
</configuration>

ポイント:

RollingFileAppender で 日次ローテーション（容量爆発を防ぐ）
root level="INFO" で 全体は INFO 以上
特定のパッケージだけ level="DEBUG" で 自分のアプリだけ詳細

5. 構造化ログという考え方

最近はクラウド環境で動かすことが多いので、ログを JSON で出力する のがトレンドです。Datadog や CloudWatch などで検索しやすくなります。

<encoder class="net.logstash.logback.encoder.LogstashEncoder" />

これだけで出力が JSON になります。プレースホルダの引数も自動的にフィールド化されるので、後から「orderId=xxx だけ抽出」が一瞬。

System.out.println ではこういう発展性がまったくありません。

6. MDC で「リクエスト1本」を追跡する

複数リクエストが並行して処理される時、どのログがどのリクエストのものか分からなくなることがあります。

そんな時に使うのが MDC (Mapped Diagnostic Context)。

import org.slf4j.MDC;

MDC.put("requestId", UUID.randomUUID().toString());
try {
    log.info("処理開始");
    // ... なにか処理 ...
    log.info("処理完了");
} finally {
    MDC.clear();
}

logback の pattern に %X{requestId} を入れておくと、そのスレッドで出た全ログに同じ requestId が付く。リクエスト単位でログを追えるようになります。

Spring Boot なら Filter で自動付与する実装をしておくのが定番です。

まとめ: ログ設計の3つの原則

System.out.println 卒業、SLF4J + Logback を使う
ログレベルは「本番で見たいかどうか」で決める
例外は最後の引数で渡す、文字列結合はしない

これだけで「現場で恥ずかしくない」ログコードになります。

おわりに

ログは「動いてる時はあってもなくてもいい、トラブル時に命綱になる」存在です。

System.out.println のままだと、本番でインシデントが起きた時に「何が起きたか分からない」「ログが大量で追えない」と詰みます。

新人の頃の自分にも教えたいのは、ログは最初から SLF4J で書く癖をつける ということ。あとで一括置換するのは想像以上に面倒です。

明日のコードから、ぜひ log.info(...) で書いてみてください。