1. ログメッセージの構造
ログはプログラムの「意識の流れ」ではなく、数カ月後や一年後にあなたや同僚が「ここで一体何が起きたのか?」という問いに答えを見つけるための貴重な記録です。そのためには、各ログメッセージが構造化されている必要があります。一般的に(多くのライブラリの標準でも)各メッセージには次が含まれます。
- 発生時刻 — いつ起きたか。
- レベル — 重要度(INFO、ERROR など)。
- ロガー名 — 通常はクラス名またはコンポーネント名。
- メッセージ本文 — 何が起きたか。
- スタックトレース(エラーがある場合)— どこでなぜ起きたかを把握するため。
Log4j/SLF4J の例で、よく整形されたログ行の例です。
2024-06-16 18:42:07,123 INFO com.example.MainApp - ユーザーがシステムにログインしました: username=vasya
エラーが発生した場合の例:
2024-06-16 18:42:10,456 ERROR com.example.LoginService - ユーザーの認証エラー: vasya
java.lang.IllegalArgumentException: パスワードが正しくありません
at com.example.LoginService.checkPassword(LoginService.java:42)
...
なぜ重要か?
アプリケーションが長時間動作すると、ログはギガバイト単位に膨れ上がります。メッセージが構造化されていなければ、問題を見つけるのは「ファンのノイズから曲名を当てる」レベルの難題になります。
2. メッセージのフォーマット
次のように書かない理由:
logger.info("ユーザー " + username + " がシステムにログインしました");
一見シンプルですが、落とし穴があります。たとえ現在のログレベルが ERROR でも、カッコ内の文字列は結局組み立てられてしまいます(連結が実行される)— これは無駄なリソース消費です。1 秒に数千行のログが出る大規模システムでは、現実的な遅延につながることがあります。
正しい書き方:プレースホルダーとパラメータ
現代的なライブラリ(たとえば SLF4J や Log4j 2)は、パラメータ付きのテンプレートをサポートしています。
logger.info("ユーザー {} がシステムにログインしました", username);
この場合、メッセージはログレベルが出力を許すときにだけ組み立てられます。もし現在のレベルが WARN なら、文字列の計算すら行われません — リソースも神経も節約できます。
ボーナス: 複数のパラメータも順番に差し込まれます。
logger.info("ユーザー {} がアクション {} をオブジェクト {} に対して実行しました", username, action, objectId);
例外のロギング(スタックトレース)
例外を捕捉したとき、スタックトレースを手作業でメッセージに追加する必要はありません。
// やってはいけない:
logger.error("エラー: " + ex.getMessage() + "\n" + Arrays.toString(ex.getStackTrace()));
正しい書き方:
logger.error("リクエスト処理中にエラーが発生しました", ex);
SLF4J と Log4j はスタックトレースを自動的にきれいにログへ追加してくれます。
例:アプローチの比較
// 悪い例(連結は常に実行される)
logger.debug("オブジェクト: " + expensiveToString(obj));
// 良い例(遅延評価で組み立て)
logger.debug("オブジェクト: {}", obj);
3. ログレベルの選び方
すべてを ERROR で出すなら、それはログというより「常時点灯の警告灯」です。すべてを DEBUG にすると、詳細に溺れてしまいます。どのレベルをいつ使うか整理しましょう。
| レベル | 用途 | メッセージ例 |
|---|---|---|
|
システムが誤動作する、または動かなくなる重大な障害 | 「データベース接続エラー」 |
|
致命的ではないが注意が必要な重要な警告 | 「ユーザーが見つかりません。guest を使用します」 |
|
アプリケーションの正常動作を表す通常の出来事 | 「ユーザーを登録しました: vasya」 |
|
デバッグ用の詳細情報。本番では不要 | 「メソッド checkPassword がパラメータ … で呼び出されました」 |
|
最も詳細な情報。深い診断に用いる | 「処理ループ開始: i=0」 |
典型的なメッセージの例
- ERROR — ファイルを書き込めない、未処理の例外を捕捉、サービスが利用不可。
- WARN — 廃止予定 API、疑わしいユーザーの挙動、試行回数の上限超過。
- INFO — ユーザーのログイン/ログアウト、注文処理の完了、アプリ起動。
- DEBUG — リクエストのパラメータ、変数の値、中間計算結果。
- TRACE — メソッドへの入出、内部ループ、アルゴリズムの詳細。
ヒント:
本番環境では通常 INFO 以上、場合によっては WARN と ERROR のみを有効にします。DEBUG と TRACE は複雑なバグ調査時のみ。
4. ベストプラクティス(ロギング)
機微情報をログに出力しない
パスワード、トークン、クレジットカード番号などはログに書くべきではありません。「ログファイルは自分しか見ないから」と思っても、GDPR のような規制や、同僚が誤ってログを共有チャットに送ってしまう可能性を思い出してください.
// 悪い例:
logger.info("ユーザー {} がパスワード {} でログインしました", username, password);
// 良い例:
logger.info("ユーザー {} がシステムにログインしました", username);
ERROR レベルの乱用を避ける
すべてを logger.error で書いていると、本当に大惨事が起きたとき誰も気づきません — 常時「赤いランプ」に慣れてしまうからです。アプリが実際に処理を継続できない、またはビジネスロジックが破綻している場合にのみ ERROR を使いましょう。
例外はスタックトレースごと記録する
ex.getMessage() だけを書かないでください。どこでエラーが起きたか分からなくなります。例外はログメソッドの第 2 引数として渡しましょう。
logger.error("リクエスト処理中にエラーが発生しました", ex);
一意の識別子を使う(イベントの相関)
大規模システムでは、各リクエストやユーザー、操作に一意の識別子を付与すると便利です。システムの異なる部分にまたがる出来事を「縫い合わせる」助けになります。
logger.info("注文処理を開始: orderId={}", orderId);
logger.info("注文処理が正常に完了: orderId={}", orderId);
何でもかんでもログに書かない
ログが多すぎると、かえって役に立ちません。すべての行をログに出すのは避け、必要な情報に絞りましょう。
分かりやすいメッセージを書く
コードの作者だけでなく、半年後にログを読む人にも伝わるように書きましょう。略語や分かりにくい省略、「内輪ネタ」は避けてください。
5. 実践: ログのフォーマットとレベルの設定
Log4j2(log4j2.xml)でのフォーマット設定例
<Configuration>
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level %logger{36} - %msg%n"/>
</Console>
</Appenders>
<Loggers>
<Root level="info">
<AppenderRef ref="Console"/>
</Root>
</Loggers>
</Configuration>
これは何を意味するか?
- %d{...} — 発生時刻。
- %-5level — レベル(ERROR、INFO など)。
- %logger{36} — ロガー名(通常はクラス)。
- %msg — メッセージ本文。
さまざまなログレベルを使ったコード例(SLF4J)
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
public class LogDemo {
private static final Logger logger = LoggerFactory.getLogger(LogDemo.class);
public static void main(String[] args) {
logger.info("アプリケーションが起動しました");
logger.debug("変数 x の値: {}", 42);
try {
throw new IllegalArgumentException("おっと!");
// ...
} catch (Exception ex) {
logger.error("起動中にエラーが発生しました", ex);
}
}
}
レベル差のデモ
設定でロガーのレベルが INFO の場合、DEBUG 以下のメッセージは出力されません。設定ファイルでレベルを debug に変更してみると、より詳細が表示されるはずです。
6. よくある間違い
間違い №1: ログでの文字列連結。 初心者は次のように書きがちです。
logger.debug("ユーザー: " + user.getName() + ", ロール: " + user.getRole());
結果として、DEBUG レベルが無効でもこれらの文字列は組み立てられ、余計な負荷になります。パラメータを使いましょう!
間違い №2: 例外のスタックなしでロギング。 メッセージだけを書いてしまう:
logger.error("エラー: " + ex.getMessage());
これではどこでエラーが起きたかがログから分かりません。例外は第 2 引数で渡しましょう!
間違い №3: なんでもかんでも ERROR レベルでロギング。 すべてが赤ければ、何も赤くありません。レベルは用途に応じて使い分けないと、重要なエラーが「小事」に埋もれてしまいます。
間違い №4: 機微情報のロギング。 パスワード、トークン、カード番号は決してログに書かないでください。誰にも見られないと思っても、人生にはサプライズがつきものです。
間違い №5: 分かりにくいメッセージ。 ログに「ERR42: fail」のように書くと、1 カ月後には自分でも何のことか思い出せません。明確かつ十分に書きましょう。
間違い №6: 一意の識別子がない。 複雑なシステムでは、orderId、userId などの識別子がないと、出来事を「縫い合わせ」て特定のユーザーや注文で何が起きたかを把握できません。
GO TO FULL VERSION