In reviewing some provided code to a client, I observed a number of actions contray to generally accepted practices regarding logging. This is what I provided as the general programming conventions with regardings to logging.
Using Log4J (http://logging.apache.org/log4j/docs/ ), which is generally accepted as the benchmark for all Java applications. This provides the following logging levels.
- FATAL
- ERROR
- WARN
- INFO
- DEBUG
- TRACE – from 1.2.12, latest is 1.2.13
A description for what handling should occur per logging level.
FATAL. As the name suggests, all processing should stop. Should logging include a FATAL, the process is a Failure.
ERROR. An error has occured, and this requires attention, and action. Generally processing should stop, however additional post processing, or an alternative path could occur. Should logging include an ERROR, the process is a Failure.
WARN. Something that is unexpected occured, however it doesn’t affect the general processing from succeeding successfully. If a process includes WARN and not FATAL/ERROR it should be considered successful.
INFO. Information Only. On high volume systems, this level of logging may even be turned off. This generally indicates key information values or steps, and can assist when enabled in longer running processes to identify where a process is. You don’t log errors at INFO.
DEBUG. For Debugging Purposes only.
Ok, well that sounds like common sense. Here is what I observed on a client site.
- Code logs a FATAL, but continues processing
- A FATAL is logged, yet the calling process reports success
- An ERROR is logged, yet the calling process reports success.
- A lot of WARN are logged, and this is misleading, as it appears more information regarding XML elements not processed (We are talking 20+ Warnings per batch process). From what I’ve observed, these don’t require futher action, and should be changed in INFO.
- Errors are being logged as INFO. A NullPointer RunTime Exception is logged as INFO. If an error provides an Exception argument where a stack trace is printed, it ain’t an INFO message.
