Many applications define one or more appenders and them simply list them all as part of their root logger section in the logback.xml configuration file:<\/p>\n\n\n
\n<configuration scan="true">\n <appender name="LOGSTASH" class="net.logstash.logback.appender.LogstashTcpSocketAppender">\n <destination>logstash-server<\/destination>\n <encoder class="net.logstash.logback.encoder.LogstashEncoder"\/>\n <\/appender>\n <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">\n <file>log\/server.log<\/file>\n <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">\n <fileNamePattern>log\/server.%d{yyyy-MM-dd}.log<\/fileNamePattern>\n <maxHistory>30<\/maxHistory>\n <\/rollingPolicy>\n <encoder>\n <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %mdc %-5level %logger{36} - %msg%n<\/pattern>\n <\/encoder>\n <\/appender>\n <root level="info">\n <appender-ref ref="LOGSTASH"\/>\n <appender-ref ref="FILE"\/>\n <\/root>\n<\/configuration>\n<\/pre><\/div>\n\n\nThis setup will send all log messages to both of the configured appenders.<\/p>\n\n\n\n\n\n\n\n
You can also configure loggers to use a specific appender. We use this in some applications to for example write all SOAP-related logging to a dedicated file, as we don’t want to pollute our regular logs with tons of SOAP messages but still want to capture those messages:<\/p>\n\n\n
\n...\n<appender name="SOAP" class="ch.qos.logback.core.rolling.RollingFileAppender">\n <file>log\/soap.log<\/file>\n ...\n<\/appender>\n<logger name="org.springframework.ws.client.MessageTracing" level="trace" additivity="false">\n <appender-ref ref="SOAP"\/>\n<\/logger>\n<logger name= "org.springframework.ws.soap.server.endpoint.interceptor.SoapEnvelopeLoggingInterceptor" level="debug" additivity="false">\n <appender-ref ref="SOAP"\/>\n<\/logger>\n<root level="info">\n <appender-ref ref="FILE"\/>\n<\/root>\n<\/pre><\/div>\n\n\nBy specifying the appender-ref inside the logger element and using additivity=”false” we ensure that the output of the SOAP-related loggers is sent only<\/strong> to the SOAP appender. Note that this appender is not<\/strong> listed inside the root element.<\/p>\n\n\n\nIn many situations these options provide you with sufficient ammunition to handle your problems.<\/p>\n\n\n\n
In the situation with Batch Job logging, however, this won’t work: there isn’t just a single logger category that will be used for all batch-related logging, and many loggers could be used both in the context of a batch job and outside such a context. So how to tackle this? Enter Logback Filters<\/em>.<\/p>\n\n\n\nLogback Filters<\/h2>\n\n\n\n
Another feature provided by Logback is Filters<\/a>. You can declare one or more filters inside of an appender: each filter can determine if a log message (more precisely: a log event<\/em>) should be passed on to the appender, or if it should be filtered out. Several useful implementations are provided out of the box, but it’s easy to define your own as well.<\/p>\n\n\n\nIn our situation, we want to have a filter that we can configure to do one of two things: filter out all batch-related log messages, or filter out all non<\/em>-batch-related logging. Then we can add that filter to two separate file appenders: one exclusively for all the batch logging, and one for all the other logging.<\/p>\n\n\n\nHere’s an initial implementation of our Logback Filter (imports are implied)<\/p>\n\n\n
\npublic class LogbackBatchFilter extends Filter<ILoggingEvent> {\n static final String MDC_KEY = "batch-job";\n private Mode mode = Mode.EXCLUDE_BATCH;\n public void setMode(Mode mode) {\n this.mode = mode;\n }\n @Override\n public FilterReply decide(ILoggingEvent iLoggingEvent) {\n boolean runningBatchJob = ...; \/\/ how to determine this?\n if (mode == Mode.EXCLUDE_BATCH && runningBatchJob ||\n mode == Mode.BATCH_ONLY && !runningBatchJob)\n {\n return FilterReply.DENY;\n }\n return FilterReply.NEUTRAL;\n }\n enum Mode {\n BATCH_ONLY,\n EXCLUDE_BATCH\n }\n}\n<\/pre><\/div>\n\n\nThis filter can be configured to run in two modes: by default it will filter out all batch messages, using an EXCLUDE_BATCH mode. However, when it’s running in BATCH_ONLY mode it does exactly the opposite and filters out all non-batch-related messages.
The NEUTRAL reply means we’re not filtering out the given logging event in our filter, but there might still be another filter down the filter chain that decides to filter it out anyway: ACCEPT instead of NEUTRAL would mean that we’re short-circuiting such a filter chain if there are additional filters, which is not what we’re after here.<\/p>\n\n\n\n
To use the filter, you simply add it within your appender config:<\/p>\n\n\n
\n<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">\n <filter class="nl.trifork.batch.LogbackBatchFilter"\/>\n <file>log\/server.log<\/file>\n ...\n<\/appender>\n<appender name="FILE-BATCH" class="ch.qos.logback.core.rolling.RollingFileAppender">\n <filter class="nl.trifork.batch.LogbackBatchFilter">\n <mode>BATCH_ONLY<\/mode>\n <\/filter>\n <file>log\/batch.log<\/file>\n ....\n<\/appender>\n<root level="info">\n <appender-ref ref="FILE" \/>\n <appender-ref ref="FILE-BATCH" \/>\n<\/root>\n<\/pre><\/div>\n\n\nEasy, right?
There\u2019s just one little unresolved detail: how do we determine the value of the runningBatchJob flag inside the decide method?<\/p>\n\n\n\n
Revisiting the Mapped Diagnostic Context<\/h2>\n\n\n\n
SLF4J<\/a>, the logging API implemented by Logback, defines the concept of a Mapped Diagnostic Context<\/em> (MDC) which can hold String-based key-value pairs associated with the current thread, which can be included in your logging output. I\u2019ve blogged about this before<\/a> in the context of security, to ensure that every log message contains the current user name.<\/p>\n\n\n\nYou can also access the MDC properties in a Logback Filter: they\u2019re available directly from the ILoggingEvent that’s passed in. So, if we could set an MDC key whenever we’re running a batch job, then that could tell us whether we should be excluding log messages inside the filter.
How to make this happen?<\/p>\n\n\n\n
In our application we’re using Spring Batch’s SimpleJobLauncher to start all Batch Jobs. This launcher can be configured with a TaskExecutor to run the job on a separate thread, typically obtained from some thread pool.
We want to achieve two things:<\/p>\n\n\n\n
- When the launcher’s run method is called, we want to set the name of the job that will run as an MDC entry, and clear that entry when the method is done;<\/li>
- When the job runs in a separate thread, we want have the same MDC entry set there as well.<\/li><\/ol>\n\n\n\n
These two things combined will ensure that all<\/strong> logging performed in the context of running a batch job will have the expected MDC entry.
What I ended up doing was subclassing that SimpleJobLauncher to inject some MDC-related code:<\/p>\n\n\n\n\/**\n * SimpleJobLauncher subclass which ensures that an MDC key {@code batch-job}\n * will be set with the name of the job to be run, both in the current thread\n * as well as in the thread used by a custom configured {@link TaskExecutor}.\n * This in turn enables filtering of log messages issued in the context of\n * batch jobs.\n *\/\npublic class MDCPopulatingJobLauncher extends SimpleJobLauncher {\n static final String MDC_KEY = "batch-job";\n @Override\n public JobExecution run(Job job, JobParameters jobParameters)\n throws JobExecutionAlreadyRunningException, JobRestartException,\n JobInstanceAlreadyCompleteException, JobParametersInvalidException {\n MDC.put(MDC_KEY, job.getName());\n try {\n return super.run(job, jobParameters);\n } finally {\n MDC.remove(MDC_KEY);\n }\n }\n @Override\n public void setTaskExecutor(TaskExecutor taskExecutor) {\n super.setTaskExecutor(\n new MDCPopulatingTaskExecutorDecorator(taskExecutor));\n }\n private static class MDCPopulatingTaskExecutorDecorator\n implements TaskExecutor {\n private TaskExecutor targetExecutor;\n MDCPopulatingTaskExecutorDecorator(TaskExecutor targetExecutor) {\n this.targetExecutor = targetExecutor;\n }\n @Override\n public void execute(Runnable task) {\n String mdcValue = MDC.get(MDC_KEY);\n targetExecutor.execute(() -> {\n MDC.put(MDC_KEY, mdcValue);\n try {\n task.run();\n } finally {\n MDC.remove(MDC_KEY);\n }\n });\n }\n }\n}\n<\/pre><\/div>\n\n\nSo, this gives us the missing piece of the puzzle to complete the Filter:<\/p>\n\n\n\n
boolean runningBatchJob = iLoggingEvent.getMDCPropertyMap().containsKey(MDC_KEY);<\/pre><\/pre>\n\n\n\n(This assumes that we\u2019re doing a static import of that MDC_KEY constant)<\/p>\n\n\n\n
Now you simply configure a Spring Bean of type MDCPopulatingJobLauncher instead of SimpleJobLauncher in your Batch configuration class or XML file and you’re done! As a bonus, you can include the name of the currently executing batch job in your batch logging by referencing it in your pattern through %X{batch-job}.<\/p>\n\n\n\n
![\"\"](\"https:\/\/trifork.nl\/articles\/wp-content\/uploads\/sites\/3\/2022\/02\/Blog-Banner-1-1024x256.png\")
<\/a><\/figure>\n","protected":false},"excerpt":{"rendered":"