Log4J Lesson Learned
Posted on October 30, 2004 by Scott Leberknight
I learned the other day not to inherit a "log" variable from a superclass, or else it really messes up your ability to adjust logging levels in Log4J. Normally I don't do this but the base class was a utility class in my "test" tree and would not actually be deployed to production, so I was being lazy. Without thinking too hard about it, I created a protected log variable in a base JUnit test class so other tests could use it if they needed to perform some logging:
protected final Log log = LogFactory.getLog(getClass()); // don't do this!
So in one test case derived from this base class, I used this log to do some debugging. Later I was messing around with logging levels in the Log4J configuration and I quickly found out that changing logging levels for various packages wasn't working as I expected. Now, I expected this to work fine since the call to getClass()
will polymorphically return the actual type instantiated at runtime. But for whatever reason changing the logging levels wasn't working. The base test class resides in a different package than the derived test class. I didn't want any logging messages from the base test case but did want to see the log messages from the derived test. However, log messages displayed from both the base and derived class. The reason is simply because the runtime type does in fact return the type instantiated at runtime! The culprit is that the derived class is in a different package than the base class, and therefore changing the log level for the package the base class resides in has no effect.
I changed the code so that the base and derived test class each has their own private static final
log variable, which is what I normally do in my classes. So the code looks like:
private static final Log log = LogFactory.getLog(MyClass.class)); // This works great!
Now the package of the logger can match those defined in the Log4J configuration, and we only have one log per class rather than one per instance of a class. This fixed everything and now I can selectively turn logging on and off for the various packages the way I would expect. Thinking back this all makes perfect sense and it was not a good idea to create that protected log which could be used by derived classes. A log should be a private component of a class anyway. The only thing I don't so much like is having to use MyClass.class
in the log variable declaration, since getClass()
is not static and cannot be referenced from a static context. But this isn't that big a deal since most IDEs will fix this reference if you rename refactor the class.