logging-patterns

ロギングパターンのスキル

構造化された、AI が解析しやすい形式に重点を置いた、Java アプリケーションの効果的なロギングです。

使用するタイミング

• ユーザーが「ロギングを追加して」／「ログを改善して」／「これをデバッグして」と言うとき
• ログからアプリケーションの処理フローを分析するとき
• 構造化ロギング（JSON）を設定するとき
• 相関 ID を使ってリクエストをトレースするとき
• AI／Claude Code がアプリケーションの動作を分析する必要があるとき

---

AI に適したロギング

重要なポイント： JSON ログは AI による分析に適しています。解析が速く、トークン数を抑えられ、フィールドに直接アクセスできます。

AI／Claude Code に JSON が適している理由

# Text format - AI must "interpret" the string
2026-01-29 10:15:30 INFO OrderService - Order 12345 created for user-789, total: 99.99

# JSON format - AI extracts fields directly
{"timestamp":"2026-01-29T10:15:30Z","level":"INFO","orderId":12345,"userId":"user-789","total":99.99}

項目	テキスト	JSON
解析	正規表現／解釈	フィールドに直接アクセス
トークン使用量	多い（パターンの繰り返し）	少ない（構造化済み）
エラーの抽出	スタックトレースのテキストを解析	exception フィールド
フィルタリング	grep パターン	jq クエリ

AI 支援開発におすすめの設定

# application.yml - JSON by default
logging:
  structured:
    format:
      console: logstash  # Spring Boot 3.4+

# When YOU need to read logs manually:
# Option 1: Use jq
# tail -f app.log | jq .

# Option 2: Switch profile temporarily
# java -jar app.jar --spring.profiles.active=human-logs

AI 分析に最適化されたログ形式

{
  "timestamp": "2026-01-29T10:15:30.123Z",
  "level": "INFO",
  "logger": "com.example.OrderService",
  "message": "Order created",
  "requestId": "req-abc123",
  "traceId": "trace-xyz",
  "orderId": 12345,
  "userId": "user-789",
  "duration_ms": 45,
  "step": "payment_completed"
}

AI によるデバッグに重要なフィールド：

• requestId - 同じリクエストのすべてのログをグループ化します
• step - 処理フローの進行状況を追跡します
• duration_ms - 時間のかかる処理を特定します
• level - エラーをすばやくフィルタリングします

AI／Claude Code を使ったログの確認

AI にログの分析を依頼するとき：

# Get recent errors
cat app.log | jq 'select(.level == "ERROR")' | tail -20

# Follow specific request
cat app.log | jq 'select(.requestId == "req-abc123")'

# Find slow operations
cat app.log | jq 'select(.duration_ms > 1000)'

AI は次のことができます：

1. JSON を直接解析する（推測は不要）
2. requestId を使ってリクエストの処理フローを追跡する
3. エラーの発生箇所を正確に特定する
4. ステップ間の所要時間を測定する

---

クイックセットアップ（Spring Boot 3.4 以降）

ネイティブの構造化ロギング

Spring Boot 3.4 以降には標準でサポートが組み込まれているため、追加の依存関係は不要です！

# application.yml
logging:
  structured:
    format:
      console: logstash    # or "ecs" for Elastic Common Schema

# Supported formats: logstash, ecs, gelf

プロファイルに基づく切り替え

# application.yml (default - JSON for AI/prod)
spring:
  profiles:
    default: json-logs

---
spring:
  config:
    activate:
      on-profile: json-logs
logging:
  structured:
    format:
      console: logstash

---
spring:
  config:
    activate:
      on-profile: human-logs
# No structured format = human-readable default
logging:
  pattern:
    console: "%d{HH:mm:ss.SSS} %-5level [%thread] %logger{36} - %msg%n"

使用方法：

# Default: JSON (for AI, CI/CD, production)
./mvnw spring-boot:run

# Human-readable when needed
./mvnw spring-boot:run -Dspring.profiles.active=human-logs

---

Spring Boot 3.4 より前のバージョンでのセットアップ

Logstash Logback Encoder

pom.xml：

<dependency>
    <groupId>net.logstash.logback</groupId>
    <artifactId>logstash-logback-encoder</artifactId>
    <version>7.4</version>
</dependency>

logback-spring.xml：

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    
    <springProfile name="!human-logs">
        <appender name="JSON" class="ch.qos.logback.core.ConsoleAppender">
            <encoder class="net.logstash.logback.encoder.LogstashEncoder">
                <includeMdcKeyName>requestId</includeMdcKeyName>
                <includeMdcKeyName>userId</includeMdcKeyName>
            </encoder>
        </appender>
        <root level="INFO">
            <appender-ref ref="JSON"/>
        </root>
    </springProfile>

    
    <springProfile name="human-logs">
        <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
            <encoder>
                <pattern>%d{HH:mm:ss.SSS} %-5level [%thread] %logger{36} - %msg%n</pattern>
            </encoder>
        </appender>
        <root level="INFO">
            <appender-ref ref="CONSOLE"/>
        </root>
    </springProfile>

</configuration>

カスタムフィールドの追加（Logstash Encoder）

import static net.logstash.logback.argument.StructuredArguments.kv;

// Fields appear as separate JSON keys
log.info("Order created",
    kv("orderId", order.getId()),
    kv("userId", user.getId()),
    kv("total", order.getTotal()),
    kv("step", "order_created")
);

// Output:
// {"message":"Order created","orderId":123,"userId":"u-456","total":99.99,"step":"order_created"}

---

SLF4J の基本

ロガーの宣言

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

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

// Or with Lombok
@Slf4j
@Service
public class OrderService {
    // use `log` directly
}

パラメーター化ロギング

// ✅ GOOD: Evaluated only if level enabled
log.debug("Processing order {} for user {}", orderId, userId);

// ❌ BAD: Always concatenates
log.debug("Processing order " + orderId + " for user " + userId);

// ✅ For expensive operations
if (log.isDebugEnabled()) {
    log.debug("Full order details: {}", order.toJson());
}

---

ログレベル

レベル	使用するタイミング	例
ERROR	対応が必要な障害	未処理の例外、サービス停止
WARN	想定外だが処理済み	リトライの成功、非推奨 API の使用
INFO	ビジネスイベント	注文の作成、決済の処理
DEBUG	技術的な詳細	メソッドのパラメーター、SQL クエリ
TRACE	非常に詳細な情報	ループの反復（使用頻度は低い）

log.error("Payment failed", kv("orderId", id), kv("reason", reason), exception);
log.warn("Retry succeeded", kv("attempt", 3), kv("orderId", id));
log.info("Order shipped", kv("orderId", id), kv("trackingNumber", tracking));
log.debug("Fetching from DB", kv("query", "findById"), kv("id", id));

---

MDC（Mapped Diagnostic Context）

MDC を使うと、リクエストの各ログエントリーにコンテキストを追加できます。トレースに不可欠です。

リクエスト ID フィルター

@Component
@Order(Ordered.HIGHEST_PRECEDENCE)
public class RequestContextFilter extends OncePerRequestFilter {

    @Override
    protected void doFilterInternal(HttpServletRequest request,
                                    HttpServletResponse response,
                                    FilterChain chain) throws ServletException, IOException {
        try {
            String requestId = Optional.ofNullable(request.getHeader("X-Request-ID"))
                .filter(s -> !s.isBlank())
                .orElse(UUID.randomUUID().toString().substring(0, 8));

            MDC.put("requestId", requestId);
            response.setHeader("X-Request-ID", requestId);

            chain.doFilter(request, response);
        } finally {
            MDC.clear();
        }
    }
}

ユーザーコンテキストの追加

// After authentication
MDC.put("userId", authentication.getName());

// All subsequent logs include userId automatically
log.info("User action performed");  // {"userId":"john123","message":"User action performed"}

非同期処理での MDC

// MDC doesn't auto-propagate to new threads!

// ✅ Copy MDC context
Map<String, String> context = MDC.getCopyOfContextMap();

CompletableFuture.runAsync(() -> {
    try {
        if (context != null) MDC.setContextMap(context);
        log.info("Async task running");  // Has requestId, userId
    } finally {
        MDC.clear();
    }
});

---

ログに記録する内容

ビジネスイベント（INFO）

// Include key identifiers and state
log.info("Order created",
    kv("orderId", id),
    kv("userId", userId),
    kv("total", total),
    kv("itemCount", items.size()),
    kv("step", "order_created"));

log.info("Payment processed",
    kv("orderId", id),
    kv("amount", amount),
    kv("method", "card"),
    kv("step", "payment_completed"));

外部呼び出し（所要時間付き）

long start = System.currentTimeMillis();
try {
    Result result = externalService.call(params);
    log.info("External call succeeded",
        kv("service", "PaymentGateway"),
        kv("operation", "charge"),
        kv("duration_ms", System.currentTimeMillis() - start));
    return result;
} catch (Exception e) {
    log.error("External call failed",
        kv("service", "PaymentGateway"),
        kv("operation", "charge"),
        kv("duration_ms", System.currentTimeMillis() - start),
        e);
    throw e;
}

処理フローのステップ（AI によるトレース用）

public Order processOrder(CreateOrderRequest request) {
    log.info("Processing started", kv("step", "start"), kv("requestData", request.summary()));

    Order order = createOrder(request);
    log.info("Order created", kv("step", "order_created"), kv("orderId", order.getId()));

    validateInventory(order);
    log.info("Inventory validated", kv("step", "inventory_ok"), kv("orderId", order.getId()));

    processPayment(order);
    log.info("Payment processed", kv("step", "payment_done"), kv("orderId", order.getId()));

    log.info("Processing completed", kv("step", "complete"), kv("orderId", order.getId()));
    return order;
}

---

ログに記録しない内容

// ❌ NEVER log sensitive data
log.info("Login", kv("password", password));           // Passwords
log.info("Payment", kv("cardNumber", card));           // Full card numbers
log.info("Request", kv("token", jwtToken));            // Tokens
log.info("User", kv("ssn", socialSecurity));           // PII

// ✅ Safe alternatives
log.info("Login attempted", kv("userId", userId));
log.info("Payment", kv("cardLast4", last4));
log.info("Token validated", kv("subject", sub), kv("exp", expiry));

---

例外のロギング

境界で一度だけログに記録する

// ❌ BAD: Logs same exception multiple times
void methodA() {
    try { methodB(); }
    catch (Exception e) { log.error("Error", e); throw e; }  // Log #1
}
void methodB() {
    try { methodC(); }
    catch (Exception e) { log.error("Error", e); throw e; }  // Log #2
}

// ✅ GOOD: Log at service boundary only
@RestControllerAdvice
public class GlobalExceptionHandler {

    @ExceptionHandler(Exception.class)
    public ResponseEntity<?> handle(Exception e, HttpServletRequest request) {
        log.error("Request failed",
            kv("path", request.getRequestURI()),
            kv("method", request.getMethod()),
            kv("errorType", e.getClass().getSimpleName()),
            e);  // Full stack trace
        return ResponseEntity.status(500).body(errorResponse);
    }
}

コンテキストを含める

// ❌ Useless
log.error("Error occurred", e);

// ✅ Useful for debugging
log.error("Order processing failed",
    kv("orderId", orderId),
    kv("step", "payment"),
    kv("userId", userId),
    kv("attemptNumber", attempt),
    e);

---

クイックリファレンス

// === Setup ===
private static final Logger log = LoggerFactory.getLogger(MyClass.class);

// === Logging with structured fields ===
import static net.logstash.logback.argument.StructuredArguments.kv;

log.info("Event", kv("key1", value1), kv("key2", value2));
log.error("Failed", kv("context", ctx), exception);

// === MDC ===
MDC.put("requestId", requestId);
MDC.put("userId", userId);
// ... all logs now include these
MDC.clear();  // cleanup

// === Levels ===
log.error()  // Failures
log.warn()   // Handled issues
log.info()   // Business events
log.debug()  // Technical details

---

ログの分析（AI／人間）

# Pretty print JSON logs
tail -f app.log | jq .

# Filter errors
cat app.log | jq 'select(.level == "ERROR")'

# Follow request flow
cat app.log | jq 'select(.requestId == "abc123")'

# Find slow operations (>1s)
cat app.log | jq 'select(.duration_ms > 1000)'

# Get timeline of steps
cat app.log | jq 'select(.requestId == "abc123") | {time: .timestamp, step: .step, message: .message}'

---

関連スキル

• spring-boot-patterns - Spring Boot の設定
• jpa-patterns - データベースのロギング（SQL クエリ）
• 今後追加予定：observability-patterns - メトリクス、トレース、包括的なオブザーバビリティ