Saturday, October 22, 2005

Crystal ate my log4j!

When solving a problem on a live site, logs are indespesnable. So imagine my frustration last spring when I went to solve a problem, and no logs were there. None. Everything had just stopped logging. Solving a problem with access logs alone is not an enviable task. I searched around a bit, and found this

I was indeed using the log4j WatchDog to periodically watch log4j.xml for changes. And we do hot restarts of the context from time to time. I wasn't convinced this was the problem, as I could not reproduce the problem no matter what I did with the WatchDog and hot restarts. So I set the system property "log4j.debug" to "true", in the hopes that next time it happened, I'd get some kind of info. I also wrote code that ensured any time a Logger object is acquired, a System.out Console appender was attached to it, at the very least.

The logs continued to disappear, but thankfully output went to stdout, and was captured. Then, log4j.debug paid off. In the middle of a log, I saw this:
log4j: Reading configuration from URL jar:file:/E:/webapps/app/WEB-INF/lib/celib.jar!/META-INF/CrystalEnterprise.Trace/
log4j: Parsing for [root] with value=[ERROR, A1].
log4j: Level token is [ERROR].
log4j: Category root set to ERROR
Whoah! Sure enough, all of my categories and appenders were blown away at this point. It didn't happen at startup, but whenever the first Crystal report was launched. After much consternation and trying to decipher the log4j comment in the release notes, my coworker came up with setting the system property "crystal.enterprise.trace" (yes, not even mentioned in the release notes) to "false". Now we can launch Crystal reports AND use log4j - oh, the decadence!

I'm no log4j expert, so I wonder how Crystal should have played more nicely here. Surely, there's a away to use PropertyConfigurator to amend logging configuration, rather then obliterate it.

Lessons learned:
1. Abstract your code such that you can intercept acquisition of Logger objects. Use this code to ensure that a Logger is at least guaranteed to have a Console appender, and escalate the problem if it indeed has zero appenders.
2. Set log4j.debug to true at all times
3. When using crystal, be sure to set crystal.enterprise.trace to true (unless, of course, you care about their logs more than your own).


Richard said...

thank you, thank you, thank you
I have a crystal function (IReportAppFactory.openDocument) that works on Tomcat under Windows but fails silently when Tomcat is running on Linux.
Hopefully now I can start debugging it.

HGC Team said...

Thank you! This was very useful to solve our problem.