logging-patterns

name	logging-patterns
description	Use when implementing structured logging, configuring log levels, adding observability, or establishing logging standards in Spring Boot applications.

Logging Patterns Skill

You are an expert in structured logging and observability for Spring Boot applications. You implement logging that is useful for debugging, monitoring, and auditing.

SLF4J Logger Setup

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

@Service
public class PaymentService {

    private static final Logger log = LoggerFactory.getLogger(PaymentService.class);

    // Always declare logger as private static final
    // Always use the class itself, not a string
}

Log Levels

@Service
public class OrderService {

    private static final Logger log = LoggerFactory.getLogger(OrderService.class);

    @Transactional
    public Order processOrder(Long orderId) {
        // TRACE - very detailed, loop internals, variable states
        log.trace("Entering processOrder with orderId={}", orderId);

        // DEBUG - useful for development, flow tracking
        log.debug("Looking up order: {}", orderId);

        var order = orderRepository.findById(orderId)
            .orElseThrow(() -> {
                // WARN - unexpected but recoverable
                log.warn("Order not found: {}", orderId);
                return new ResourceNotFoundException("Order", orderId);
            });

        // INFO - business events, state transitions
        log.info("Processing order: id={}, status={}, total={}",
            order.getId(), order.getStatus(), order.getTotal());

        try {
            paymentGateway.charge(order);
        } catch (PaymentGatewayException e) {
            // ERROR - requires attention, includes exception
            log.error("Payment failed for order: id={}, amount={}",
                order.getId(), order.getTotal(), e);
            throw new PaymentProcessingException("Payment failed", e);
        }

        order.setStatus(OrderStatus.CONFIRMED);
        var saved = orderRepository.save(order);

        log.info("Order processed successfully: id={}, newStatus={}",
            saved.getId(), saved.getStatus());

        return saved;
    }
}

Parameterized Logging

// CORRECT - parameterized (lazy evaluation)
log.debug("Processing item: id={}, price={}", item.getId(), item.getPrice());

// WRONG - string concatenation (always evaluated)
log.debug("Processing item: id=" + item.getId() + ", price=" + item.getPrice());

// CORRECT - expensive operations wrapped in level check
if (log.isDebugEnabled()) {
    log.debug("Full order details: {}", order.toDetailedString());
}

// For multiple parameters use varargs
log.info("Order summary: id={}, customer={}, items={}, total={}, status={}",
    order.getId(), order.getCustomerId(), order.getItems().size(),
    order.getTotal(), order.getStatus());

Structured Logging with MDC

import org.slf4j.MDC;

@Component
public class RequestContextFilter extends OncePerRequestFilter {

    @Override
    protected void doFilterInternal(HttpServletRequest request,
                                     HttpServletResponse response,
                                     FilterChain filterChain) throws ServletException, IOException {
        try {
            MDC.put("requestId", UUID.randomUUID().toString());
            MDC.put("userId", extractUserId(request));
            MDC.put("clientIp", request.getRemoteAddr());
            MDC.put("method", request.getMethod());
            MDC.put("path", request.getRequestURI());

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

// Logback configuration for structured JSON output
// logback-spring.xml
/*
<configuration>
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="net.logstash.logback.encoder.LogstashEncoder">
            <includeMdcKeyName>requestId</includeMdcKeyName>
            <includeMdcKeyName>userId</includeMdcKeyName>
            <includeMdcKeyName>clientIp</includeMdcKeyName>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="CONSOLE"/>
    </root>
</configuration>
*/

Request/Response Logging

@Component
public class RequestLoggingInterceptor implements HandlerInterceptor {

    private static final Logger log = LoggerFactory.getLogger(RequestLoggingInterceptor.class);

    @Override
    public boolean preHandle(HttpServletRequest request,
                              HttpServletResponse response,
                              Object handler) {
        request.setAttribute("startTime", System.currentTimeMillis());
        log.info("Incoming request: {} {}", request.getMethod(), request.getRequestURI());
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request,
                                 HttpServletResponse response,
                                 Object handler,
                                 Exception ex) {
        var startTime = (Long) request.getAttribute("startTime");
        var duration = System.currentTimeMillis() - startTime;

        log.info("Request completed: {} {} status={} duration={}ms",
            request.getMethod(), request.getRequestURI(),
            response.getStatus(), duration);
    }
}

Service Method Logging Pattern

@Aspect
@Component
public class ServiceLoggingAspect {

    private static final Logger log = LoggerFactory.getLogger(ServiceLoggingAspect.class);

    @Around("@within(org.springframework.stereotype.Service)")
    public Object logServiceMethod(ProceedingJoinPoint joinPoint) throws Throwable {
        var methodName = joinPoint.getSignature().toShortString();
        var args = joinPoint.getArgs();

        log.debug("Calling {} with args: {}", methodName, args);
        var startTime = System.nanoTime();

        try {
            var result = joinPoint.proceed();
            var duration = (System.nanoTime() - startTime) / 1_000_000;
            log.debug("{} completed in {}ms", methodName, duration);
            return result;
        } catch (Exception e) {
            var duration = (System.nanoTime() - startTime) / 1_000_000;
            log.error("{} failed after {}ms: {}", methodName, duration, e.getMessage());
            throw e;
        }
    }
}

What NOT to Log

// NEVER log sensitive data
log.info("User authenticated: password={}", password);         // NEVER
log.info("Payment processed: cardNumber={}", cardNumber);       // NEVER
log.info("Token issued: jwt={}", jwtToken);                     // NEVER

// CORRECT
log.info("User authenticated: userId={}", userId);
log.info("Payment processed: last4={}, amount={}", last4Digits, amount);
log.info("Token issued for user: {}", userId);

// NEVER log at INFO level in loops
for (var item : items) {
    log.info("Processing item: {}", item.getId()); // Use DEBUG or TRACE
}

// CORRECT
log.info("Processing {} items", items.size());
for (var item : items) {
    log.debug("Processing item: {}", item.getId());
}

Application Properties

# application.yml
logging:
  level:
    root: INFO
    pl.piomin.services: DEBUG
    org.springframework.web: INFO
    org.hibernate.SQL: DEBUG
    org.hibernate.type.descriptor.sql.BasicBinder: TRACE
  pattern:
    console: "%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{requestId}] %-5level %logger{36} - %msg%n"