Logging

Introduction

Logging in Sling is supported by three bundles:

• org.apache.felix.log : This is an implementation of the OSGi Log Service specification and providers OSGi services like the LogService and LogReader services
• org.apache.sling.commons.log : This bundle contains logback and allows to configure logback logging based on OSGi configurations or logback XML. It also supports registering of some logback services via the OSGi service registry.
• org.apache.sling.commons.logservice : This bundle binds (SLF4J)](http://www.slf4j.org) to the OSGi log service. and started by the Sling Launcher. This bundle along with other bundles manages the Sling Logging and provides the following features:

Additionally, the latest version of (SLF4J)](http://www.slf4j.org) should be installed as bundles as well as any bridge for other logging frameworks.

Important Changes

This document describes the latest version. For older releases have a look at Logging 3.x.

The latest release of commons log includes the latest version of logback.

v5.0.0 release

With Sling Commons Log 5.0.0. release the webconsole support has been moved to a different bundle named Sling Commons Log WebConsole (org.apache.sling.commons.log.webconsole)

Also with this release Logback 1.1.7 version is embedded and thus it requires at least slf4j-api:1.7.15. See SLING-6144 for details

Initial Configuration

The org.apache.sling.commons.log bundle gets its initial configuration from the following BundleContext properties:

User Configuration - OSGi Based

User Configuration after initial configuration is provided by the Configuration Admin Service. To this avail two org.osgi.services.cm.ManagedServiceFactory services are registered under the PIDs org.apache.sling.commons.log.LogManager.factory.writer and org.apache.sling.commons.log.LogManager.factory.config to receive configurations.

Logger Configuration

Loggers (or Categories) can be configured to log to specific files at specific levels using configurable patterns. To this avail factory configuration instances with factory PID org.apache.sling.commons.log.LogManager.factory.config may be created and configured with the Configuration Admin Service.

The following properties may be set:

Note that multiple Logger Configurations may refer to the same Log Writer Configuration. If no Log Writer Configuration exists whose file name matches the file name set on the Logger Configuration an implicit Log Writer Configuration with default setup (daily log rotation) is internally created. While the log level configuration is case insensitive, it is suggested to always use upper case letters.

Log Writer Configuration

Log Writer Configuration is used to setup file output and log file rotation characteristics for log writers used by the Loggers.

The following properties may be set:

Note that any log writer config should not refer to same log file which is referred in global config i.e. OSGi config pid for org.apache.sling.commons.log.LogManager

See the section Log File Rotation below for full details on the org.apache.sling.commons.log.file.size and org.apache.sling.commons.log.file.number properties.

Log File Rotation

Log files can grow rather quickly and fill up available disk space. To cope with this growth log files may be rotated in two ways: At specific times or when the log file reaches a configurable size. The first method is called Scheduled Rotation and is used by specifying a SimpleDateFormat pattern as the log file "size". The second method is called Size Rotation and is used by setting a maximum file size as the log file size.

As of version 2.0.6 of the Sling Commons Log bundle, the default value for log file scheduling is '.'yyyy-MM-dd causing daily log rotation. In previous version, log rotation defaults to a 10MB file size limit.

Scheduled Rotation

The rolling schedule is specified by setting the org.apache.sling.commons.log.file.size property to a java.text.SimpleDateFormat pattern. Literal text (such as a leading dot) to be included must be enclosed within a pair of single quotes. A formatted version of the date pattern is used as the suffix for the rolled file name. Internally the Log bundle configures a TimeBasedRollingPolicy for the appender. Refer to TimeBasedRollingPolicy for more details around the pattern format

For example, if the log file is configured as /foo/bar.log and the pattern set to '.'yyyy-MM-dd, on 2001-02-16 at midnight, the logging file /foo/bar.log will be renamed to /foo/bar.log.2001-02-16 and logging for 2001-02-17 will continue in a new /foo/bar.log file until it rolls over the next day.

It is possible to specify monthly, weekly, half-daily, daily, hourly, or minutely rollover schedules.

Do not use the colon ":" character in anywhere in the pattern option. The text before the colon is interpreted as the protocol specification of a URL which is probably not what you want.

Note that when using Scheduled Rotation purging of old log files can be disabled by setting the property org.apache.sling.commons.log.file.number to '0'.

Size Rotation

Log file rotation by size is specified by setting the org.apache.sling.commons.log.file.size property to a plain number or a number plus a size multiplier. The size multiplier may be any of K, KB, M, MB, G, or GB where the case is ignored and the meaning is probably obvious.

When using Size Rotation, the org.apache.sling.commons.log.file.number defines the number of old log file generations to keep. For example to keep 5 old log files indexed by 0 through 4, set the org.apache.sling.commons.log.file.number to 5 (which happens to be the default).

WebConsole Plugin

The Web Console Plugin supports the following features:

• Display the list of loggers which have levels or appenders configured.
• List the file appenders with the location of current active log files.
• Show the contents of LogBack config files.
• Show the contents of various Logback config fragments.
• Show Logback Status logs.
• Inline edit the Logger setting
• Configure Logger with content assist for logger names
• Provides links to log file content allows log file content to be viewed from Web UI

WebTail

The Web Console Plugin also supports tailing of the current active log files. It generates link to all active log files which can be used to see there content from within the browser. The url used is like

http://localhost:8080/system/console/slinglog/tailer.txt?tail=1000&grep=lucene&name=%2Flogs%2Ferror.log

It supports following parameters

• name - Appender name like /logs/error.log
• tail - Number of lines to include in dump. -1 to include whole file
• grep - Filter the log lines based on grep value which can be
  • Simple string phrase - In this case search is done in case insensitive way via String.contains
  • regex - In this case the search would be done via regex pattern matching

Logback Integration

Logback integration provides following features

• LogBack configuration can be provided via Logback config xml
• Supports Appenders registered as OSGi Services
• Supports Filters and TurboFilters registered as OSGi Services
• Support providing Logback configuration as fragments through OSGi Service Registry
• Support for referring to Appenders registered as OSGi services from with Logback config
• Exposes Logback runtime state through the Felix WebConsole Plugin

Note, that for all loggers configured via OSGi configurations (see above) certain characters are escaped when outputting the log message and the exception message. For example newline and carriage return are replaced with an underscore.

The following sections provide more details.

TurboFilters as OSGi Services

Logback TurboFilters operate globally and are invoked for every Logback call. To register an OSGi TurboFilter, just to register an service that implements the ch.qos.logback.classic.turbo.TurboFilter interface.

import import ch.qos.logback.classic.turbo.MatchingFilter;

SimpleTurboFilter stf = new SimpleTurboFilter();
ServiceRegistration sr  = bundleContext.registerService(TurboFilter.class.getName(), stf, null);

private static class SimpleTurboFilter extends MatchingFilter {
    @Override
    public FilterReply decide(Marker marker, Logger logger, Level level, String format,
     Object[] params, Throwable t) {
        if(logger.getName().equals("turbofilter.foo.bar")){
                return FilterReply.DENY;
        }
        return FilterReply.NEUTRAL;
    }
}

As these filters are invoked for every call they must execute quickly.

Filters as OSGi services

Logback Filters are attached to appenders and are used to determine if any LoggingEvent needs to be passed to the appender. When registering a filter the bundle needs to configure a service property appenders which refers to list of appender names to which the Filter must be attached

import ch.qos.logback.core.filter.Filter;

SimpleFilter stf = new SimpleFilter();
Dictionary<String, Object> props = new Hashtable<String, Object>();
props.put("appenders", "TestAppender");
ServiceRegistration sr  = bundleContext.registerService(Filter.class.getName(), stf, props);

private static class SimpleFilter extends Filter<ILoggingEvent> {

    @Override
    public FilterReply decide(ILoggingEvent event) {
        if(event.getLoggerName().equals("filter.foo.bar")){
            return FilterReply.DENY;
        }
        return FilterReply.NEUTRAL;
    }
}

If the appenders value is set to * then the filter would be registered with all the appenders (Since 4.0.4)

Appenders as OSGi services

Logback Appenders handle the logging events produced by Logback. To register an OSGi Appender, just register a service that implements the ch.qos.logback.core.Appender interface. Such a service must have a loggers service property, which refers to list of logger names to which the Appender must be attached.

Dictionary<String,Object> props = new Hashtable<String, Object>();

String[] loggers = {
        "foo.bar:DEBUG",
        "foo.bar.zoo:INFO",
};

props.put("loggers",loggers);
sr = bundleContext.registerService(Appender.class.getName(),this,props);

Logback Config Fragment Support

Logback supports including parts of a configuration file from another file (See File Inclusion). This module extends that support by allowing other bundles to provide config fragments. There are two ways to achieve that, described below.

Logback config fragments as String objects

If you have the config as string then you can register that String instance as a service with property logbackConfig set to true. The Sling Logback Extension monitors such objects and passes them to logback.

Properties props = new Properties();
props.setProperty("logbackConfig","true");

String config = "<included>\n" +
        "  <appender name=\"FOOFILE\" class=\"ch.qos.logback.core.FileAppender\">\n" +
        "    <file>${sling.home}/logs/foo.log</file>\n" +
        "    <encoder>\n" +
        "      <pattern>%d %-5level %logger{35} - %msg %n</pattern>\n" +
        "    </encoder>\n" +
        "  </appender>\n" +
        "\n" +
        "  <logger name=\"foo.bar.include\" level=\"INFO\">\n" +
        "       <appender-ref ref=\"FOOFILE\" />\n" +
        "  </logger>\n" +
        "\n" +
        "</included>";

registration = context.registerService(String.class.getName(),config,props);

If the config needs to be updated just re-register the service so that changes are picked up.

Logback config fragments as ConfigProvider instances

Another way to provide config fragments is with services that implement the org.apache.sling.commons.log.logback.ConfigProvider interface.

@Component
@Service
public class ConfigProviderExample implements ConfigProvider {
    public InputSource getConfigSource() {
        return new InputSource(getClass().getClassLoader().getResourceAsStream("foo-config.xml"));
    }
}

If the config changes then sending an OSGi event with the org/apache/sling/commons/log/RESET topic resets the Logback runtime.

eventAdmin.sendEvent(new Event("org/apache/sling/commons/log/RESET",new Properties()));

External Config File

Logback can be configured with an external file. The file name can be specified through

1. OSGi config - Look for a config with name Apache Sling Logging Configuration and specify the config file path.
2. OSGi Framework Properties - Logback support also looks for a file named according to the OSGi framwork org.apache.sling.commons.log.configurationFile property.

If you are providing an external config file then to support OSGi integration you need to add following action entry:

<newRule pattern="*/configuration/osgi"
         actionClass="org.apache.sling.commons.log.logback.OsgiAction"/>
<newRule pattern="*/configuration/appender-ref-osgi"
         actionClass="org.apache.sling.commons.log.logback.OsgiAppenderRefAction"/>
<osgi/>

The osgi element enables the OSGi integration support

Java Util Logging (JUL) Integration

The bundle also support SLF4JBridgeHandler. The two steps listed below enable the JUL integration. This allows for routing logging messages from JUL to the Logbback appenders.

1. Set the org.apache.sling.commons.log.julenabled framework property to true.

If org.apache.sling.commons.log.julenabled is found to be true then LevelChangePropagator would be registered automatically with Logback

Configuring OSGi appenders in the Logback Config

So far Sling used to configure the appenders based on OSGi config. This provides a very limited set of configuration options. To make use of other Logback features you can override the OSGi config from within the Logback config file. OSGi config based appenders are named based on the file name.

For example, for the following OSGi config

org.apache.sling.commons.log.file="logs/error.log"
org.apache.sling.commons.log.level="INFO"
org.apache.sling.commons.log.file.size="'.'yyyy-MM-dd"
org.apache.sling.commons.log.file.number=I"7"
org.apache.sling.commons.log.pattern="{0,date,dd.MM.yyyy HH:mm:ss.SSS} *{4}* [{2}] {3} {5}"

The Logback appender would be named logs/error.log. To extend/override the config in a Logback config create an appender with the name logs/error.log:

<appender name="/logs/error.log" class="ch.qos.logback.core.FileAppender">
  <file>${sling.home}/logs/error.log</file>
  <encoder>
    <pattern>%d %-5level %X{sling.userId:-NA} [%thread] %logger{30} %marker- %msg %n</pattern>
    <immediateFlush>true</immediateFlush>
  </encoder>
</appender>

In this case the logging module creates an appender based on the Logback config instead of the OSGi config. This can be used to move the application from OSGi based configs to Logback based configs.

Using Slf4j API 1.7

With Slf4j API 1.7 onwards its possible to use logger methods with varargs i.e. log n arguments without constructing an object array e.g. log.info("This is a test {} , {}, {}, {}",1,2,3,4). Without var args you need to construct an object array log.info("This is a test {} , {}, {}, {}",new Object[] {1,2,3,4}). To make use of this API and still be able to use your bundle on Sling systems which package older version of the API jar, follow the below steps. (See SLING-3243) for more details.

1. Update the api version in the pom:

   <dependencies>
       <dependency>
         <groupId>org.slf4j</groupId>
         <artifactId>slf4j-api</artifactId>
         <version>1.7.5</version>
         <scope>provided</scope>
       </dependency>
      ...
   </dependency>
   

2. Add an Import-Package instruction with a custom version range:

   <build>
       <plugins>
         <plugin>
           <groupId>org.apache.felix</groupId>
           <artifactId>maven-bundle-plugin</artifactId>
           <extensions>true</extensions>
           <configuration>
             <instructions>
               ...
               <Import-Package>
                 org.slf4j;version="[1.5,2)",
                 *
               </Import-Package>
             </instructions>
           </configuration>
         </plugin>
         ...
      </plugins>
   </build>
   

The Slf4j API bundle 1.7.x is binary compatible with 1.6.x.

This setup allows your bundles to make use of the var args feature while making logging calls, but the bundles can still be deployed on older systems which provide only the 1.6.4 version of the slf4j api.

Log Tracer

Log Tracer provides support for enabling the logs for specific category at specific level and only for specific request. It provides a very fine level of control via config provided as part of HTTP request around how the logging should be performed for given category.

Refer to Log Tracer Doc for more details

Slf4j MDC

Sling MDC Inserting Filter exposes various request details as part of MDC.

Currently it exposes following variables:

1. req.remoteHost - Request remote host
2. req.userAgent - User Agent Header
3. req.requestURI - Request URI
4. req.queryString - Query String from request
5. req.requestURL -
6. req.xForwardedFor -
7. sling.userId - UserID associated with the request. Obtained from ResourceResolver
8. jcr.sessionId - Session ID of the JCR Session associated with current request.

The filter also allow configuration to extract data from request cookie, header and parameters. Look for configuration with name 'Apache Sling Logging MDC Inserting Filter' for details on specifying header, cookie, param names.

Including MDC in Log Message

To include the MDC value in log message you MUST use the Logback pattern based on Logback and not the old MessageFormat based pattern.

%d{dd.MM.yyyy HH:mm:ss.SSS} *%p* [%X{req.remoteHost}] [%t] %c %msg%n

Installation

Download the bundle from here or use following Maven dependency

<dependency>
    <groupId>org.apache.sling</groupId>
    <artifactId>org.apache.sling.extensions.slf4j.mdc</artifactId>
    <version>1.0.0</version>
</dependency>

Logback Groovy Fragment

This fragment is required to make use of Groovy based event evaluation support provided by Logback. This enables programatic filtering of the log messages and is useful to get desired logs without flooding the system. For example Oak logs the JCR operations being performed via a particular session. if this lo is enabled it would flood the log with messages from all the active session. However if you need logging only from session created in a particular thread then that can be done in following way

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="1 second">
  <jmxConfigurator/>
  <newRule pattern="*/configuration/osgi" actionClass="org.apache.sling.commons.log.logback.OsgiAction"/>
  <newRule pattern="*/configuration/appender-ref-osgi" actionClass="org.apache.sling.commons.log.logback.OsgiAppenderRefAction"/>
  <osgi/>

   <appender name="OAK" class="ch.qos.logback.core.FileAppender">
    <filter class="ch.qos.logback.core.filter.EvaluatorFilter">      
      <evaluator class="ch.qos.logback.classic.boolex.GEventEvaluator"> 
        <expression><![CDATA[
            return e.getThreadName().contains("JobHandler");
        ]]></expression>
      </evaluator>
      <OnMismatch>DENY</OnMismatch>
      <OnMatch>ACCEPT</OnMatch>
    </filter>
    <file>${sling.home}/logs/oak.log</file>
    <encoder>
      <pattern>%d %-5level [%thread] %marker- %msg %n</pattern> 
      <immediateFlush>true</immediateFlush>
    </encoder>
  </appender>

  <logger name="org.apache.jackrabbit.oak.jcr.operations" level="DEBUG" additivity="false">
      <appender-ref ref="OAK"/>
  </logger>
</configuration>

Logback exposes a variable e which is of type ILoggingEvent. It provides access to current logging event. Above logback config would route all log messages from org.apache.jackrabbit.oak.jcr.operations category to ${sling.home}/logs/oak.log. Further only those log messages would be logged where the threadName contains JobHandler. Depending on the requirement the expression can be customised.

Installation

Currently the bundle is not released and has to be build from here

<dependency>
    <groupId>org.apache.sling</groupId>
    <artifactId>org.apache.sling.extensions.logback-groovy-fragment</artifactId>
    <version>1.0.0-SNAPSHOT</version>
</dependency>

FAQ

Q. Can Sling Commons Log bundle be used in non Sling environments

This bundle does not depend on any other Sling bundle and can be easily used in any OSGi framework. To get complete log support working you need to deploy following bundles

• Slf4j-Api - org.slf4j:slf4j-api
• Jcl over Slf4j - org.slf4j:jcl-over-slf4j
• Log4j over Slf4j - org.slf4j:log4j-over-slf4j
• Sling Log Service - org.apache.sling:org.apache.sling.commons.logservice:1.0.2
• Sling Commons Log - org.apache.sling:org.apache.sling.commons.log:4.0.0 or above
• Sling Log WebConsole - org.apache.sling.commons.log.webconsole:1.0.0 or above

Q. How to start Sling with an external logback.xml file

You need to specify the location of logback.xml via org.apache.sling.commons.log.configurationFile

    java -jar org.apache.sling.starter-XXX-standalone.jar -Dorg.apache.sling.commons.log.configurationFile=/path/to/logback