Over a million developers have joined DZone.
{{announcement.body}}
{{announcement.title}}

SiftingAppender: Logging Different Threads to Different Log Files

DZone's Guide to

SiftingAppender: Logging Different Threads to Different Log Files

· Java Zone
Free Resource

Learn how to troubleshoot and diagnose some of the most common performance issues in Java today. Brought to you in partnership with AppDynamics.

One novel feature of Logback is SiftingAppender (JavaDoc). In short it's a proxy appender that creates one child appender per each unique value of a given runtime property. Typically this property is taken from MDC. Here is an example based on the official documentation linked above:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
 
    <appender name="SIFT" class="ch.qos.logback.classic.sift.SiftingAppender">
        <discriminator>
            <key>userid</key>
            <defaultValue>unknown</defaultValue>
        </discriminator>
        <sift>
            <appender name="FILE-${userid}" class="ch.qos.logback.core.FileAppender">
                <file>user-${userid}.log</file>
                <layout class="ch.qos.logback.classic.PatternLayout">
                    <pattern>%d{HH:mm:ss:SSS} | %-5level | %thread | %logger{20} | %msg%n%rEx</pattern>
                </layout>
            </appender>
        </sift>
    </appender>
 
    <root level="ALL">
        <appender-ref ref="SIFT" />
    </root>
</configuration>

Notice that the <file> property is parameterized with ${userid} property. Where does this property come from? It has to be placed in MDC. For example in a web application using Spring Security I tend to use a servlet filter with a help of SecurityContextHolder:

import javax.servlet._
import org.slf4j.MDC
import org.springframework.security.core.context.SecurityContextHolder
import org.springframework.security.core.userdetails.UserDetails
 
class UserIdFilter extends Filter
{
    def init(filterConfig: FilterConfig) {}
 
    def doFilter(request: ServletRequest, response: ServletResponse, chain: FilterChain) {
        val userid = Option(
            SecurityContextHolder.getContext.getAuthentication
        ).collect{case u: UserDetails => u.getUsername}
 
        MDC.put("userid", userid.orNull)
        try {
            chain.doFilter(request, response)
        } finally {
            MDC.remove("userid")
        }
 
    }
 
    def destroy() {}
}

Just make sure this filter is applied after Spring Security filter. But that's not the point. The presence of ${userid} placeholder in the file name causes sifting appender to create one child appender for each different value of this property (thus: different user names). Running your web application with this configuration will quickly create several log files like user-alice.log, user-bob.log and user-unknown.log in case of MDC property not set.

Another use case is using thread name rather than MDC property. Unfortunately this is not built in, but can be easily plugged in using custom Discriminator as opposed to default MDCBasedDiscriminator:

public class ThreadNameBasedDiscriminator implements Discriminator<ILoggingEvent> {
 
    private static final String KEY = "threadName";
 
    private boolean started;
 
    @Override
    public String getDiscriminatingValue(ILoggingEvent iLoggingEvent) {
        return Thread.currentThread().getName();
    }
 
    @Override
    public String getKey() {
        return KEY;
    }
 
    public void start() {
        started = true;
    }
 
    public void stop() {
        started = false;
    }
 
    public boolean isStarted() {
        return started;
    }
}

Now we have to instruct logback.xml to use our custom discriminator:

<appender name="SIFT" class="ch.qos.logback.classic.sift.SiftingAppender">
    <discriminator class="com.blogspot.nurkiewicz.ThreadNameBasedDiscriminator"/>
    <sift>
        <appender class="ch.qos.logback.core.FileAppender">
            <file>app-${threadName}.log</file>
            <layout class="ch.qos.logback.classic.PatternLayout">
                <pattern>%d{HH:mm:ss:SSS} | %-5level | %logger{20} | %msg%n%rEx</pattern>
            </layout>
        </appender>
    </sift>
</appender>

Note that we no longer put %thread in PatternLayout - it is unnecessary as thread name is part of the log file name:

  • app-main.log
  • app-http-nio-8080-exec-1.log
  • app-taskScheduler-1
  • app-ForkJoinPool-1-worker-1.log
  • ...and so forth
This is probably not the most convenient setup for server application, but on desktop where you have a limited number of focused threads like EDT, IO thread, etc. it might be a vital alternative.



Understand the needs and benefits around implementing the right monitoring solution for a growing containerized market. Brought to you in partnership with AppDynamics.

Topics:

Published at DZone with permission of Tomasz Nurkiewicz, DZone MVB. See the original article here.

Opinions expressed by DZone contributors are their own.

THE DZONE NEWSLETTER

Dev Resources & Solutions Straight to Your Inbox

Thanks for subscribing!

Awesome! Check your inbox to verify your email so you can start receiving the latest in tech news and resources.

X

{{ parent.title || parent.header.title}}

{{ parent.tldr }}

{{ parent.urlSource.name }}