Spring BootCustom Logging
Spring Boot

Custom Logging

Custom logging extends the standard logging infrastructure to meet application-specific needs — AOP-based method logging, request/response logging, custom appenders, metrics integration, and log event enrichment. This entry covers AOP logging, HTTP request logging with filters, custom Logback appenders, log-driven metrics, and audit logging patterns.

AOP Method Logging

An AOP aspect intercepts method calls and logs entry, exit, duration, and exceptions without polluting business code. Apply it selectively with a custom @Logged annotation or broadly via a pointcut expression. The aspect captures parameters, return values, and timing for every annotated method.
Java
// ── @Logged annotation ───────────────────────────────────────────────
@Target({ElementType.METHOD, ElementType.TYPE})
@Retention(RetentionPolicy.RUNTIME)
public @interface Logged {
    boolean logArgs() default true;
    boolean logResult() default true;
    boolean logDuration() default true;
    String  level() default "DEBUG";
}

// ── AOP logging aspect ────────────────────────────────────────────────
@Aspect
@Component
@Slf4j
public class LoggingAspect {

    // ── Pointcut: all @Logged methods ─────────────────────────────────
    @Pointcut("@annotation(com.myapp.annotation.Logged) " +
              "|| @within(com.myapp.annotation.Logged)")
    public void loggedMethods() {}

    @Around("loggedMethods()")
    public Object logMethodCall(ProceedingJoinPoint pjp)
            throws Throwable {

        MethodSignature signature =
            (MethodSignature) pjp.getSignature();
        String className  = signature.getDeclaringType()
            .getSimpleName();
        String methodName = signature.getName();
        Object[] args     = pjp.getArgs();

        log.debug("→ {}.{}({})",
            className, methodName, formatArgs(args));

        long start = System.currentTimeMillis();
        try {
            Object result = pjp.proceed();
            long duration = System.currentTimeMillis() - start;

            log.debug("← {}.{} returned {} in {}ms",
                className, methodName,
                formatResult(result), duration);

            return result;

        } catch (Exception ex) {
            long duration = System.currentTimeMillis() - start;
            log.warn("✗ {}.{} threw {} after {}ms: {}",
                className, methodName,
                ex.getClass().getSimpleName(),
                duration, ex.getMessage());
            throw ex;
        }
    }

    // ── Service layer pointcut without annotation ─────────────────────
    @Around("execution(public * com.myapp.service.*Service.*(..))")
    public Object logServiceMethods(ProceedingJoinPoint pjp)
            throws Throwable {
        String method =
            pjp.getSignature().toShortString();
        long start = System.currentTimeMillis();
        try {
            Object result = pjp.proceed();
            log.debug("{} completed in {}ms",
                method,
                System.currentTimeMillis() - start);
            return result;
        } catch (Exception ex) {
            log.warn("{} failed: {}",
                method, ex.getMessage());
            throw ex;
        }
    }

    private String formatArgs(Object[] args) {
        if (args == null || args.length == 0) return "";
        return Arrays.stream(args)
            .map(a -> a == null ? "null" : a.toString())
            .collect(Collectors.joining(", "));
    }

    private String formatResult(Object result) {
        if (result == null) return "null";
        if (result instanceof Collection)
            return result.getClass().getSimpleName() +
                "[" + ((Collection<?>) result).size() + "]";
        return result.toString();
    }
}

HTTP Request and Response Logging

Log all inbound HTTP traffic — method, URI, status, duration, and optionally the body — using a OncePerRequestFilter or Spring's ContentCachingRequestWrapper and ContentCachingResponseWrapper. Limit body logging to development environments and never log sensitive paths such as /auth/login.
Java
@Component
@Order(Ordered.HIGHEST_PRECEDENCE + 1)
@Slf4j
public class HttpLoggingFilter extends OncePerRequestFilter {

    private static final Set<String> EXCLUDE_PATHS = Set.of(
        "/actuator/health",
        "/actuator/info",
        "/favicon.ico"
    );

    private static final Set<String> SENSITIVE_PATHS = Set.of(
        "/api/v1/auth/login",
        "/api/v1/auth/refresh"
    );

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

        String path = request.getRequestURI();

        // Skip noisy health checks
        if (EXCLUDE_PATHS.contains(path)) {
            chain.doFilter(request, response);
            return;
        }

        ContentCachingRequestWrapper  wrappedRequest  =
            new ContentCachingRequestWrapper(request,  10_000);
        ContentCachingResponseWrapper wrappedResponse =
            new ContentCachingResponseWrapper(response);

        long start = System.currentTimeMillis();

        try {
            chain.doFilter(wrappedRequest, wrappedResponse);
        } finally {
            long duration = System.currentTimeMillis() - start;
            int  status   = wrappedResponse.getStatus();

            if (status >= 400) {
                // Log errors at WARN with body
                log.warn("HTTP {} {} → {} {}ms body={}",
                    request.getMethod(), path, status, duration,
                    SENSITIVE_PATHS.contains(path)
                        ? "[REDACTED]"
                        : getBody(wrappedRequest));
            } else {
                log.debug("HTTP {} {} → {} {}ms",
                    request.getMethod(), path, status, duration);
            }

            // MUST copy body back — response is consumed
            wrappedResponse.copyBodyToResponse();
        }
    }

    private String getBody(ContentCachingRequestWrapper req) {
        byte[] buf = req.getContentAsByteArray();
        if (buf.length == 0) return "";
        return new String(buf, 0,
            Math.min(buf.length, 500),   // cap at 500 chars
            StandardCharsets.UTF_8);
    }

    @Override
    protected boolean shouldNotFilterAsyncDispatch() {
        return false;
    }
}

Custom Logback Appender

A custom Logback appender sends log events to any destination — a database, a message queue, an alerting system, or a webhook. Extend AppenderBase<ILoggingEvent> and implement the append() method. The appender is lifecycle-managed by Logback — start() and stop() control initialisation.
Java
// ── Custom appender — sends ERROR events to Slack ────────────────────
public class SlackAlertAppender
        extends AppenderBase<ILoggingEvent> {

    private String webhookUrl;
    private String channel;
    private String appName;

    // Setters are called from logback XML configuration
    public void setWebhookUrl(String url) {
        this.webhookUrl = url;
    }
    public void setChannel(String channel) {
        this.channel = channel;
    }
    public void setAppName(String name) {
        this.appName = name;
    }

    private RestClient restClient;

    @Override
    public void start() {
        if (webhookUrl == null || webhookUrl.isBlank()) {
            addError("webhookUrl is required");
            return;
        }
        restClient = RestClient.create();
        super.start();
    }

    @Override
    protected void append(ILoggingEvent event) {
        if (event.getLevel().levelInt < Level.ERROR_INT) {
            return;   // only send ERRORs
        }

        try {
            String text = String.format(
                ":rotating_light: *[%s]* ERROR in `%s`\n" +
                "```%s```",
                appName,
                event.getLoggerName(),
                event.getFormattedMessage());

            restClient.post()
                .uri(webhookUrl)
                .body(Map.of("text", text, "channel", channel))
                .retrieve()
                .toBodilessEntity();

        } catch (Exception ex) {
            addError("Failed to send Slack alert", ex);
        }
    }
}

<!-- Register in logback-spring.xml ──────────────────────────────────── -->
<appender name="SLACK"
    class="com.myapp.logging.SlackAlertAppender">
  <webhookUrl>${SLACK_WEBHOOK_URL}</webhookUrl>
  <channel>#alerts</channel>
  <appName>${spring:spring.application.name}</appName>
  <filter class="ch.qos.logback.classic.filter.LevelFilter">
    <level>ERROR</level>
    <onMatch>ACCEPT</onMatch>
    <onMismatch>DENY</onMismatch>
  </filter>
</appender>

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

Log-Driven Metrics with Micrometer

Logs and metrics are complementary. Log-driven metrics count specific log events — error rates, slow query occurrences, authentication failures — using Micrometer counters that increment when a matching log event occurs. This avoids duplicating instrumentation and provides metrics from logs automatically.
Java
// ── Logback TurboFilter — intercept events and record metrics ─────────
@Component
@RequiredArgsConstructor
public class MetricsLoggingFilter extends TurboFilter {

    private final MeterRegistry meterRegistry;

    @Override
    public FilterReply decide(Marker marker, Logger logger,
                               Level level, String format,
                               Object[] params, Throwable t) {

        // Count every ERROR event
        if (level == Level.ERROR) {
            meterRegistry.counter("log.events",
                "level",   "error",
                "logger",  logger.getName())
                .increment();
        }

        // Count every WARN event
        if (level == Level.WARN) {
            meterRegistry.counter("log.events",
                "level",  "warn",
                "logger", logger.getName())
                .increment();
        }

        return FilterReply.NEUTRAL;   // don't block the event
    }
}

// ── Register TurboFilter in Spring context ────────────────────────────
@Configuration
@RequiredArgsConstructor
public class LoggingMetricsConfig {

    private final MetricsLoggingFilter metricsFilter;

    @PostConstruct
    public void registerTurboFilter() {
        LoggerContext ctx = (LoggerContext)
            LoggerFactory.getILoggerFactory();
        ctx.addTurboFilter(metricsFilter);
    }
}

// ── Specific business event metrics from logs ─────────────────────────
@Service
@Slf4j
@RequiredArgsConstructor
public class AuthenticationService {

    private final MeterRegistry meterRegistry;

    public AuthResponse login(LoginRequest request) {
        try {
            AuthResponse response = doLogin(request);
            log.info("Login success email={}",
                request.email());
            meterRegistry.counter("auth.login",
                "result", "success").increment();
            return response;
        } catch (BadCredentialsException ex) {
            log.warn("Login failed email={} reason=bad_credentials",
                request.email());
            meterRegistry.counter("auth.login",
                "result", "failure",
                "reason", "bad_credentials").increment();
            throw ex;
        } catch (AccountLockedException ex) {
            log.warn("Login blocked email={} reason=account_locked",
                request.email());
            meterRegistry.counter("auth.login",
                "result", "failure",
                "reason", "account_locked").increment();
            throw ex;
        }
    }
}

Audit Logging Pattern

Audit logs record who did what and when for compliance, security investigation, and debugging. Separate audit logs from application logs — different retention, different consumers, different sensitivity. Use a dedicated appender and a dedicated logger name so audit events never mix with debug output.
Java
// ── Audit event record ───────────────────────────────────────────────
public record AuditEvent(
    String  action,
    String  actor,
    String  resourceType,
    String  resourceId,
    String  outcome,         // SUCCESS or FAILURE
    String  ipAddress,
    String  correlationId,
    Instant timestamp,
    Map<String, String> details
) {}

// ── Dedicated audit logger ─────────────────────────────────────────────
@Component
@Slf4j
public class AuditLogger {

    // Named logger separate from the class logger
    private static final Logger AUDIT =
        LoggerFactory.getLogger("AUDIT");

    private final ObjectMapper objectMapper;

    public AuditLogger(ObjectMapper objectMapper) {
        this.objectMapper = objectMapper;
    }

    public void log(AuditEvent event) {
        try {
            // Log as JSON for structured audit trail
            AUDIT.info(objectMapper.writeValueAsString(event));
        } catch (JsonProcessingException ex) {
            log.error("Failed to serialize audit event", ex);
        }
    }

    public void logAccess(String actor, String resource,
                           String resourceId, String ip) {
        log(new AuditEvent(
            "RESOURCE_ACCESSED", actor,
            resource, resourceId, "SUCCESS",
            ip, MDC.get("correlationId"),
            Instant.now(), Map.of()));
    }

    public void logMutation(String actor, String action,
            String resource, String resourceId,
            String ip, Map<String, String> changes) {
        log(new AuditEvent(
            action, actor, resource, resourceId,
            "SUCCESS", ip, MDC.get("correlationId"),
            Instant.now(), changes));
    }
}

<!-- Dedicated audit appender in logback-spring.xml ──────────────────── -->
<appender name="AUDIT_FILE"
    class="ch.qos.logback.core.rolling.RollingFileAppender">
  <file>logs/audit.log</file>
  <encoder>
    <!-- Plain message only — already JSON from AuditLogger -->
    <pattern>%m%n</pattern>
  </encoder>
  <rollingPolicy
      class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
    <fileNamePattern>logs/audit-%d{yyyy-MM-dd}.log.gz</fileNamePattern>
    <!-- Compliance: keep audit logs 7 years -->
    <maxHistory>2555</maxHistory>
  </rollingPolicy>
</appender>

<!-- Route AUDIT logger to dedicated appender only -->
<logger name="AUDIT" level="INFO" additivity="false">
  <appender-ref ref="AUDIT_FILE"/>
</logger>