Automatically include authenticated user in your Spring Boot logs

May 16, 2023 2-minute read

When troubleshootings systems, it is incredibly helpful (or even absolutely necessary) to view the authenticated user associated to any log lines.

One can use Mapped Diagnostic Context (MDC) to the rescue here. MDC provides a way to enrich log messages with information that could be unavailable in the scope where the logging actually occurs but that can be indeed useful to better track the execution of the program.

Here’s an example of how I implemented this using Spring Boot v2.7.

First define a custom filter that will set the user in the MDC. I’m setting it based on the name property of the principal, but if you cast your principal to the type you actually use, you can of course set anything you want here.

import org.slf4j.MDC
import org.springframework.security.core.AuthenticatedPrincipal
import org.springframework.security.core.context.SecurityContextHolder
import org.springframework.stereotype.Component
import org.springframework.web.filter.OncePerRequestFilter
import javax.servlet.FilterChain
import javax.servlet.http.HttpServletRequest
import javax.servlet.http.HttpServletResponse

@Component
class UserMdcFilter : OncePerRequestFilter() {

    companion object {
        private const val USER_MDC_KEY = "user"
    }

    override fun doFilterInternal(
        request: HttpServletRequest,
        response: HttpServletResponse,
        filterChain: FilterChain
    ) {
        val principal = SecurityContextHolder.getContext().authentication?.principal as? AuthenticatedPrincipal
        if (principal != null) {
            val user = principal.name
            MDC.put(USER_MDC_KEY, user)
        }

        try {
            filterChain.doFilter(request, response)
        } finally {
            MDC.remove(USER_MDC_KEY)
        }
    }
}

Then, add the filter in your Spring Security configuration.

// I do it after FilterSecurityInterceptor, otherwise authenticated context is not set
http.addFilterAfter(userMdcFilter, FilterSecurityInterceptor::class.java)

You can view the data by modifying the log pattern in your SLF4J configuration to include MDC:

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
        <Pattern>
            %clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd HH:mm:ss.SSS}}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr([%mdc]){yellow} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}
        </Pattern>
        <charset>utf8</charset>
    </encoder>
</appender>

This is the default Spring console log pattern, except %clr([%mdc]){yellow} is added to display the MDC values.

End result:

2023-05-16 01:23:14.346 DEBUG [] 77570 --- [nio-8080-exec-7] [user=bf11c59b-eaca-47cd-a9d4-77cd62181e55] o.s.jdbc.core.JdbcTemplate: Executing prepared SQL query

Hope this helps someone!