How to set up the spring boot logger to scheduled tasks only?

Viewed 2502

I have a spring boot project, so I set up the hibernate logger to log all queries in a request like this:

In my application.properties file

logging.level.org.hibernate.type=trace
logging.level.org.hibernate.SQL=debug
logging.level.org.hibernate.type.descriptor.sql.BasicBinder=trace

This works fine, All my requests show the log for the hibernate queries.

But I also have a scheduled task to run every one second like this:

@Scheduled(cron = "${* * * * * *}")
public void task() {
  ...
}

So, I want to turn off the hibernate queries log only for this task execution to avoid mess up my requests output log.

How can I set up the logger to do this?! Thanks.

4 Answers

If you're using Slf4j and logback, you can filter based on the Mapped Diagnostic Context (http://logback.qos.ch/manual/mdc.html).

The MDC is thread-local, and you can put any key-value pairs in it that you want to use in the logger. E.g:

@Scheduled(cron = "${* * * * * *}")
public void task() {
  MDC.put("DONOTLOG", "true")
  try {
    ....
  } finally {
    MDC.remove("DONOTLOG");
  }
}

You can use this in a custom logback filter (http://logback.qos.ch/manual/filters.html), by putting this in your logback.xml:

<configuration>
  <appender name="...">

    <filter class="...SampleFilter" />

  </appender>

SampleFilter:

public class SampleFilter extends Filter<ILoggingEvent> {

  @Override
  public FilterReply decide(ILoggingEvent event) {    
    if (event.getMDCPropertyMap().containsKey("DONOTLOG")) {
      return FilterReply.DENY;
    } else {
      return FilterReply.NEUTRAL;
    }
  }
}

I assume you are using Slf4j.

This library does not support that functionally out of the box.

The capacity of changing the logger level at runtime largely depends on the underlying logging libraries (Logback, Log4J2, etcetera) configured.

But Spring Boot provides an underlying logging system that handles all this stuff for us. We can use that underlying logging system to achieve the functionally that you need.

You can do something like the following example:

@Scheduled(cron = "${* * * * * *}")
public void task() {
  // At the beginning of the method, disable logging levels
  final List<String> loggerNames = Arrays.asList("org.hibernate.SQL", "org.hibernate.type", "org.hibernate.type.descriptor.sql.BasicBinder");
Map<String, LogLevel> previousLogLevels = new HashMap();
loggerNames.forEach(loggerName -> {
  final LoggerConfiguration loggerConfiguration = loggingSystem.getLoggerConfiguration(loggerName);
  final LogLevel logLevel = loggerConfiguration.getEffectiveLevel();
  previousLogLevels.put(loggerName, logLevel);
  loggingSystem.setLogLevel(loggerName, LogLevel.OFF);
});
  
  try {
    // Do your stuff
    ...
  } finally {
    // Restore the logging levels to the original ones
    previousLogLevels.forEach((loggerName, logLevel) -> loggingSystem.setLogLevel(loggerName, logLevel));
  }
}

You must inject a bean of type LoggingSystem in your scheduled task bean so you can reference it in the code.

This functionally can be easily reused in different contexts: if you need to, you can create an aspect for that, for instance, freeing the business logic from this need.

Edit

After read the @KavithakaranKanapathippillai answer, and read again, carefully, your question, I fully understand your need.

He is right: please, be aware that with this setup you will modify the logging level of the affected logs globally, not only for the async task, and the rest of the code will be also affected for the change, so it will be always a chance for lost some "normal" application code log traces if that "normal" code uses Hibernate and is executed while the async task is running.

If this is important or not will largely depend on how much the async task is running - I suppose it runs very fast if it is executed every second but, on the other hand, it runs a lot times - and how many transactions your application receives.

I don't think you will be able to achieve your result.

Even if you manage to switch off the logging levels for hibernate at runtime, it will switch off the log level globally in the application for hibernate because it is tied to the caller class loader

It means if there concurrent executions of hibernate calls where you want to log in the first synchronous execution and you don't want in the second concurrent asynchronous execution, they are going to interfere with each other and you will get non deterministic results

My answer is inspired by GreyFairer's.

Actually StringBoot by default uses logback so if havent overriden with log4j then you just need to create

logback-spring.xml

and put in classpath (WEB-INF/classes) Example taken from http://logback.qos.ch/manual/filters.html

logback-spring.xml

    <?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/base.xml"/>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.core.filter.EvaluatorFilter">      
      <evaluator class="ch.qos.logback.classic.boolex.GEventEvaluator"> 
        <expression>
           (e.mdc?.get("DONOTLOG") =~ /true/ )
        </expression>
      </evaluator>
      <OnMismatch>NEUTRAL</OnMismatch>
      <OnMatch>DENY</OnMatch>
    </filter>
    <encoder>
      <pattern>
        %-4relative [%thread] %-5level %logger - %msg%n
      </pattern>
    </encoder>
  </appender>

  <logger name="org.hibernate.sql" level="DEBUG" additivity="false">
        <appender-ref ref="STDOUT"/>
    </logger>
 </configuration>

and then

@Scheduled(cron = "${* * * * * *}")
public void task() {
  MDC.put("DONOTLOG", "true")
  try {
    ....
  } finally {
    MDC.remove("DONOTLOG");
  }
}

should solve the purpose.

Related