AppSuite:OX Logging

OX Logging

With OX App Suite 7.4.2 the groupware server introduces LOGBack as logging implementation. Formerly log4j 1.2 or java.util.logging have been used for logging. As of now the package 'open-xchange-log4j' has become obsolete and LOGBack is entirely contained in 'open-xchange-core'. No additional packages are needed even for syslog-based logging or sophisticated logging configurations anymore. Log4j and java.util.logging have been completely replaced by LOGBack.

For Operators

Configuration

LOGBacks configuration is defined in /opt/open-xchange/etc/logback.xml. We ship the file pre-configured for new installations and set some useful defaults. Without any changes, the groupware writes log files to /var/log/open-xchange. See chapter #Backward Compatibility for detailed information on product upgrades from older versions. See LOGBack manual for details on configuring LOGBack.

Backward Compatibility

Configuration Migration

In most cases no further work should be necessary after upgrading to OX App Suite 7.4.2. Based on your existing logging configuration (/opt/open-xchange/etc/file-logging.properties or /opt/open-xchange/etc/log4j.xml) we automatically migrate custom configured logger levels.

We also configure file-based logging or syslog-based logging in accordance with the default configuration of the formerly used logging implementation. That means, you don't have to change anything if

• you use plain file logging and did not modify the 'handler'-section in file-logging.properties.
• you use syslog-based logging via log4j and did not change the configured 'SERVER_LOG' appender.

Please note: If you customized handlers or appenders you have to port your changes manually to /opt/open-xchange/etc/logback.xml. See LOGBack manual for details.

Log File Format

We keep the former default layout for log events on product upgrades. So nothing should break if you wrote your own log file parser.

Please note: We also ship a pre-configured new log file format. You are encouraged to use this one for file-based logging, as it provides more information and is better structured than the old one.

New Features

Config-based Asynchronous Logging

Publishing log events to files, syslogd or the like is performed asynchronously. Therefore the root loggers appender is set to 'ASYNC', which is configured as follows:

<configuration>
...
  <appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <queueSize>2048</queueSize>
    <discardingThreshold>0</discardingThreshold>
    <includeCallerData>true</includeCallerData>
    <appender-ref ref="FILE" />
  </appender>
...
</configuration>

The most important property is "appender-ref". It denotes the name of the appender, that finally writes log events out in some way. A detailed description of the other parameters can be found here: [1].

If you introduce your own log appender, only change the above mentioned 'appender-ref' property. Don't remove or deactivate the configuration for asynchronous logging! It might decrease the applications performance significantly.

Suppression Of Stacktraces

It is possible to suppress Java stacktraces in log messages for configured categories. Those categories are part of OX App Suites internal error and exception handling. Suppression can be configured in server.properties by adjusting the value for 'com.openexchange.log.suppressedCategories'. See below excerpt of /opt/open-xchange/etc/server.properties:

...
# Specify the OXException categories (comma separated) to be suppressed when logging.
# The Exception itself will still be logged as configured, but the StackTraces are omitted.
# Valid categories are ERROR, TRY_AGAIN, USER_INPUT, PERMISSION_DENIED, CONFIGURATION, CONNECTIVITY, SERVICE_DOWN, TRUNCATED, CONFLICT, CAPACITY, WARNING
# Default is USER_INPUT.
com.openexchange.log.suppressedCategories=USER_INPUT
...

Tracing Of Sessions, Users and Contexts

It is possible to enable extended logging for defined scopes like sessions, users or contexts at a whole. This means that every log event which belongs to a configured scope will be logged despite of it's level.

Example: Imagine logback is configured to log on level 'INFO' and additionally the logger 'com.openexchange.example.SomeLogger' is only allowed to log warnings and errors.

<configuration>
...
  <root level="INFO">
    <appender-ref ref="ASYNC" />
  </root>
  <logger name="com.openexchange.example.SomeLogger" level="WARN"/>
...
</configuration>

If tracing is activated for user '5' in context '1', events belonging to this user are written out, even if they deceed the configured thresholds. I.e. you can find log entries with level 'DEBUG' from logger 'com.openexchange.example.SomeLogger' that belong to the traced user.

2013-12-09 15:29:31,641 DEBUG [OXWorker-0000001] com.openexchange.example.SomeLogger
Some very useful debug message.
 com.openexchange.session.sessionId=711c651fa4c94dc0894c733c92bc77d4
 com.openexchange.session.contextId=1
 com.openexchange.session.userId=5
 com.openexchange.session.userName=oxuser
 ...

The decision whether to log such an event is based on the context information that every log event carries along. These information is structured as key-value-pairs and always printed below the log events message. Afterwards it's easy to find the tracing events in the log file. You just have to search for 'com.openexchange.session.contextId=1' and 'com.openexchange.session.userId=5'. If you trace a specific session, according events can be found with looking for 'com.openexchange.session.sessionId=session_id_to_trace'.

New Log Event Layout

We ship a new default layout for log events that

• contains a more precise timestamp
• carries the name of the current thread
• is easier to parse

Please note: The new layout applys only for fresh installations. On upgrades you have to enable it manually. See #Log File Format for details.

For Developers

Instantiate Loggers

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Clazz {

    private static final Logger LOG = LoggerFactory.getLogger(Clazz.class);

    ...

}

Using Apache Commons Logging as logging facade is depracted as of OX App Suite 7.4.2. Formerly we used own wrapper classes to enable extended logging features. With the current logging implementation this is not necessary anymore. Obtaining loggers via

com.openexchange.log.Log.loggerFor(Clazz.class); or
com.openexchange.log.LogFactory.getLog(Clazz.class); or
com.openexchange.log.Log.valueOf(LogFactory.getLog(Clazz.class));

still works for backward compatibility, but should not be used for new classes. Existing classes should be ported to SLF4J, when touched during refactorings, bugfixes etc.

Logging Statements

With SLF4J you should avoid code like this:

if (LOG.isDebugEnabled()) {
    LOG.debug("Some debug message for user " + userId + " in context " + contextId + ".");
}

Instead relinquish the if-statement completely and make use of SLF4Js printf()-like syntax for log statements:

LOG.debug("Some debug message for user {} in context {}.", userId, contextId);

Please read What is the fastest way of (not) logging? for details.