2
5

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

【Javaの良いコード・悪いコード #9】System.out.printlnを卒業する「ログ出力」の3原則

2
Posted at

はじめに

株式会社Good Labでエンジニアをしている コータロー です。
日々、Java・SQL・Gitなどの技術情報や、新人エンジニア向けの学習ノウハウ、
AI活用についての情報を発信しています。

Good Labについて気になった方は、コーポレートサイトもぜひご覧ください。
コーポレートサイト

この記事は、新人〜2年目のJavaエンジニア向けに 「良いコードと悪いコードの違い」 を、現場でよく見る具体例とともに解説していくシリーズの第9回です。

テーマ
#1 命名
#2 コメントの書き方
#3 マジックナンバー・定数化
#4 Null処理
#5 早期リターン
#6 メソッド分割
#7 ループ処理
#8 例外処理
#9(本記事) ログ出力
#10 クラス設計

第9回は ログ出力 です。新人がやってしまいがちなのが、デバッグのつもりで書いた System.out.println本番にそのまま残してしまう こと。本番で起きたバグを調査するときに ログが頼りない のは、新人〜2年目のコードの典型的な特徴です。


この記事のゴール

この記事を読み終わると、以下ができるようになります。

  • System.out.println ではなく Logger を使うべき理由を説明できる
  • ログレベル(DEBUG / INFO / WARN / ERROR)を使い分けられる
  • 個人情報・機密情報をログに残さない設計ができる

「悪いログ」の本当のコスト

新人〜2年目のコードによく見られるのが、こんなコードです。

public void registerUser(String name, String email, String password) {
    System.out.println("registerUser called");
    System.out.println("name = " + name);
    System.out.println("email = " + email);
    System.out.println("password = " + password);  // ← 危険!
    // ...
    System.out.println("done");
}

書いた本人は「デバッグログのつもり」かもしれません。
ですが、このコードには以下の問題があります。

  1. 本番ログに残らないSystem.out.println は標準出力。本番のロギング基盤に集約されない
  2. ログレベル制御ができない:本番では DEBUG ログを出したくないが、消す手段がない
  3. 機密情報が漏れる:パスワードを平文でログに書いている(重大なセキュリティ事故)

悪いログには3つの大きなコストがあります。

コスト 内容
障害対応コスト ログから状況が読み取れず、本番障害の調査が長期化
セキュリティコスト 個人情報・機密情報の漏えい事故
運用コスト 不要なログでディスクを圧迫、本当に必要なログが埋もれる

特に セキュリティコスト は深刻です。
パスワードやクレジットカード番号がログに残ると、ログを見られる全ての人(運用担当・委託業者・侵入者)に漏えい します。


押さえるべきは3原則

新人〜2年目がまず身につけるべきログ出力の原則は、以下の3つです。

  1. System.out.println ではなく Logger を使う
  2. ログレベルを使い分ける
  3. 個人情報・機密情報を漏らさない

順番に見ていきます。


原則① System.out.println ではなく Logger を使う

System.out.printlnデバッグ用の道具 であり、本番運用には使えません
業務コードでは必ず Logger を使います。

Loggerの選択肢

Javaのロギングには複数の選択肢があります。

ライブラリ 概要
java.util.logging(JUL) 標準API。追加ライブラリ不要
SLF4J + Logback 業界標準。Spring Bootのデフォルト
Log4j 2 高機能な代替実装

新人のうちは「現場で何が使われているか」を最初に確認しましょう。Spring Bootの案件なら SLF4J + Logback、レガシー案件なら Log4j 1.x のことも。
本記事では、追加ライブラリ不要で動く java.util.logging を例に解説します。

悪い例(System.out.println)

public class UserService {
    public void registerUser(String name) {
        System.out.println("登録開始: " + name);
        // ...
        System.out.println("登録完了");
    }
}

良い例(Logger)

import java.util.logging.Logger;

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

    public void registerUser(String name) {
        logger.info("登録開始: " + name);
        // ...
        logger.info("登録完了");
    }
}

Loggerを使うメリット

メリット 説明
設定で有効/無効を切替可能 本番ではDEBUG OFF、開発ではDEBUG ON にできる
ログレベルで重要度を区別 INFO / WARN / ERROR で集計しやすい
出力先を変更できる 標準出力/ファイル/外部送信(Datadog等)に切替可能
クラス名・タイムスタンプ自動付与 どこで発生したかが追跡可能
本番のログ基盤に集約 grep / 検索可能なログとして残る

SLF4Jを使う場合(参考)

実務で最も多いSLF4Jの場合、書き方はこうなります。

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

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

    public void registerUser(String name) {
        logger.info("登録開始: name={}", name);  // {} プレースホルダ
    }
}

SLF4Jの {} プレースホルダ は、文字列連結より高速で安全です(後述)。


原則② ログレベルを使い分ける

ログには レベル があります。重要度に応じて使い分けることで、本番で必要なログだけを拾えるようになります。

ログレベルの基本(4段階)

レベル 用途
DEBUG(FINE) 詳細な動作トレース 「リクエスト詳細: userId=1234 path=/api/users」
INFO 通常のイベント 「ユーザー登録完了 userId=1234」
WARN 問題ではないが注意すべき事象 「レスポンスタイム超過: 3500ms(閾値3000ms)」
ERROR(SEVERE) エラーが発生、要対応 「DB接続不可: ConnectionTimeout」

java.util.logging では DEBUG → FINEERROR → SEVERE という名称です。本記事は標準APIの名称(FINE/INFO/WARNING/SEVERE)で記述しますが、概念は同じです。

レベルの使い分け基準

シーン レベル 理由
メソッドの開始・終了 DEBUG 通常運用では不要だが、開発時の追跡に有用
ユーザー登録完了 INFO 業務イベントとして記録すべき
入力バリデーション失敗 WARN ユーザーの誤入力(システム異常ではない)
外部APIタイムアウト WARN リトライで回復するなら警告レベル
DB接続失敗(リトライ後) ERROR システムが機能不全に陥る
想定外の例外 ERROR 即時調査が必要

悪い例(全部 INFO)

logger.info("メソッド開始");
logger.info("DB接続成功");
logger.info("検索結果: 100件");
logger.info("メソッド終了");
logger.info("ユーザー登録完了");  // 業務イベント
logger.info("DB接続失敗");          // エラー

すべてINFOで出力すると、本番ログがノイズで埋まって、本当に必要な情報が見つかりません

良い例(レベルを使い分け)

logger.fine("メソッド開始");
logger.fine("DB接続成功");
logger.fine("検索結果: 100件");
logger.fine("メソッド終了");
logger.info("ユーザー登録完了 userId=1234");  // 業務イベント
logger.severe("DB接続失敗");                  // エラー

本番では INFO以上だけ出力、開発・調査時に DEBUG/FINEを有効化 という運用ができます。

文字列連結より「プレースホルダ」を使う(SLF4J)

// 良くない例(文字列連結)
logger.info("登録: name=" + name + " age=" + age);

// 良い例(プレースホルダ)
logger.info("登録: name={} age={}", name, age);

理由:

  • ログレベルが DEBUG OFF のとき、文字列連結のコストが発生しない(プレースホルダは遅延評価)
  • 引数を構造化情報として扱える
  • 引数の数と {} の数が一致しない場合、ライブラリが検知してくれる

java.util.logging には {} プレースホルダはないため、logger.log(Level.INFO, "msg {0}", arg); という別形式を使いますが、新人〜2年目のうちは「SLF4Jなら {} を使うのが標準」と覚えておきましょう。


原則③ 個人情報・機密情報を漏らさない

ログに 絶対に出してはいけない情報 があります。
これは技術的な問題ではなく、法令・契約上の重大な問題 に直結します。

ログに出してはいけない情報

種類
認証情報 パスワード、APIキー、トークン
個人識別情報(PII) 氏名、メールアドレス、電話番号、住所、生年月日
金融情報 クレジットカード番号、銀行口座番号、CVV
健康情報 病歴、検査結果
機密の業務情報 顧客リスト、内部見積り

悪い例

public void login(String email, String password) {
    logger.info("ログイン試行: email=" + email + " password=" + password);
}

このコードでは、ログに メールアドレスとパスワードが平文で残ります
これは、システムを運用する人全員から、過去のログを保存している全てのストレージにいたるまで、機密情報が垂れ流される状態 です。

良い例(マスキング)

public void login(String email, String password) {
    logger.info("ログイン試行: email=" + maskEmail(email));
    // パスワードはログに出さない
}

private String maskEmail(String email) {
    if (email == null || !email.contains("@")) {
        return "***";
    }
    int at = email.indexOf("@");
    String local = email.substring(0, at);
    String domain = email.substring(at);
    if (local.length() <= 2) {
        return "**" + domain;
    }
    return local.substring(0, 2) + "***" + domain;
}

tanaka@example.comta***@example.com のようにマスキングして、業務調査に必要な情報 だけを残します。

クレジットカード番号のマスキング

クレジットカード番号は、業界規格(PCI DSS)によって 末尾4桁以外はログに残してはいけない と定められています。

private String maskCreditCard(String cardNumber) {
    if (cardNumber == null || cardNumber.length() < 4) {
        return "****";
    }
    return "****-****-****-" + cardNumber.substring(cardNumber.length() - 4);
}

「ユーザーIDだけは残す」が現場の落とし所

業務調査のために、ユーザーIDなど内部識別子だけはログに残す のが現場の落とし所です。

logger.info("ログイン成功: userId=1234");  // OK
logger.info("ログイン成功: email=tanaka@example.com");  // NG(メールはPII)

メールアドレスや氏名そのものではなく、「内部DB上のID」だけをログに残す ことで、調査時にDB側からPIIを引き当てられます。


動作確認:3原則を全部適用したサンプル

3つの原則をすべて適用したコード例です。コピペでそのまま動かせます。

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

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

    public static void main(String[] args) {
        // 原則①:System.out.println ではなく Logger を使う
        logger.info("アプリケーション起動");

        // 原則②:ログレベルを使い分ける
        logger.fine("デバッグ情報: 詳細な動作トレース");  // DEBUG相当
        logger.info("通常情報: ユーザー登録完了 userId=1234");
        logger.warning("警告: 設定値が推奨範囲外 value=200");
        logger.severe("エラー: DB接続失敗");

        // 原則③:機密情報をログに出さない
        String userName = "tanaka";
        String maskedEmail = maskEmail("tanaka@example.com");
        logger.info("ログイン成功: userName=" + userName + " email=" + maskedEmail);

        // 例外を伴うログ
        try {
            Integer.parseInt("abc");
        } catch (NumberFormatException e) {
            logger.log(Level.WARNING, "数値変換失敗: input=abc", e);
        }
    }

    static String maskEmail(String email) {
        if (email == null || !email.contains("@")) {
            return "***";
        }
        int atIndex = email.indexOf("@");
        String local = email.substring(0, atIndex);
        String domain = email.substring(atIndex);
        if (local.length() <= 2) {
            return "**" + domain;
        }
        return local.substring(0, 2) + "***" + domain;
    }
}

期待する出力(抜粋・形式)

情報: アプリケーション起動
情報: 通常情報: ユーザー登録完了 userId=1234
警告: 警告: 設定値が推奨範囲外 value=200
重大: エラー: DB接続失敗
情報: ログイン成功: userName=tanaka email=ta***@example.com
警告: 数値変換失敗: input=abc
java.lang.NumberFormatException: For input string: "abc"
    ...

logger.finejava.util.logging のデフォルト設定では出力されません(INFO以上が出力されるため)。本番運用ではログレベルを設定ファイルで制御します。


半日溶かした実話:ログがない地獄

ある日、本番で「特定のユーザーだけログイン失敗が発生している、原因不明」という障害報告が上がりました。

ログを見ると、こう書かれていました。

2024-09-15 14:23:01 INFO  ログイン処理
2024-09-15 14:23:01 INFO  処理中
2024-09-15 14:23:02 ERROR エラー発生

「処理中」エラー発生」しか書かれていません。
ユーザーIDも、何のエラーかも、どこで失敗したかも分かりません。

調査のために、以下の手順を踏むことになりました:

  1. 該当時刻に何が起きたかを推測
  2. ソースコードを「ログイン処理」「処理中」「エラー発生」でgrep
  3. 該当箇所を特定して、ローカルで再現テスト
  4. デバッグ実行で原因特定

ここまでで 半日以上 かかりました。

もし最初から以下のようにログが書かれていれば、調査時間は 5分 で済んだはずです。

2024-09-15 14:23:01 INFO  ログイン試行: userId=12345 ip=10.20.30.40
2024-09-15 14:23:01 INFO  認証DB問い合わせ: userId=12345
2024-09-15 14:23:02 ERROR 認証失敗: userId=12345 reason=PasswordExpired expireDate=2024-09-10

良いログは、調査の労力を100分の1にします。

ログは「書く時間」より「読まれる時間」のほうが圧倒的に長い、ということを覚えておきましょう。


演習問題

難易度の見方

マーク 難易度 目安
基本 原則を覚えれば解ける
⭐⭐ 応用 複数の原則を組み合わせる

まずは自分で考えてから、模範解答を見てください!


問題1:System.out.println を Logger に置き換える ⭐

次のコードを、java.util.logging.Logger を使うように書き直してください。

public class Sample {
    public static void main(String[] args) {
        System.out.println("ユーザー登録処理開始");
        registerUser("tanaka", 30);
        System.out.println("ユーザー登録処理終了");
    }

    static void registerUser(String name, int age) {
        System.out.println("登録中: name=" + name + " age=" + age);
    }
}
模範解答
import java.util.logging.Logger;

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

    public static void main(String[] args) {
        logger.info("ユーザー登録処理開始");
        registerUser("tanaka", 30);
        logger.info("ユーザー登録処理終了");
    }

    static void registerUser(String name, int age) {
        logger.info("登録中: name=" + name + " age=" + age);
    }
}

ポイント

  • Logger.getLogger(クラス名) で取得
  • フィールドとして private static final で宣言
  • info()warning()severe() などのメソッドで出力
  • タイムスタンプ・クラス名・メソッド名が自動で付与される

問題2:適切なログレベルに直す ⭐

次のコードはすべて info() で出力していますが、本来は内容に応じてレベルを使い分けるべきです。
適切なログレベルに修正してください。

仕様

  • 「リクエスト詳細」は通常運用では不要 → DEBUG相当(FINE)
  • 「APIリクエスト受付」は業務イベント → INFO
  • 「レスポンスタイム超過」は警告 → WARNING
  • 「DB接続不可」は致命的なエラー → SEVERE
import java.util.logging.Logger;

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

    public static void main(String[] args) {
        logger.info("リクエスト詳細: userId=1234 path=/api/users method=GET");
        logger.info("APIリクエスト受付: userId=1234");
        logger.info("レスポンスタイム超過: 3500ms(閾値3000ms)");
        logger.info("DB接続不可: ConnectionTimeout");
    }
}
模範解答
import java.util.logging.Logger;
import java.util.logging.Level;

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

    public static void main(String[] args) {
        logger.fine("リクエスト詳細: userId=1234 path=/api/users method=GET");
        logger.info("APIリクエスト受付: userId=1234");
        logger.warning("レスポンスタイム超過: 3500ms(閾値3000ms)");
        logger.severe("DB接続不可: ConnectionTimeout");
    }
}

ポイント

  • fine は標準設定では出力されない → 開発・調査時のみ
  • info は本番ログに残る業務イベント
  • warning は問題の予兆(即時対応は不要)
  • severe は即時対応が必要なエラー
  • 本番運用では INFO 以上だけ出力する設定が一般的

問題3:クレジットカード番号をマスキングする ⭐

次のメソッドを実装してください。
16桁のカード番号を ****-****-****-XXXX 形式にマスキングします。

public class Sample {
    public static void main(String[] args) {
        System.out.println(maskCreditCard("1234567812345678"));
        System.out.println(maskCreditCard("4111111111111111"));
        System.out.println(maskCreditCard("12345"));
        System.out.println(maskCreditCard(null));
    }

    static String maskCreditCard(String cardNumber) {
        // ここを実装する
        return null;
    }
}

期待する出力

****-****-****-5678
****-****-****-1111
****
****
模範解答
public class Exercise03 {
    public static void main(String[] args) {
        System.out.println(maskCreditCard("1234567812345678"));
        System.out.println(maskCreditCard("4111111111111111"));
        System.out.println(maskCreditCard("12345"));
        System.out.println(maskCreditCard(null));
    }

    static String maskCreditCard(String cardNumber) {
        if (cardNumber == null || cardNumber.length() < 8) {
            return "****";
        }
        int len = cardNumber.length();
        String last4 = cardNumber.substring(len - 4);
        return "****-****-****-" + last4;
    }
}

ポイント

  • nullや短すぎる値はすべて **** に寄せる
  • 末尾4桁だけ表示(業界標準 PCI DSS 準拠)
  • 早期リターン(#5参照)で前提条件を弾く

問題4:決済処理のログを設計する ⭐⭐

次のメソッドはログがほとんどなく、本番障害時に調査困難です。
3原則を踏まえて、適切なログを追加してください。

仕様

  • 決済開始時:INFO で userId / マスキングしたemail・カード番号 / amount を出力
  • 決済成功時:INFO で userId を出力
  • 決済失敗時:WARNING で例外とともに出力(金額不正など)
public class Sample {
    public static void main(String[] args) {
        processPayment(new Payment("user001", "tanaka@example.com", "1234567812345678", 5000));
        processPayment(new Payment("user002", "yamada@example.com", "4111111111111111", -100));
    }

    static void processPayment(Payment payment) {
        // ログを追加する
        try {
            validateAmount(payment.getAmount());
        } catch (InvalidPaymentException e) {
            // ログを追加する
        }
    }

    static void validateAmount(int amount) throws InvalidPaymentException {
        if (amount <= 0) {
            throw new InvalidPaymentException("金額が不正: " + amount);
        }
    }
}

class Payment {
    private final String userId;
    private final String email;
    private final String cardNumber;
    private final int amount;
    Payment(String userId, String email, String cardNumber, int amount) {
        this.userId = userId; this.email = email; this.cardNumber = cardNumber; this.amount = amount;
    }
    String getUserId() { return userId; }
    String getEmail() { return email; }
    String getCardNumber() { return cardNumber; }
    int getAmount() { return amount; }
}

class InvalidPaymentException extends Exception {
    public InvalidPaymentException(String message) { super(message); }
}
模範解答
import java.util.logging.Logger;
import java.util.logging.Level;

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

    public static void main(String[] args) {
        processPayment(new Payment("user001", "tanaka@example.com", "1234567812345678", 5000));
        processPayment(new Payment("user002", "yamada@example.com", "4111111111111111", -100));
    }

    static void processPayment(Payment payment) {
        String maskedEmail = maskEmail(payment.getEmail());
        String maskedCard = maskCreditCard(payment.getCardNumber());
        logger.info("決済開始: userId=" + payment.getUserId()
                + " email=" + maskedEmail
                + " card=" + maskedCard
                + " amount=" + payment.getAmount());

        try {
            validateAmount(payment.getAmount());
            logger.info("決済成功: userId=" + payment.getUserId());
        } catch (InvalidPaymentException e) {
            logger.log(Level.WARNING, "決済失敗: userId=" + payment.getUserId(), e);
        }
    }

    static void validateAmount(int amount) throws InvalidPaymentException {
        if (amount <= 0) {
            throw new InvalidPaymentException("金額が不正: " + amount);
        }
    }

    static String maskEmail(String email) {
        if (email == null || !email.contains("@")) return "***";
        int at = email.indexOf("@");
        String local = email.substring(0, at);
        String domain = email.substring(at);
        if (local.length() <= 2) return "**" + domain;
        return local.substring(0, 2) + "***" + domain;
    }

    static String maskCreditCard(String card) {
        if (card == null || card.length() < 4) return "****";
        return "****-****-****-" + card.substring(card.length() - 4);
    }
}

class Payment {
    private final String userId;
    private final String email;
    private final String cardNumber;
    private final int amount;
    Payment(String userId, String email, String cardNumber, int amount) {
        this.userId = userId; this.email = email; this.cardNumber = cardNumber; this.amount = amount;
    }
    String getUserId() { return userId; }
    String getEmail() { return email; }
    String getCardNumber() { return cardNumber; }
    int getAmount() { return amount; }
}

class InvalidPaymentException extends Exception {
    public InvalidPaymentException(String message) { super(message); }
}

期待する出力(抜粋)

情報: 決済開始: userId=user001 email=ta***@example.com card=****-****-****-5678 amount=5000
情報: 決済成功: userId=user001
情報: 決済開始: userId=user002 email=ya***@example.com card=****-****-****-1111 amount=-100
警告: 決済失敗: userId=user002
InvalidPaymentException: 金額が不正: -100
    ...

改善ポイント

元のコード 改善後 理由
ログなし INFO / WARNING で記録 本番障害時に追跡可能に
email・カード番号を平文出力 マスキングして出力 PII / カード情報の漏えい防止
catch で何も残らない logger.log(Level.WARNING, msg, e) 例外スタックトレースを残す
userId の記録なし 各ログに含める どのユーザーの処理か追跡可能

ポイント

  • 業務イベント(開始・成功)は INFO
  • 失敗(業務的な拒否)は WARNING
  • すべてのログに userId を含めると、調査時にユーザーで絞り込める
  • 例外を伴うログは logger.log(Level.XXX, msg, exception) 形式でスタックトレースも残す

まとめ

新人〜2年目が押さえるべきログ出力の3原則は、以下の3つです。

  1. System.out.println ではなく Logger を使う:本番運用に耐える形に
  2. ログレベルを使い分ける:DEBUG / INFO / WARN / ERROR で重要度を表現
  3. 個人情報・機密情報を漏らさない:マスキング、IDだけ記録

ログは「書く時間」より「読まれる時間」のほうが圧倒的に長いです。
未来の自分とチームに対するメッセージ だと思って書きましょう。

良いログがあれば、本番障害の調査時間は 100分の1 になります。
逆に、悪いログのままだと、本番障害のたびに 半日〜数日 が消えます。


次回予告

次回(#10:最終回)は 「クラス設計」 を扱います。

  • 1クラス1責務(SRP)
  • 不変クラス(immutable)を優先する
  • getter/setterの塊(貧血ドメイン)を避ける

を、Before / After 形式で解説していきます。


参考


@kotaro_ai_lab
AI活用や開発効率化について発信しています。フォローお気軽にどうぞ!

2
5
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
2
5

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?