I see a lot of developers at my organization who are using Log4J incorrectly when it comes to logging exceptions.
Invariably, the desire is to log the error and get a meaningful message from the exception that is thrown.
Consider the following code:
Logger log = Logger.getLogger(ClassName.class);
//Some code here...
log.error("Some error has occurred");
This block of code sets up the context for our example.¬† We’ll just worry about the log.error statement from here on.
The most common errors I see in logging exceptions are:
log.error("An error has occurred: " + e.getMessage());
Unfortunately, neither of these calls will generate the output that the developer wants.
Ultimately, the developer wants to get a meaningful message that will help them identify and debug the problem.
Log4J does provide a simple way to generate a full stack trace for an exception in your logs:
log.error(String msg, Throwable e)
So you could modify the incorrect examples I listed above to do what you really want:
log.error("Some Error Message", e);
This code will generate an entry in the log that contains your error message AND a full stack trace for the exception that was caught.
I found a simple way to enable Remote Debugging in OC4J stand-alone version 10.1.3. I assume it will work on other versions.
I was looking at the startup script (oc4j.cmd on Windows) that is found in the bin directory of your OC4J install. I was looking for where exactly to add the necessary startup options in the script to enable remote debugging.
I found that the script reads from an environment variable OC4J_JVM_ARGS to look for additional startup parameters.
Rather than muck about with the canned startup script, I simply created an environment variable OC4J_JVM_ARGS which contains the following value:
This was picked up by OC4J and the container launched with remote debugging enabled on port 4000.
Now, I want to be able to easily turn remote debugging on and off, but I don’t want to have to remember the pesky parameters every time, so I took another step.
I created a second Environment Variable OC4J_DEBUG with the value set to
I then changed the OC4J_JVM_ARGS parameter to contain a value of %OC4J_DEBUG%
Now to turn debugging on and off, I simply modify the value of OC4J_JVM_ARGS and add or remove my %OC4J_DEBUG% variable. It’s less typing and easier to remember.
We had a thread leak on our production servers recently that caused downtime on multiple applications.¬† The culprit turned out to be an application that configured Log4J incorrectly.
How can Log4J bring down an application server?¬† I don’t think this one was Log4J’s fault so much as a developer who initialized it incorrectly.
As you may know, Log4J has a nice feature called ConfigureAndWatch which allows you to specify a configuration file and an interval.¬† Log4J will check the configuration file for updates on the specified interval and will update the configuration as needed. ¬† This is a very useful feature as it allows us to configure logging on the fly on our production servers.¬† Thus, when an app begins to misbehave, we can enable more detailed logging without having to restart the application (which would reset the app and potentially make the error disappear for awhile).
The danger with ConfigureAndWatch is that by its very nature, it must spawn a new thread when it is called.¬† This thread sleeps for a period of time, then wakes up to check the config file.¬† This works well if you initialize Log4J properly as it is only called once when the application starts up.¬† Unfortunately, a developer will occasionally embed a call to ConfigureAndWatch in the main execution path of the application.¬† In the case of a web application, this results in a new thread being spawned each time the application gets a hit.¬† The threads never die, they just keep going.¬† Because they sleep most of the time, they don’t show up on system load reports and such until the system eventually cannot allocate any more threads.
On our LINUX systems, java threads count as OS processes.¬† As the OS reached its process limit, the application crashed as did the container, and everything else that was owned by the same user.
I caught wind of the thread leak and someone involved mentioned that all the threads were running the FileWatchDog class which is the class used by Log4J to monitor files.¬† We were able to identify the offending app and issue a fix, but this should have never happened.
In general, developers should follow the following rules when developing application code:
- Shared libraries should not run any kind of Log4J initialization code.¬† This should be left to the applications that will use the library.
- If you don’t need the ability to change your logging configuration at run-time, you should allow Log4J to configure itself by simply including a log4j.properties or log4j.xml file in the application classpath.
- Never call ConfigureAndWatch in a way where it can be executed more than once during an application’s life.
One of my teammates ran head on into some dependency conflicts recently.¬† The application in question must use 2 sets of APIs from 2 vendors.¬† One for our content management system provider and the other from our search platform provider.
Unfortunately, the 2 APIs have conflicting dependencies and to make matters worse, the Content Management vendor hides these dependencies by wrapping all of their dependencies into a single jar file. (thirdparty-combined.jar)¬†¬† Having all the dependencies wrapped inside a single jar prevents me from being able to simply swap out the conflicting version.
The problem comes up when we put both commons-httpclient-3.0.jar and this thirdparty-combined.jar (which contains commons-httpclient-2.0) into the WEB-INF/lib directory of our application.¬† Java does not give us a method for controlling the priority of jars in WEB-INF/lib, so we are at the mercy of the app server which for some reason behaves differently on our local desktop, dev, and test tiers.
The simple solution would be to resolve the dependency by including only commons-httpclient-3.0.jar.¬† Unfortunately, thanks to the vendor’s decision to jam all of their dependencies into a single jar, we don’t have the option of removing the conflicting version.
To work around the problem, we had to ensure that commons-httpclient-3.0.jar would be loaded by a higher-level classloader (or parent classloader) to the web app’s classloader.¬† We accomplished this by packaging the app as an EAR file and adding commons-httpclient-3.0.jar to the ear file.¬† We then added a reference to the ear file’s copy of commons-httpclient-3.0.jar to the webapp’s manifest classpath in the war files MANIFEST.MF file.
On our app servers, the war manifest classpath is accessed by the classloader that is parent to the loader for WEB-INF/lib.¬† This ensures that the desired version of the library is loaded first.
I still need to do some research to see if I can find a cleaner solution, but this will allow us to meet our release deadline.
Things I don’t like about the way we resolved this include:
- Having to muck with the Manifest Classpath for the webapp
- Different app servers behave differently, so this may not work on another app server, or even on the next version of the app server
Ideally, I would like to find a way to have this loaded by the ear file’s classloader which can generally be expected to be the parent classloader for the included war files.¬† I just haven’t had time to mess about with it further.
This one’s pretty simple, but I find that it comes up in most code reviews that I perform. Developers commonly need to populate a String object, then check to see if the String contains a certain value;
s = someMethod();
Unfortunately, if someMethod() returns null for any reason, you end up getting a NullPointerException when you call s.equals() . Continue reading Comparing String objects with literals