Declaring a Logger
For consistency, declare your logger as the first field (top of code) in your class and declare it as follows:
Notice that we have used the instance variable named "log" and not "logger". The term "log" (in lieu of "logger") is more efficient to type and makes for cleaner code while not reducing any developer's ability to understand the code. Follow this convention for both efficiency and consistency.
If you are declaring you logger to pipe through Apache Commons Logging, the declaration will be a little bit different:
Use TRACE only for tracing execution flow
In general, trace-level logging should be used only for tracing the flow of execution through a program and for flagging particular positions in a program (i.e. to ensure they have been reached). While you may want to trace every method of a class in early stages of development, you should ensure that you are only tracing key aspects of the flow when it is time to pass the code onto other developers. An overabundance of TRACE statements (especially in simple getter and setter methods) can hinder others rather than help them.
Entering a Method
- Logging the entrance to a method should always be done with the level: TRACE
- Use the abbreviated symbol for 'entering' which is '>>' followed by the method name. Use a parenthesis to help clarify that the item is a method. Example:
Exiting a Method
- Logging the exit from a method should always be done with the level: TRACE
- Use the abbreviated symbol for 'exiting' which is '<<' followed by the method name. Use a parenthesis to help clarify that the item is a method. Example:
- Logging the instantiation of an object (in the class constructor method) should always be done with the level: TRACE
- Use the abbreviated symbol for 'instantiation' which is '**' followed by the constructor name. Use a parenthesis.
Prefix all logging statements with a method name
Assuming that you will set your logging configuration to print class names, it is then helpful to prefix the statements with the name of the method from which the statement is being executed.
Notice also that two hyphens are used before the method name. This helps to improve legibility in log files where trace may be also used with '>>' specifying the entry of a method and '<<' specifying exit. Adding '--' in the middle of methods provides a visual indication that the statement is executed somewhere in the middle after entry and before exit. So you get a clean visual pattern like this:
Use DEBUG to report results to yourself and other developers
Use INFO to report results to Administrators and Users
Use Guarded Logging
"Guarded logging" is a pattern that checks to see if a log statement will result in output before it is executed. Since the logger itself makes this check, it may seem redundant to do this for every call. However, as almost every logging call creates String objects, it is critical. The accumulation of these Strings causes memory fragmentation and unnecessary garbage collection. Garbage collection, while beneficial, also produces significant performance loss. To reduce this as much as possible, always guard logging statements with a severity less than SEVERE. Since SEVERE is always expressed by the logger, these do not need a guard. Here is an example:
Note that if you use SLF4J for logging, the necessity for guarded logging is reduced or eliminated as SLF4J has a nice pattern substitution mechanism that avoids the need for string concatenation and unnecessary evaluations and object instantiations.
Use StringBuffers and toString() or toPrint() to ease and improve logging
Sometimes, when you want to print all the values of an object, it is helpful to use a StringBuffer or StringBuilder. In this way, you can assemble all of the data into one clean output statement and avoid cluttering up your log file with redundant data (i.e. multiple lines with several time and level stamps for just one object). The snippet below shows an example of how to do this, but it is still not the best approach.
While the code above creates a clean logging statement without multiple lines containing redundant data, there is still a problem. Notice that we are printing the values of the object "cat" (of the class Category). What would be better is to move most of this code into a toString() method on the Category class itself. In this way, all developers can simply call the toString() method to get a print of all the object's current data. Sometimes, however, you might find that you'd rather use a toString() method for application functionality instead of for logging or because the toString() method is already being used in another way. In this case, you could create a method called toPrint() instead. Following is an example:
Notice also in the code snippet above that we have taken care to align all of the colons separating the key from value. This makes the toPrint() method's output much easier to read. Also notice that we've added a newline character to the beginning of each property statement that appends to the StringBuffer. If you get in the habit of adding a newline character to the end of the line, you might end up with something like this:
In the example above, since the newline must be merged into the String at runtime, your asking the JVM to do unnecessary work. By putting the newline in the beginning of the String instead, you'll need no addition operator and thus, your saving the JVM from having to do that operation. It all adds up!
Now, in any point of the code's execution, it is easy for a developer to inspect the object using just a few statements like this:
Use Delegates, Managers, or Service classes as a logging juncture
Typically Delegate or Manager classes act as junction or integration points. And the delegates often have very simple methods that act as proxies to actual implementations in other classes. You can take advantage of this delegate or manager class to act as a place to log the entry and exit of methods at the integration point including the data being passed in and the data returned. Here is an example of a simple method in a delegate class that logs entry, exit, and the data going in, and the data coming out:
The key here is that we have standardized on WHERE to do the primary logging so it is consistent. In this way, we don't have a random mix of primary logging code in the delegate and in the implementation classes.