Temporarily increase log4j2 logger level in multi-threaded service

Question

Here is a long question for you Log4j2 gurus.

I have a service that:

has very strict performance requirements
is instrumented with a lot of logging calls using log4j2.

A typical call is gated, like:

if ( LOG.isInfoEnabled() ) {
  LOG.info("everything's fine"); 
}

Because of the number of log messages and the performance needs, the service will generally run with logging set to WARN (i.e., not many messages).

However, I have been asked to build in a parameter to the service call that, if given, will cause it to:

Temporarily increase the logging level to whatever was requested in the parameter (e.g., INFO or TRACE)
Add a WriterAppender to capture the logging in a PrintWriter.
Append the PrintWriter log data to the request response.

It seems clear, due to the gating I put around each logging call, that I need to actually increase the logging level temporarily, like this:

LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
Configuration cfg = ctx.getConfiguration();
LoggerConfig loggerCfg = cfg.getLoggerConfig("com.mycompany.scm");
loggerCfg.setLevel(logLevel);
.. other code to add `WriterAppender` ...
ctx.updateLoggers();

But I have an immediate problem with that, in that it causes the logging to ALSO go the log file of the service. That might not be the end of the world, but I'd like to avoid that, if possible.

I did that by having the default logging go through appenders that filter by level, so that even if logging is turned on, it won't write any messages more detailed than are wanted in the default log file. (Like this, from my .properties file):

appenders=scm_warn, scm_info 

appender.scm_warn.type = Console
appender.scm_warn.name = SCM_WARN
appender.scm_warn.layout.type = PatternLayout
appender.scm_warn.layout.pattern = %d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n
appender.scm_warn.filter.threshold.type = ThresholdFilter
appender.scm_warn.filter.threshold.level = warn

appender.scm_info.type = Console
appender.scm_info.name = SCM_INFO
appender.scm_info.layout.type = PatternLayout
appender.scm_info.layout.pattern = %d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n
appender.scm_info.filter.threshold.type = ThresholdFilter
appender.scm_info.filter.threshold.level = info

loggers = coreConfigurator

logger.coreConfigurator.name = com.mycompany.scm
logger.coreConfigurator.level = warn
logger.coreConfigurator.additivity = false   # do not let configurator log messages get processed by client application's parent or root logger.
logger.coreConfigurator.appenderRefs = core
logger.coreConfigurator.appenderRef.core.ref = SCM_WARN

... that way, even if the logging level gets increased, the extra messages will not go to the main log file (I only want them to go to my PrintWriter).

And now, the question!

How can I temporarily increase the log level (like I try to do in the code above) for the current thread only?

If there are three (3) simultaneous calls to the service, I...

... want each added Appender to only write log messages generated by the thread that created the Appender.
... want each added Appender to be removed after the request that added it finishes.
... want the logging level to get reset back to what it was, as long as there are no other requests with this logging parameter turned on still in process.

Ideally, I think it sounds like I want each thread to have a completely separate logging context. Is that possible? Any thoughts on how to do all this?

Andreas Andreas · Accepted Answer · 2019-08-28T15:45:28

You could potentially use a custom Context Selector to have a different context per thread, but that's probably cause issues when multiple threads want to write to the same log file, so likely not a viable option.

The alternative is to write a custom Appender, that uses a ThreadLocal to store the StringWriter. If a StringWriter has not been established for the thread, the appended will skip logging. This custom Appender should be added in the Log4J config file, so it's always there and receiving log entries.

That way you enable logging for a particular thread by creating and assigning a StringWriter to the ThreadLocal, run the code, then clear the ThreadLocal and get the logged information from the StringWriter. Since there initially is no StringWriter for any thread, the appender will do nothing, so shouldn't affect performance in any noticeable way.

You'd still have to do the level-escalation you're already doing, with filters on the other appenders.

Temporarily increase log4j2 logger level in multi-threaded service

2 Answers