spring-projects / spring-boot

Spring Boot
https://spring.io/projects/spring-boot
Apache License 2.0
74.55k stars 40.54k forks source link

Auto configure SLF4J MDC with a servlet filter #7927

Closed bbrouwer closed 6 years ago

bbrouwer commented 7 years ago

I find it useful to automatically configure the Mapped Diagnostic Context in slf4j to include

There could be plenty of other things worth capturing, but these are the ones I like to capture by default. What I've done is made a servlet filter that is registered by an @Configuration class registered in META-INF/spring.factories as a FilterRegistrationBean.

What the filter does is use SpEL from the ServletRequest to retrieve these values:

Then, all you need to do is have a logback pattern that includes the MDC and you easily get these added to the log. Is there interest in adding this to Spring Boot? I can submit the code if there is interest. Of course it would be nice to have some properties to alternatively configure it in application.properties. Maybe like this:

logging.mdc.src=getHeader('X-Forwarded-For') ?: getRemoteHost()
logging.mdc.uid=userPrincipal?.name
logging.mdc.uri=requestURI
# to show custom user values
logging.mdc.locale=locale.displayName
philwebb commented 7 years ago

Thanks for the suggestion but we need to be a bit careful here that we don't end up implementing programming by properties. We've generally tried to avoid adding SpEL expression support in properties files whenever possible.

I get the feeling that setting MDC attributes is something that tends to be quite application specific and not something that we should necessarily add to Boot itself. Mostly applications should be able to add MDC attributes easily by doing something like this:

@Component 
public static class MdcFilter extends OncePerRequestFilter() {

    @Override
    protected abstract void doFilterInternal(HttpServletRequest request,
            HttpServletResponse response, FilterChain filterChain)
                    throws ServletException, IOException {
        MDC.put("src", request.getRemoteHost());
        // ...
    }

}
bbrouwer commented 7 years ago

I'm fine if SpEL is not the way to go, but do you see value in injecting those 3 attributes into the MDC automatically for web apps? They have proven to be very valuable to me, and honestly nobody has ever gone away from those defaults in my organization. Plus, you can configure the logback log pattern to only include the MDC variables that you choose, or include them all, which is what I do. It can be a nice way to easily get useful information into your logs without really thinking much about it.

philwebb commented 7 years ago

@bbrouwer That's an interesting suggestion, something that's just on by default with perhaps an option to disable it. That would remove the complexity around the application.properties but still be quite valuable.

I wonder if there are any downsides? Is there a performance hit updating the MDC on each request?

bbrouwer commented 7 years ago

I have not noticed any performance impact because of using the MDC. There's really not much the MDC has to do. This would simply pull out a few bits from the ServletRequest, and under the covers, I think the MDC is really just a map attached to a ThreadLocal.

The only thing you run into is how it relates to Spring Security. If you put the filter in too early, Spring Security hasn't had the opportunity to populate the userPrincipal. If you put the filter in after Spring Security, then you won't have src or requested URI information in your Spring Security logs, which could be very useful. So you could actually do this with two filters: one early to add the src and URI to the MDC, and one later after Spring Security populates the userPrincipal. In my implementation I cheated because we just use BasicAuth, so I didn't need two filters.

The MDC is also a concept in slf4j, so it could cover both logback and log4j, maybe others as well. I see that Spring Boot still relies simply on Commons Logging which doesn't support the concept of the MDC. So what would be the right way to implement this? Would there be different configurations activated specifically for slf4j, or would we need to make specific implementations for log4j or logback?

Also, where would this filter(s) class live? Would it go in spring-web while the autoconfig goes in spring-boot-autoconfigure? Or would it all go in spring-boot-autoconfigure?

Finally, what configuration would you suggest for disabling this feature? One property in application.properties to disable it all? 3 properties, one for each of the 3 settings? Or simply rely upon excluding this particular autoconfiguration via @EnableAutoConfiguration(exclude={WebMdcAutoConfiguration.class}) or spring.autoconfigure.exclude=org.springframework.web.logging.WebMdcAutoConfiguration (or whatever package and class names sounds good.

philwebb commented 7 years ago

The MDC is also a concept in slf4j, so it could cover both logback and log4j, maybe others as well. I see that Spring Boot still relies simply on Commons Logging which doesn't support the concept of the MDC. So what would be the right way to implement this?

Spring Boot uses commons-logging for its own logging, but it supports Logback, Log4J2 and JUL for users (see LoggingSystem subclasses). Out of the box we give users logback.

So what would be the right way to implement this? Would there be different configurations activated specifically for slf4j, or would we need to make specific implementations for log4j or logback?

My guess is we can just create a single config and activate it if SLF4J is on the classpath (but I'll admit that's just a guess at this point).

Also, where would this filter(s) class live? Would it go in spring-web while the autoconfig goes in spring-boot-autoconfigure? Or would it all go in spring-boot-autoconfigure?

Probably all in spring-boot-autoconfigure. If the filter is generally useful we could put it in spring-boot under the org.springframework.boot.web.filter package. I think it's probably going to be so small that in auto-configure would be best.

Finally, what configuration would you suggest for disabling this feature? One property in application.properties to disable it all?

A single property would probably be enough. The exclude= route isn't usually idea, it's meant more as an escape hatch.

wilkinsona commented 7 years ago

Logback already has an MDC-related Filter: https://logback.qos.ch/xref/ch/qos/logback/classic/helpers/MDCInsertingServletFilter.html

bbrouwer commented 7 years ago

Logback already has an MDC-related Filter

This is basically what I'm asking for. This will only work for Logback, though, and not log4j or any other slf4j compliant logging implementation. Also, MDCInsertingServletFilter does not add the user to the MDC.

If we want to rely upon MDCInsertingServletFilter and not worry about log4j, I can go with that approach. I am usually using logback these days anyway. But I also find it valuable to know who the user is.

Ultimately, I would like the solution to be auto-configured.

ceefour commented 7 years ago

This is a very nice suggestion. It'd be great if this ever gets implemented.

philwebb commented 6 years ago

After some consideration we've decided it would be best not add this into the core of Boot. Thanks anyway for the suggestion.