Forcing logger/appender to output line logged at lower than its current level?

Question

Consider the following scenario:

I am writing a Dispatcher Servlet that delegates processing to various handlers depending on the request URL; the handler objects having previously registered themselves for URL patterns, pretty much as Servlets register themselves in web.xml.

When a Handler registers or unregisters itself for a pattern, I want to log a line that includes the action and pattern; and also the current mappings, so that when a subsequent request processing logs a warning that a request was not processed I can go back in the logs and find out the mappings.

The question is how to ensure that lines logged by registerUrlPattern/unregisterUrlPattern actually appear in the log file:

• It seems to me that these methods should log the mapping changes at INFO level, since it is additional INFO being logged. But the logger's level is WARN so that will not work. The logger get many other messages at INFO level so it is not possible to change its level to INFO in production, except for troubleshooting.

• I could log it at WARN level, but qa/usability/customer does not like such warnings to appear.

I can think of the following alternatives:

• Change the Logger's level to INFO when logging these lines, possibly by adding a forceInfo method in my Logger (which wraps a standard log4j type logger)

• Use a different Logger for these methods and set its level to INFO

• Log at warning level but change the language to indicate that it is not something to be worried about

Answer 1

So, you need different treshold within the same class. I think you use a different logger corresponding to a specific name. You can thus set the log level to INFO for this specific Logger in DispatchServlet class.

For me, the benefits would be:

• the possibility to specificly reduce the treshold to INFO as you required (the goal).
• if one day you realize that your specific logs become too verbose and finally useless because the functionnality is 100% stable and doesn't cause any issue, you still can reduce the treshold by configuration and without impacting the rest of the logs. Logging in WARNING level or do something based on forcedLog would imply you to modify the sources for such a purpose.

The only CON I see is that it might be "surprising" but a correct documentation solves everything.

For example in your log4j.xml file, you could have:

<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
    <!-- general application log -->
    <appender name="MyLogFileAppender" class="org.apache.log4j.FileAppender">
        <param name="File" value="mylog.log" />
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d{yyyy MM dd - HH:mm:ss,SSS} %-5p %t [%-40.40c] %x - %m%n"/>
        </layout>
    </appender>
    <logger name="DispatchServletSpecific">
        <level value="INFO" />
        <appender-ref ref="MyLogFileAppender" />
    </logger>
    <root>
         <level value="WARNING" />
         <appender-ref ref="MyLogFileAppender" />
    </root>
</log4j:configuration>

And in the Java code you create a specific Logger

Logger specificLogger = Logger.getLogger("DispatchServletSpecific");

This way the log treshold should be set to INFO while the rest of your app should be log only WARNING logs. Hope it helps.

Answer 2

Change the Logger's level to INFO when logging these lines, possibly by adding a forceInfo method in my Logger (which wraps a standard log4j type logger)

At some point down the line you will probably consider the register/unregister behaviour reliable enough that you don't want to log it any more, and you only want to see 'proper' warnings. At this point you'll have no option but to go and change the code.

Use a different Logger for these methods and set its level to INFO

Yep, do this. It gives you the fine-grained control that you need in this scenario.

Log at warning level but change the language to indicate that it is not something to be worried about

Don't do this. Your users/QA don't want it, ant the event isn't a warning, so don't make it one. Also, you again have to change the code in order to disable logging these events.

Answer 3

Instead of trying to force a message containing the data you want available when another message is logged, you should use Log4J's Thread Context capability to add the data to the other message. That way, if the error message is issued, it carries along the data you want logged. So, for example, instead of:

logger.ForceInfoOutputEvenThoughBelowLoggingLevel("Hey, I'm going to be processing record " + recordNumber + ", so if an error happens, you'll know what I'm doing!");
...
logger.Error("OMG!")

which would presumably log:

INFO Hey, I'm going to be processing record 42, so if an error happens, you'll know what I'm doing!
ERROR OMG!

you'd do this instead:

ThreadContext.put("recordNumber", recordNumber);
...
logger.Error("OMG!")

which, with %x or %X in your Log4J config's layout definition, would log:

ERROR recordNumber=42 OMG!

The point is to augment the error message with useful data, rather than to force another message into the log. This has lots of benefits, including the fact that you can augment any message issued by any code, without having to modify that code, even if you don't have it's source.