Making a long story short, while trying to debug an an issue in one of my applications, I noticed my debug statements were not writing to my logfile. In addition, the logfile would only be updated after I had just restarted my development server (WAS).
No errors were showing up anywhere, so I wrote a little wrapper around my method that wrote logger info to the console. That was when I noticed the configuration values at the end of the method had been replaced. Ultimately I was able to narrow the before and after until I had shown that a call out to class in a helper application (on the same server) had overwritten the previous values, including the output file. Sure enough, I went to that other file and there was the rest of the logger debug info from my application, as well as the mysterious "subsequent run" logs.
I have since found this condition in at least one other application using a different helper app. Since I am but one of about a dozen programmers, I assume there may be more.
Each application has its own log4j configuration and log file, including most of the helper apps. Most of those have a rootLogger setting. Nearly all are running inside the same JVM.
Googling didn't really help (at least the way I'd formed the query), so I'm looking for either things to try or places to look.
We learn more from our mistakes than our successes.
Yeah, that's why log4j has always frustrated me, and I try to stay away from log4j. Maybe I don't know the right way of doing it, but it seems like log4j is built with an assumption that there will be only logf4j configuration in the classpath. However, the way people use it is that they bundle log4j inside their jar, and someone else log4j configuration can mess up yours.
That's true, log4j is built with the assumption that there's going to be only one source of loggers within a classloader (which in Websphere usually translates into a web application).
But as far as I know that's true of all logging frameworks, so pointing the finger at log4j isn't quite correct.
Which means, I don't think your problem is going to be solved by switching to another logging framework, unless you can find one which allows for multiple configurations within a single classloader. And even if you did find such a thing, you would still have to trawl through all of that code and modify it to use this new framework. That sounds like it could be a bigger project than you'd like.
What I would do in this case is to go through the helper jars and modify them so that they don't include their own log4j configuration file. Let them continue doing the logging they are doing now, but limit the configuration to a single config file which belongs to the web application. This config file might have to be modified to support logging from the helper jars, and maybe those jars would have to start documenting their logging requirements.
For example I used Hibernate in my web app, and it does logging. I noticed output in the logs saying that log4j didn't know what to do with the Hibernate logging (it told me the name of the logger and so on) so I modified my log4j configuration to handle that. You've probably seen output like that as well.
Last Imelda I faced a problem with log4j was because a 3rd party library we used *coughalfrescocough* had log4j that turned debug logging on. Hibernate logs every property of every entity it persists at debug level. One of our entities has a byte array... A very large byte array.
End result: log4j coverts the byte array into a base64 encoded string. App OOM. heap dump showed log4j. WTF
Thanks, Paul. I tried just commenting out the log4j config lines in our properties db and the primary apps retained control over the logger. The possible downside is that it didn't appear the help apps were logging anything into the primary logger stream, but I'm not sure that there were any messages to log. I'll run an experiment case in a couple of days to clean up any loose ends.
subject: Log4j: loggers in multiapp environment "hijacking" configs