Confluence Docs 3.0 : Logging Guidelines This page last changed on Dec 10, 2007 by pfragemann.
| These are guidelines related to the development of Confluence. The guidelines mainly apply to Atlassian employees, but reading them should provide insight for third-party plugin developers as well, so we decided to make them public.
### The Purpose of Logging Logging has three customers: The user (server administrator) wants to know if their server is running correctly Atlassian support wants evidence of possible problems Developers want to be able to trace code execution without attaching a debugger When you write any code in Confluence, you should ask yourself what you would want to see, from the point of view of the above three people. If you were running a server, what would you want to be notified of? If you were handling a support case regarding some problem with the system, what information would you need? If you were tracing a bug in the code, what would you want to see logged? ### Loggers
    private static final Logger log = Logger.getLogger(TheCurrentClass.class);
The current practice in Confluence is to create a `static final` logger called `log` (lower-case) in each class that needs to perform logging. This may need to be addressed in the future. You will find some old code still uses `Category.getInstance()` instead of `Logger.getLogger()`. Category is deprecated in newer versions of log4j, and should be phased out as you find it. There is a special log called `startupLog` in `ConfluenceConfigurationListener`, which defaults to logging at INFO level, and is used to print out informational messages on system startup. Use this definition for startup messages:
    private final static Logger startupLog = Logger.getLogger("com.atlassian.confluence.lifecycle");
### Log Levels DEBUG Fine-grained information about what is going on within the system. INFO Announcements about the normal operation of the system - scheduled jobs running, services starting and stopping, significant user-triggered processes WARN Any condition that, while not an error in itself, may indicate that the system is running sub-optimally ERROR A condition that indicates something has gone wrong with the system FATAL A condition that indicates something has gone wrong so badly that the system can not recover ### Default Log Level The standard Confluence log (level WARN) is a way for Confluence to communicate with the server administrator. Anything we log to this file will worry the administrator in some way. Logging at WARN level and higher should be reserved for situations that require some kind of attention from the server administrator, and for which corrective action is possible. We should assume that any time Confluence logs a WARN level message or higher, the customer will create a support case, and will expect us to provide a solution that prevents that message from happening again. ### Context You can rarely put too much context in a log message. Don't just say an operation failed. Say what operation you were attempting when it failed, what object you were trying to act on, and why. Remember to log the exception, so a stack-trace can be logged. Bad:
        log.error("Unable to save page: " + exception.getMessage());
Better:
        log.error("Unable to save " + page + ": " + exception.getMessage(), exception);
Even better (assuming this information is available and relevant in the context. I am making this one up):
        log.error("Unable to save " + page + " in updateMode=" +
                  isAutomaticSaveBoolean + " upon moving it from space " +
                  oldSpace + " to space "+newSpace+": " + exception.getMessage(), exception);
### The Mapped Diagnostic Context The log4j MDC allows you to add contextual information to a ThreadLocal, which is then included with subsequent log messages. This is a useful tool when you need to add the same contextual information to a lot of log messages. For example, we currently use the MDC in the `LoggingContextFilter` to add the request URL and current user to the logging context for every web request. Example usage:
    while (objectsToIndex.hasNext())
    {
        Searchable obj = (Searchable) objectsToIndex.next();

        try
        {
            MDC.put("Indexing", obj.toString());
            index(obj);
        }
        finally
        {
            MDC.remove("Indexing");
        }
### Logging Risks Logging has the potential to introduce Heisenbugs into your code, because the act of turning logging on to look for an error changes the code-paths around where the error is occurring. For example, logging often calls `toString()` on the objects it wants to log information about. In turn, the `toString()` method of an object may have unexpected side-effects, for example causing some lazy-loaded Hibernate property to be loaded in from the database. Also, make sure to check that an object can't be null when calling a method on it. Especially when reporting errors, do go the extra mile to query for null, e.g. like this:
    String previousPageOutdatedId="[previous page variable is null]";
    if (previousPage!=null) {
        previousPageOutdatedId=previousPage.getOutdatedId();
    }
    log.error("Unable to revert to previous page: " + previousPageOutdatedId);
instead of
        log.error("Unable to revert to previous page " + previousPage.getOutdatedId());
### Logging Performance Always wrap debug-level logging in `isDebugEnabled()` checks. Put any frequently-accessed info-level logging in an `isInfoEnabled()` check. Avoid logging inside a tight loop, and if you have to make sure it's at the debug level ### Logging progress It is absolutely vital that some kind of logging is done during a long running task. At least at the start and at the end of it. Usually, a loop will call a single operation very often. Make sure that - depending on how long a single call takes - you log each 10th, 100th, 1000th operation. If possible add the complete number of operations that will have to be performed, e.g. in the form " executing delete user (2000/5301)"

Document generated by Confluence on Nov 05, 2009 23:34