Spring Boot

Logging Basics

Spring Boot configures logging automatically through spring-boot-starter-logging, which bundles Logback as the default implementation behind the SLF4J facade. Log levels, output format, and file output are configurable in application.yml without any additional dependencies. This entry covers log levels, configuration in YAML, Lombok's @Slf4j, MDC context, and structured logging fundamentals.

Log Levels and Basic Configuration

Spring Boot uses five log levels in ascending severity: TRACE, DEBUG, INFO, WARN, and ERROR. The root level defaults to INFO — only INFO, WARN, and ERROR messages are emitted. Override levels per package or class in application.yml. Spring Boot and Spring Framework internal packages are set to WARN by default so they do not clutter application logs.

yaml

# ── application.yml ────────────────────────────────────────────────────
logging:
  # ── Root level — applies to everything not explicitly configured ──────
  level:
    root: INFO

    # ── Package-level overrides ───────────────────────────────────────
    com.myapp:            DEBUG    # all application classes
    com.myapp.service:    DEBUG    # service layer
    com.myapp.repository: WARN     # suppress Hibernate SQL details

    # ── Framework packages ────────────────────────────────────────────
    org.springframework:              WARN
    org.springframework.web:          INFO   # HTTP request mapping
    org.springframework.security:     WARN
    org.hibernate.SQL:                DEBUG  # log SQL statements
    org.hibernate.type.descriptor:    TRACE  # log bind parameters
    org.flywaydb:                     INFO

  # ── Console output format ─────────────────────────────────────────────
  pattern:
    console: >
      %d{yyyy-MM-dd HH:mm:ss.SSS} %5p
      [%15.15t] %-40.40logger{39} : %m%n%wEx

  # ── Log to file ───────────────────────────────────────────────────────
  file:
    name: logs/application.log

  logback:
    rollingpolicy:
      max-file-size:    10MB
      max-history:      30        # keep 30 days of rotated files
      total-size-cap:   1GB
      file-name-pattern: logs/application-%d{yyyy-MM-dd}.%i.log.gz

# ── application-dev.yml — verbose development logging ────────────────
logging:
  level:
    root: DEBUG
    com.myapp: TRACE
    org.hibernate.SQL: DEBUG
    org.hibernate.type.descriptor.sql: TRACE

# ── application-prod.yml — minimal production logging ────────────────
logging:
  level:
    root: WARN
    com.myapp: INFO

Using @Slf4j and the Logger

Inject a logger into every class that needs one. Lombok's @Slf4j annotation generates a static final Logger field named log, eliminating boilerplate. Always use parameterised logging — log.info("msg {}", value) — never string concatenation — to avoid building the message string when the level is disabled.

Java

// ── @Slf4j — Lombok generates: private static final Logger log ───────
@Service
@RequiredArgsConstructor
@Slf4j
public class OrderService {

    private final OrderRepository    orderRepo;
    private final InventoryService   inventoryService;

    public OrderResponse create(CreateOrderRequest request,
                                 Long userId) {
        log.debug("Creating order for user {} with {} items",
            userId, request.items().size());

        try {
            inventoryService.reserve(request.items());
            Order order = orderRepo.save(
                Order.from(request, userId));

            log.info("Order {} created for user {}",
                order.getId(), userId);

            return OrderResponse.from(order);

        } catch (InsufficientStockException ex) {
            log.warn("Insufficient stock for order — user={} items={}",
                userId, request.items(), ex);
            throw ex;
        } catch (Exception ex) {
            log.error("Unexpected error creating order " +
                "for user {}", userId, ex);
            throw ex;
        }
    }

    // ── Level guard — avoid computing expensive arguments ─────────────
    public void processLargeDataset(List<Order> orders) {
        if (log.isDebugEnabled()) {
            log.debug("Processing {} orders: {}",
                orders.size(),
                orders.stream()
                    .map(o -> o.getId().toString())
                    .collect(Collectors.joining(",")));
        }
    }
}

// ── WRONG — string concatenation always builds the string ────────────
log.debug("Order id=" + order.getId() + " user=" + userId);

// CORRECT — parameterised — string built only if DEBUG is enabled ──
log.debug("Order id={} user={}", order.getId(), userId);

// ── Log the exception with stack trace ───────────────────────────────
try {
    riskyOperation();
} catch (Exception ex) {
    // Pass exception as the LAST argument — Logback prints stack trace
    log.error("Operation failed for order {}", orderId, ex);
}

MDC — Mapped Diagnostic Context

MDC attaches key-value pairs to the current thread's logging context. Every log statement on that thread automatically includes the MDC values without passing them explicitly. Use MDC for correlation IDs, user IDs, tenant IDs, and request paths to make logs traceable across a request lifecycle.

Java

// ── MDC filter — set context on every inbound request ────────────────
@Component
@Order(Ordered.HIGHEST_PRECEDENCE)
@Slf4j
public class MdcLoggingFilter extends OncePerRequestFilter {

    @Override
    protected void doFilterInternal(HttpServletRequest  request,
                                    HttpServletResponse response,
                                    FilterChain         chain)
            throws ServletException, IOException {

        String correlationId = Optional
            .ofNullable(request.getHeader("X-Correlation-ID"))
            .orElse(UUID.randomUUID().toString());

        String requestId = UUID.randomUUID().toString();

        try {
            MDC.put("correlationId", correlationId);
            MDC.put("requestId",     requestId);
            MDC.put("method",        request.getMethod());
            MDC.put("path",          request.getRequestURI());
            MDC.put("remoteIp",      getClientIp(request));

            // Propagate correlation ID back to caller
            response.setHeader("X-Correlation-ID", correlationId);
            response.setHeader("X-Request-ID",     requestId);

            chain.doFilter(request, response);

        } finally {
            MDC.clear();   // ALWAYS clear — thread pool reuse
        }
    }

    private String getClientIp(HttpServletRequest req) {
        String fwd = req.getHeader("X-Forwarded-For");
        return fwd != null ? fwd.split(",")[0].trim()
                           : req.getRemoteAddr();
    }
}

# ── Include MDC values in log pattern ─────────────────────────────────
logging:
  pattern:
    console: >
      %d{HH:mm:ss.SSS} %5p
      [%X{correlationId:-},%X{requestId:-}]
      %-40.40logger{39} : %m%n

// ── Log output with MDC ────────────────────────────────────────────────
// 10:30:00.123  INFO [abc-123,req-456] c.m.s.OrderService : Order 42 created
// 10:30:00.456 DEBUG [abc-123,req-456] c.m.r.OrderRepo    : SELECT ...

// ── Set MDC manually in a service ────────────────────────────────────
@Service
@Slf4j
public class PaymentService {

    public PaymentResponse charge(Long orderId, BigDecimal amount) {
        MDC.put("orderId",        String.valueOf(orderId));
        MDC.put("paymentAmount",  amount.toPlainString());
        try {
            log.info("Processing payment");
            // All log statements below automatically include orderId
            PaymentResponse result = gateway.charge(amount);
            log.info("Payment processed successfully ref={}",
                result.reference());
            return result;
        } finally {
            MDC.remove("orderId");
            MDC.remove("paymentAmount");
        }
    }
}

Logging Best Practices

Well-structured logs are searchable, actionable, and noise-free. Apply consistent conventions across the codebase: log at the right level, include context, avoid sensitive data, and use structured formats in production.

Java

// ── Rule 1: Log at the correct level ─────────────────────────────────
log.trace("Entering method with args={}", args);  // fine-grained debug
log.debug("Repository query returned {} rows", count);
log.info("Order {} placed for user {}", orderId, userId);
log.warn("Payment retry {} of {} for order {}", attempt, max, orderId);
log.error("Failed to charge payment for order {}", orderId, ex);

// ── Rule 2: Never log sensitive data ─────────────────────────────────
// WRONG:
log.info("User {} authenticated password={}", email, password);
log.debug("JWT token={}", jwtToken);
log.info("Credit card charged last4={} cvv={}", last4, cvv);

// CORRECT — log identifiers and outcomes, not secrets
log.info("User {} authenticated successfully", email);
log.debug("JWT issued for user {}", email);
log.info("Card charged successfully for order {}", orderId);

// ── Rule 3: Include enough context to act on ──────────────────────────
// WRONG — useless without context
log.error("Something went wrong");
log.warn("Retry");

// CORRECT — actionable
log.error("Order creation failed userId={} itemCount={} cause={}",
    userId, items.size(), ex.getMessage(), ex);
log.warn("Payment retry attempt {}/{} orderId={} delayMs={}",
    attempt, maxAttempts, orderId, delay);

// ── Rule 4: Log at service boundaries ────────────────────────────────
// Log when entering a significant operation (DEBUG)
// Log when an operation completes (INFO for business events)
// Log when an operation fails (WARN for expected, ERROR for unexpected)

// ── Rule 5: Use structured logging in production ──────────────────────
// JSON log enables queries like:
// { level: "ERROR", service: "order-service", userId: "42" }
// Use logstash-logback-encoder or log4j2 JSON layout

// ── Rule 6: Log durations for SLA-sensitive operations ───────────────
@Slf4j
public class ExternalApiClient {
    public Response call(Request req) {
        long start = System.currentTimeMillis();
        try {
            Response response = httpClient.send(req);
            log.info("External API responded status={} durationMs={}",
                response.status(),
                System.currentTimeMillis() - start);
            return response;
        } catch (Exception ex) {
            log.error("External API failed durationMs={} error={}",
                System.currentTimeMillis() - start,
                ex.getMessage(), ex);
            throw ex;
        }
    }
}

Structured Logging with JSON

Structured logging emits JSON instead of plain text. Each field is a distinct JSON key — level, message, timestamp, traceId — making logs queryable by any log aggregation platform (Loki, Elasticsearch, Splunk, Datadog). Add the logstash-logback-encoder to produce JSON without changing application code.

XML

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

// ── logback-spring.xml ─────────────────────────────────────────────────
// <configuration>
//
//   <!-- JSON appender for production -->
//   <springProfile name="prod">
//     <appender name="JSON"
//         class="ch.qos.logback.core.ConsoleAppender">
//       <encoder
//           class="net.logstash.logback.encoder.LogstashEncoder">
//         <customFields>
//           {"service":"order-service","env":"production"}
//         </customFields>
//         <fieldNames>
//           <timestamp>timestamp</timestamp>
//           <message>message</message>
//           <logger>logger</logger>
//           <thread>thread</thread>
//         </fieldNames>
//       </encoder>
//     </appender>
//     <root level="INFO">
//       <appender-ref ref="JSON"/>
//     </root>
//   </springProfile>
//
//   <!-- Human-readable appender for development -->
//   <springProfile name="dev,default">
//     <appender name="CONSOLE"
//         class="ch.qos.logback.core.ConsoleAppender">
//       <encoder>
//         <pattern>
//           %d{HH:mm:ss.SSS} %5p [%X{correlationId:-}]
//           %-40.40logger{39} : %m%n
//         </pattern>
//       </encoder>
//     </appender>
//     <root level="DEBUG">
//       <appender-ref ref="CONSOLE"/>
//     </root>
//   </springProfile>
//
// </configuration>

// ── Sample JSON output ────────────────────────────────────────────────
// {
//   "timestamp":     "2024-03-15T10:30:00.123Z",
//   "level":         "INFO",
//   "logger":        "com.myapp.service.OrderService",
//   "message":       "Order 42 created for user 1",
//   "thread":        "http-nio-8080-exec-1",
//   "traceId":       "abc123def456abc1",
//   "spanId":        "def456abc123def4",
//   "correlationId": "req-uuid-789",
//   "service":       "order-service",
//   "env":           "production"
// }

// ── Add custom fields to a specific log event ─────────────────────────
import net.logstash.logback.argument.StructuredArguments.*;

log.info("Order created {}",
    kv("orderId",   order.getId()),
    kv("userId",    userId),
    kv("total",     order.getTotal()),
    kv("itemCount", order.getItems().size()));

// ── Output ────────────────────────────────────────────────────────────
// { "message": "Order created", "orderId": 42,
//   "userId": 1, "total": 99.99, "itemCount": 3 }

Security Testing

SLF4J