Logging Patterns Skill

Rule: JSON is the default log format. Plain text logging is only for local development with human-logs profile. Production, CI/CD, and Kubernetes environments must use structured JSON.

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
• An AI coding assistant needs to analyze application behavior

AI-Friendly Logging

Key insight: JSON logs are better for AI analysis - faster parsing, fewer tokens, direct field access.

Why JSON for AI coding assistants?

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

Recommended Setup for AI-Assisted Development

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

# 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

Log Format Optimized for AI Analysis

{
  "timestamp": "2026-01-29T10:15:30.123Z",
  "level": "INFO",
  "logger": "pl.piomin.services.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

Reading Logs with AI coding assistants

When asking AI to analyze logs:

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

Quick Setup (Spring Boot 4.x)

Native Structured Logging

Spring Boot 4.x has built-in JSON logging — no extra dependencies required.

# application.yml — this is the REQUIRED default for every app
logging:
  structured:
    format:
      console: logstash    # or "ecs" for Elastic Common Schema

# Supported formats:
#   logstash - JSON (most common, compatible with ELK and OpenTelemetry Collector)
#   ecs      - Elastic Common Schema (native Elastic/Kibana integration)
#   gelf     - Graylog Extended Log Format

OpenTelemetry Integration

When Micrometer Tracing is on the classpath, traceId and spanId are automatically included in every JSON log line. This allows OTel Collector to correlate logs with distributed traces.

# application.yml — tracing + structured logging together
management:
  tracing:
    sampling:
      probability: 1.0

logging:
  structured:
    format:
      console: logstash
  pattern:
    level: "%5p [${spring.application.name:},%X{traceId:-},%X{spanId:-}]"

Output:

{"@timestamp":"2026-01-29T10:15:30.123Z","level":"INFO","logger_name":"pl.piomin.services.OrderService","message":"Order created","traceId":"abc123def456","spanId":"789xyz","service.name":"order-service"}

The traceId field in JSON logs is the same trace ID visible in Jaeger, Tempo, or any OTel-compatible backend — enabling direct log-to-trace correlation.

Profile-Based Switching

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

Usage:

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

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

Setup for Spring Boot < 3.4 (Legacy)

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>

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

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

Logger Declaration

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

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

    // use `log` directly for logging
}

Parameterized Logging

// ✅ 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("Order details: {}", order.toDetailedString());
}

Exception Logging

// ✅ GOOD: Pass exception as last argument
try {
    processOrder(order);
} catch (PaymentException e) {
    log.error("Payment failed for order {}", order.getId(), e);
}

// ❌ BAD: Loses stack trace
log.error("Payment failed: " + e.getMessage());

// ❌ BAD: Exception in placeholder (toString only)
log.error("Payment failed for order {}: {}", order.getId(), e);

// ❌ BAD: No context - useless when reading logs later
log.error("Error occurred", e);

// ✅ GOOD: Key-value pairs become separate JSON fields (SLF4J 2 fluent API)
log.atError()
    .addKeyValue("orderId", orderId)
    .addKeyValue("step", "payment")
    .setCause(e)
    .log("Order processing failed");

Log Once, at the Boundary

// ❌ BAD: Log-and-rethrow - the same stack trace appears once per layer
try {
    paymentClient.charge(order);
} catch (PaymentException e) {
    log.error("Payment failed", e);
    throw e;
}

// ✅ GOOD: Wrap with context and rethrow, no log
try {
    paymentClient.charge(order);
} catch (PaymentException e) {
    throw new OrderProcessingException("Payment failed for order " + order.id(), e);
}

The @RestControllerAdvice handler (or message listener / scheduled job) that ends the flow logs the exception once. Expected business errors (404, validation) are WARN or DEBUG without stack trace; only unexpected failures are ERROR with the throwable.

What NOT to Log

// ❌ NEVER
log.info("Login user={} password={}", username, password);  // credentials
log.debug("Calling API with token {}", jwt);                 // tokens, API keys, session IDs
log.info("Payment card={}", cardNumber);                     // full card number / CVV
log.info("Created customer {}", customer);                   // toString() may dump email, address, IBAN

// ✅ Identify, don't expose
log.info("Login attempted userId={}", userId);
log.info("Payment authorised cardLast4={}", last4);
log.info("Created customer customerId={}", customer.id());

• Sensitive: passwords, secrets, tokens, Authorization/Cookie headers, card data, national IDs, health data, PII (email, phone, address, birth date)
• Records print every component in toString() - log the ID or override toString() for records carrying PII
• Don't log full request/response bodies in production

Log Levels Guide

MDC (Mapped Diagnostic Context)

MDC attaches context (request ID, user ID) to every log line in the current thread automatically.

Request Filter for Correlation IDs

@Component
@Order(Ordered.HIGHEST_PRECEDENCE)
public class MdcFilter implements Filter {

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
            throws IOException, ServletException {
        try {
            HttpServletRequest httpRequest = (HttpServletRequest) request;
            String requestId = httpRequest.getHeader("X-Request-Id");
            if (requestId == null) {
                requestId = UUID.randomUUID().toString().substring(0, 8);
            }
            MDC.put("requestId", requestId);
            MDC.put("clientIp", httpRequest.getRemoteAddr());

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

MDC in Service Layer

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

    public Order createOrder(OrderRequest request) {
        MDC.put("userId", request.userId());
        MDC.put("orderId", String.valueOf(request.orderId()));

        log.info("Creating order");
        // All subsequent log lines in this thread automatically include userId and orderId

        return processOrder(request);
    }
}

MDC with Virtual Threads

Virtual threads don't inherit MDC from parent threads. Use TaskDecorator to propagate:

@Configuration
public class AsyncConfig {

    @Bean
    public TaskDecorator mdcTaskDecorator() {
        return runnable -> {
            Map<String, String> context = MDC.getCopyOfContextMap();
            return () -> {
                if (context != null) {
                    MDC.setContextMap(context);
                }
                try {
                    runnable.run();
                } finally {
                    MDC.clear();
                }
            };
        };
    }
}

The decorator only applies to Spring-managed executors (@Async, injected ThreadPoolTaskExecutor). CompletableFuture.supplyAsync(...) without an executor runs on the common pool and loses MDC - always pass the Spring executor.

Quick Reference