log4j rootLogger seems to inherit log level of other logger. Why?

Question

I've got a log4J setup in which the root logger is supposed to log ERROR level messages and above to the console and another logger logs everything to syslog.

log4j.properties is:

# Root logger option
log4j.rootLogger=ERROR,R

log4j.appender.R=org.apache.log4j.ConsoleAppender
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%d %p %t %c - %m%n

log4j.logger.SGSearch=DEBUG,SGSearch
log4j.appender.SGSearch=org.apache.log4j.net.SyslogAppender
log4j.appender.SGSearch.SyslogHost=localhost
log4j.appender.SGSearch.Facility=LOCAL6
log4j.appender.SGSearch.layout=org.apache.log4j.PatternLayout
log4j.appender.SGSearch.layout.ConversionPattern=[%-5p] %m%n

In code I do

private static final Logger logger = Logger.getLogger("SGSearch");
.
.
.
logger.info("Commencing snapshot index [" + args[1] + " -> " + args[2] + "]");

What is happening is that I get the console logging for all logging levels. What seems to be happening is that the level for SGSearch overrides the level set for the root logger somehow. I can't figure it out.

I have confirmed that Log4J is reading the properties file I think it is, and no other (via the -Dlog4j.debug option)

Answer 1

Quick information about Levels

Log4J Levels

Loggers may be assigned levels. The set of possible levels, that is DEBUG, INFO, WARN, ERROR and FATAL are defined in the org.apache.log4j.Level class.

If a given logger is not assigned a level, then it inherits one from its closest ancestor with an assigned level.

The root logger resides at the top of the logger hierarchy. It always exists and always has an assigned level.

I've changed your sample log4j configuration to work this way:

# Root logger option
log4j.rootLogger=ALL,R

log4j.appender.R=org.apache.log4j.ConsoleAppender
log4j.appender.R.Target=System.out
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%d %p %t %c - %m%n
log4j.appender.R.Threshold=ERROR

log4j.appender.SGSearch=org.apache.log4j.net.SyslogAppender
log4j.appender.SGSearch.SyslogHost=localhost
log4j.appender.SGSearch.Facility=LOCAL6
log4j.appender.SGSearch.layout=org.apache.log4j.PatternLayout
log4j.appender.SGSearch.layout.ConversionPattern=[%-5p] %m%n
log4j.appender.SGSearch.Threshold=DEBUG

I hope this helps you.

Answer 2

The way Log4j chaining works is a bit counter intuitive (to me at least). See the log4j manual. If the request level is equal to or above the threshold of the most specific matching logger, it is accepted. Once the request is accepted, it gets handled by the complete chain of ancestors regardless of their thresholds!

To suppress the chaining behavior, add:

log4j.additivity.SGSearch=false

This will cause requests handled by logger SGSearch to no longer be passed up the chain.

One other suggestion: don't name your logger and appender the same, because at some point in the future you, or a colleague will mix them up. The logger name should indicate which type of logging is handled, the appender name should specify where the logging goes. So in this case I would think 'SGSearch' could be the logger name, and the appender should be called something like 'LocalSysLog'.

BTW: In my opinion you are doing the right thing by restricting the root logger with a high threshold, and lowering it for specific loggers. This avoids clutter from loud libraries (Apache has a few notorious ones).