logging-patterns

Compare original and translation side by side

🇺🇸

Original

English
🇨🇳

Translation

Chinese

Logging Patterns Skill

日志模式技巧

Effective logging for Java applications with focus on structured, AI-parsable formats.
针对Java应用的高效日志实践,重点关注结构化、可被AI解析的格式。

When to Use

适用场景

  • User says "add logging" / "improve logs" / "debug this"
  • Analyzing application flow from logs
  • Setting up structured logging (JSON)
  • Request tracing with correlation IDs
  • AI/Claude Code needs to analyze application behavior

  • 用户提出「添加日志」/「优化日志」/「调试该问题」
  • 通过日志分析应用运行流程
  • 搭建结构化日志(JSON)体系
  • 使用关联ID实现请求链路追踪
  • AI/Claude Code需要分析应用行为

AI-Friendly Logging

AI友好型日志

Key insight: JSON logs are better for AI analysis - faster parsing, fewer tokens, direct field access.
核心要点: JSON格式日志更适合AI分析,解析速度更快、Token消耗量更低、可直接访问字段。

Why JSON for AI/Claude Code?

为什么JSON适合AI/Claude Code?

undefined
undefined

Text format - AI must "interpret" the string

Text format - AI must "interpret" the string

2026-01-29 10:15:30 INFO OrderService - Order 12345 created for user-789, total: 99.99
2026-01-29 10:15:30 INFO OrderService - Order 12345 created for user-789, total: 99.99

JSON format - AI extracts fields directly

JSON format - AI extracts fields directly

{"timestamp":"2026-01-29T10:15:30Z","level":"INFO","orderId":12345,"userId":"user-789","total":99.99}

| Aspect | Text | JSON |
|--------|------|------|
| Parsing | Regex/interpretation | Direct field access |
| Token usage | Higher (repeated patterns) | Lower (structured) |
| Error extraction | Parse stack trace text | `exception` field |
| Filtering | grep patterns | `jq` queries |
{"timestamp":"2026-01-29T10:15:30Z","level":"INFO","orderId":12345,"userId":"user-789","total":99.99}

| 对比项 | 文本格式 | JSON格式 |
|--------|----------|----------|
| 解析方式 | 正则/内容解读 | 直接字段访问 |
| Token消耗量 | 更高(存在重复模式) | 更低(结构化) |
| 错误提取 | 解析堆栈跟踪文本 | `exception` 字段 |
| 过滤方式 | grep模式匹配 | `jq` 查询 |

Recommended Setup for AI-Assisted Development

AI辅助开发的推荐配置

yaml
undefined
yaml
undefined

application.yml - JSON by default

application.yml - JSON by default

logging: structured: format: console: logstash # Spring Boot 3.4+
logging: structured: format: console: logstash # Spring Boot 3.4+

When YOU need to read logs manually:

When YOU need to read logs manually:

Option 1: Use jq

Option 1: Use jq

tail -f app.log | jq .

tail -f app.log | jq .

Option 2: Switch profile temporarily

Option 2: Switch profile temporarily

java -jar app.jar --spring.profiles.active=human-logs

java -jar app.jar --spring.profiles.active=human-logs

undefined
undefined

Log Format Optimized for AI Analysis

适配AI分析的日志格式

json
{
  "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"
}
Key fields for AI debugging:
  • requestId
    - group all logs from same request
  • step
    - track progress through flow
  • duration_ms
    - identify slow operations
  • level
    - quick filter for errors
json
{
  "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
    - 快速过滤错误日志

Reading Logs with AI/Claude Code

借助AI/Claude Code读取日志

When asking AI to analyze logs:
bash
undefined
当要求AI分析日志时:
bash
undefined

Get recent errors

Get recent errors

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

Follow specific request

Follow specific request

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

Find slow operations

Find slow operations

cat app.log | jq 'select(.duration_ms > 1000)'

AI can then:
1. Parse JSON directly (no guessing)
2. Follow request flow via requestId
3. Identify exactly where errors occurred
4. Measure timing between steps

---
cat app.log | jq 'select(.duration_ms > 1000)'

AI随后可以:
1. 直接解析JSON(无需猜测内容)
2. 通过requestId跟踪请求流程
3. 精确定位错误发生位置
4. 统计步骤之间的耗时

---

Quick Setup (Spring Boot 3.4+)

快速配置(Spring Boot 3.4+版本)

Native Structured Logging

原生结构化日志

Spring Boot 3.4+ has built-in support - no extra dependencies!
yaml
undefined
Spring Boot 3.4+已内置支持,无需额外依赖!
yaml
undefined

application.yml

application.yml

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

Supported formats: logstash, ecs, gelf

Supported formats: logstash, ecs, gelf

undefined
undefined

Profile-Based Switching

基于配置文件的切换

yaml
undefined
yaml
undefined

application.yml (default - JSON for AI/prod)

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
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

No structured format = human-readable default

logging: pattern: console: "%d{HH:mm:ss.SSS} %-5level [%thread] %logger{36} - %msg%n"

**Usage:**
```bash
logging: pattern: console: "%d{HH:mm:ss.SSS} %-5level [%thread] %logger{36} - %msg%n"

**使用方式:**
```bash

Default: JSON (for AI, CI/CD, production)

Default: JSON (for AI, CI/CD, production)

./mvnw spring-boot:run
./mvnw spring-boot:run

Human-readable when needed

Human-readable when needed

./mvnw spring-boot:run -Dspring.profiles.active=human-logs

---
./mvnw spring-boot:run -Dspring.profiles.active=human-logs

---

Setup for Spring Boot < 3.4

低于3.4版本的Spring Boot配置

Logstash Logback Encoder

Logstash Logback Encoder

pom.xml:
xml
<dependency>
    <groupId>net.logstash.logback</groupId>
    <artifactId>logstash-logback-encoder</artifactId>
    <version>7.4</version>
</dependency>
logback-spring.xml:
xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <!-- JSON (default) -->
    <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>

    <!-- Human-readable (optional) -->
    <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>
pom.xml:
xml
<dependency>
    <groupId>net.logstash.logback</groupId>
    <artifactId>logstash-logback-encoder</artifactId>
    <version>7.4</version>
</dependency>
logback-spring.xml:
xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <!-- JSON (default) -->
    <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>

    <!-- Human-readable (optional) -->
    <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>

Adding Custom Fields (Logstash Encoder)

添加自定义字段(Logstash Encoder)

java
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"}

java
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 Basics

SLF4J基础

Logger Declaration

日志器声明

java
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
}
java
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
}

Parameterized Logging

参数化日志

java
// ✅ 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());
}

java
// ✅ 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());
}

Log Levels

日志级别

LevelWhenExample
ERRORFailures needing attentionUnhandled exception, service down
WARNUnexpected but handledRetry succeeded, deprecated API used
INFOBusiness eventsOrder created, payment processed
DEBUGTechnical detailsMethod params, SQL queries
TRACEVery detailedLoop iterations (rarely used)
java
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));

级别适用场景示例
ERROR需要立即处理的故障未处理异常、服务宕机
WARN非预期但已处理的问题重试成功、调用已废弃API
INFO业务事件订单创建、支付完成
DEBUG技术细节方法参数、SQL查询
TRACE极细粒度信息循环迭代(极少使用)
java
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(映射诊断上下文)

MDC adds context to every log entry in a request - essential for tracing.
MDC可为同一个请求中的所有日志条目添加上下文信息,是链路追踪的核心工具。

Request ID Filter

请求ID过滤器

java
@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();
        }
    }
}
java
@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();
        }
    }
}

Add User Context

添加用户上下文

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

// All subsequent logs include userId automatically
log.info("User action performed");  // {"userId":"john123","message":"User action performed"}
java
// 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 in Async Operations

异步操作中的MDC使用

java
// 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();
    }
});

java
// 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();
    }
});

What to Log

应该记录的内容

Business Events (INFO)

业务事件(INFO级别)

java
// 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"));
java
// 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"));

External Calls (with timing)

外部调用(含耗时统计)

java
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;
}
java
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;
}

Flow Steps (for AI tracing)

流程步骤(用于AI追踪)

java
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;
}

java
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;
}

What NOT to Log

禁止记录的内容

java
// ❌ 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));

java
// ❌ 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));

Exception Logging

异常日志

Log Once at Boundary

在边界处统一记录一次

java
// ❌ 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);
    }
}
java
// ❌ 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);
    }
}

Include Context

附带上下文信息

java
// ❌ 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);

java
// ❌ 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);

Quick Reference

快速参考

java
// === 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

java
// === 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

Analyzing Logs (AI/Human)

日志分析(AI/人工)

bash
undefined
bash
undefined

Pretty print JSON logs

Pretty print JSON logs

tail -f app.log | jq .
tail -f app.log | jq .

Filter errors

Filter errors

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

Follow request flow

Follow request flow

cat app.log | jq 'select(.requestId == "abc123")'
cat app.log | jq 'select(.requestId == "abc123")'

Find slow operations (>1s)

Find slow operations (>1s)

cat app.log | jq 'select(.duration_ms > 1000)'
cat app.log | jq 'select(.duration_ms > 1000)'

Get timeline of steps

Get timeline of steps

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

---
cat app.log | jq 'select(.requestId == "abc123") | {time: .timestamp, step: .step, message: .message}'

---

Related Skills

相关技巧

  • spring-boot-patterns
    - Spring Boot configuration
  • jpa-patterns
    - Database logging (SQL queries)
  • Future:
    observability-patterns
    - Metrics, tracing, full observability
  • spring-boot-patterns
    - Spring Boot配置
  • jpa-patterns
    - 数据库日志(SQL查询)
  • 后续补充:
    observability-patterns
    - 指标、链路追踪、全链路可观测性