Apache Karaf and log4j2 appenders

If Karaf default logging service matches most of users need, I had questions about how to add new or custom appenders.

Karaf and Pax Logging

The first thing to remember is that Apache Karaf doesn’t directly use log4j or slf4j or any direct logging framework. In order to provide maximum flexibility with unique configuration, Karaf uses Pax Logging. Pax Logging “abstracts” bunch of logging frameworks.
The purpose is to allow the developer to use the logging framework he wants and the devops doesn’t care about the logging framework, he just know the “central” and unique pax-logging configuration, dealing with the concrete logging framework.

This approach is very convenient and flexible, but he has a minor drawback: adding new “modules” (appenders, layout, etc) has to be done at Pax Logging level.

Fortunately, it’s easy 😉

Pax Logging extra

On Apache Karaf 4.2.x and 4.3.x, we are using pax-logging-log4j2 service implementation. Basically Pax Logging is splitted in two parts: Pax Logging API provides (exports) the “abstract” logging frameworks packages that the developer can use directly in his code (without impact) and Pax Logging “Service” is the concrete logging service (central configuration, etc). We have several implementations of the Pax Logging Service. Right now, Apache Karaf uses the Pax Logging Log4j2 service, meaning that the configuration uses the log4j2 format for instance.

Pax Logging Log4j2 service (named pax-logging-log4j2) provides the minimal layer required to use any logging framework smoothly. Especially, it includes “classic” set of log4j2 appenders and layouts (like the RollingRandomAccessFile or Console appenders for instance).
It's important to understand that the logging service has to be started in the "early" stage of the runtime in order to "catch" log use.
That's why Pax Logging bundles are started in etc/startup.properties. etc/startup.properties starts bundles even before the Apache Karaf features service (so before the boot features, in the very early stage of the Karaf bootstrap).

In order to avoid including bunch of dependencies, we packaged another bundle named pax-logging-log4j2-extra that provide "additional" log4j2 appenders and layout.

To illustrate this, let's say that we want to use JSON format in Karaf log.

The first step is to add pax-logging-log4j2-extra close to pax-logging-log4j2 in etc/startup.properties. As we want to use json layout, we need the dependency for this layout: jackson. It means we need to add jacson required bundles in etc/startup.properties as well.

Finally, it means etc/startup.properties looks like:

...mvn\:com.fasterxml.jackson.core/jackson-core/2.10.2 = 30mvn\:com.fasterxml.jackson.core/jackson-databind/2.10.2 = 30mvn\:com.fasterxml.jackson.core/jackson-annotations/2.10.2 = 30mvn\:org.ops4j.pax.logging/pax-logging-log4j2-extra/1.11.4 = 30

If you want to create your own custom distribution with pax-logging-log4j2-extra, you can use the following configuration of the karaf-maven-plugin:

                   <startupBundles>                        <bundle>mvn:com.fasterxml.jackson.core/jackson-core/2.10.2</bundle>                        <bundle>mvn:com.fasterxml.jackson.core/jackson-databind/2.10.2</bundle>                        <bundle>mvn:com.fasterxml.jackson.core/jackson-annotations/2.10.2</bundle>                        <bundle>mvn:org.ops4j.pax.logging/pax-logging-log4j2-extra/1.11.4</bundle>                    </startupBundles>

Now, we can update the etc/org.ops4j.pax.logging.cfg configuration to use json layout:

log4j2.rootLogger.level = INFOlog4j2.rootLogger.appenderRef.RollingFile.ref = RollingFilelog4j2.appender.rolling.type = RollingRandomAccessFilelog4j2.appender.rolling.name = RollingFilelog4j2.appender.rolling.fileName = ${karaf.log}/karaf.loglog4j2.appender.rolling.filePattern = ${karaf.log}/karaf.log.%ilog4j2.appender.rolling.append = truelog4j2.appender.rolling.layout.type = JsonLayoutlog4j2.appender.rolling.policies.type = Policieslog4j2.appender.rolling.policies.size.type = SizeBasedTriggeringPolicylog4j2.appender.rolling.policies.size.size = 8MB

Now, let's start Karaf and see what we have in data/log/karaf.log:

{  "thread" : "CM Configuration Updater (Update: pid=org.ops4j.pax.logging)",  "level" : "INFO",  "loggerName" : "org.ops4j.pax.logging.spi.support.EventAdminConfigurationNotifier",  "message" : "Sending Event Admin notification (configuration successful) to org/ops4j/pax/logging/Configuration",  "endOfBatch" : false,  "loggerFqcn" : "org.ops4j.pax.logging.slf4j.Slf4jLogger",  "instant" : {    "epochSecond" : 1591934845,    "nanoOfSecond" : 255000000  },  "threadId" : 36,  "threadPriority" : 5}^M{  "thread" : "activator-1-thread-2",  "level" : "INFO",  "loggerName" : "org.apache.karaf.features.internal.service.FeaturesServiceImpl",  "message" : "Adding features: 6935cc89-8cc6-4add-894c-8af917198d1d/[0,0.0.0]",  "endOfBatch" : false,  "loggerFqcn" : "org.ops4j.pax.logging.slf4j.Slf4jLogger",  "instant" : {    "epochSecond" : 1591934845,    "nanoOfSecond" : 443000000  },  "threadId" : 44,  "threadPriority" : 5}^M{  "thread" : "features-3-thread-1",  "level" : "INFO",  "loggerName" : "org.apache.karaf.features.internal.service.FeaturesServiceImpl",  "message" : "Changes to perform:",  "endOfBatch" : false,  "loggerFqcn" : "org.ops4j.pax.logging.slf4j.Slf4jLogger",  "instant" : {    "epochSecond" : 1591934845,    "nanoOfSecond" : 676000000  },  "threadId" : 47,  "threadPriority" : 5}^M

We can see the log events as JSON format, so our appender and layout are working fine.

Custom appender

If pax-logging-log4j2-extra provides most of the log4j2 "classic" appenders and layouts, sometime you want to add a third party appender ("outside" of log4j2) or your own custom appender.

That's very easy: you just have to create a fragment to "attach" your appender to pax-logging-log4j2 to have your appender available in Pax Logging service and so the configuration.

To illustrate this, let's say we want to add Rollbar log4j2 appender. Rollbar provides real-time exception reporting and continuous deployment monitoring for developers.

We gonna add a Rollbar log4j2 appender that send exceptions and messages to Rollbar platform.

The appender code itself is provided by Rollbar and pretty simple:

package com.rollbar.log4j2;import static com.rollbar.notifier.config.ConfigBuilder.withAccessToken;import com.rollbar.api.payload.data.Level;import com.rollbar.notifier.Rollbar;import com.rollbar.notifier.config.Config;import com.rollbar.notifier.config.ConfigBuilder;import com.rollbar.notifier.config.ConfigProvider;import com.rollbar.notifier.config.ConfigProviderHelper;import com.rollbar.notifier.provider.server.ServerProvider;import com.rollbar.notifier.wrapper.RollbarThrowableWrapper;import com.rollbar.notifier.wrapper.ThrowableWrapper;import java.io.Serializable;import java.util.HashMap;import java.util.List;import java.util.Map;import java.util.Map.Entry;import java.util.concurrent.TimeUnit;import org.apache.logging.log4j.core.Appender;import org.apache.logging.log4j.core.Filter;import org.apache.logging.log4j.core.Layout;import org.apache.logging.log4j.core.LogEvent;import org.apache.logging.log4j.core.appender.AbstractAppender;import org.apache.logging.log4j.core.config.Node;import org.apache.logging.log4j.core.config.plugins.Plugin;import org.apache.logging.log4j.core.config.plugins.PluginAttribute;import org.apache.logging.log4j.core.config.plugins.PluginElement;import org.apache.logging.log4j.core.config.plugins.PluginFactory;import org.apache.logging.log4j.core.config.plugins.validation.constraints.Required;import org.apache.logging.log4j.core.impl.ThrowableProxy;import org.apache.logging.log4j.core.util.Booleans;@Plugin(name = "Rollbar", category = Node.CATEGORY, elementType = Appender.ELEMENT_TYPE,        printObject = true)public class RollbarAppender extends AbstractAppender {    private static final String PACKAGE_NAME = "com.rollbar";    private static final String CUSTOM_NAMESPACE_KEY = "rollbar-log4j2";    private static final String CUSTOM_LOGGER_NAME_KEY = "loggerName";    private static final String CUSTOM_MDC_NAME_KEY = "mdc";    private static final String CUSTOM_NDC_NAME_KEY = "ndc";    private static final String CUSTOM_MAKER_NAME_KEY = "marker";    private static final String CUSTOM_THREAD_NAME_KEY = "threadName";    private Rollbar rollbar;    protected RollbarAppender(String name, Filter filter, Layout<? extends Serializable> layout,                              boolean ignoreExceptions, Rollbar rollbar) {        super(name, filter, layout, ignoreExceptions);        this.rollbar = rollbar;    }    /**     * Create appender plugin factory method.     *     * @param accessToken the Rollbar access token.     * @param codeVersion the codeVersion.     * @param endpoint the Rollbar endpoint to be used.     * @param environment the environment.     * @param language the language.     * @param enabled to enable or disable Rollbar.     * @param configProviderClassName The class name of the config provider implementation to get     *     the configuration.     * @param name the name.     * @param layout the layout.     * @param filter the filter.     * @param ignore the ignore exceptions flag.     * @return the rollbar appender.     */    @PluginFactory    public static RollbarAppender createAppender(            @PluginAttribute("accessToken") @Required final String accessToken,            @PluginAttribute("codeVersion") final String codeVersion,            @PluginAttribute("endpoint") final String endpoint,            @PluginAttribute("environment") final String environment,            @PluginAttribute("language") final String language,            @PluginAttribute("enabled") final boolean enabled,            @PluginAttribute("configProviderClassName") final String configProviderClassName,            @PluginAttribute("name") @Required final String name,            @PluginElement("Layout") Layout<? extends Serializable> layout,            @PluginElement("Filter") Filter filter,            @PluginAttribute("ignoreExceptions") final String ignore    ) {        ConfigProvider configProvider = ConfigProviderHelper                .getConfigProvider(configProviderClassName);        Config config;        ConfigBuilder configBuilder = withAccessToken(accessToken)                .codeVersion(codeVersion)                .environment(environment)                .endpoint(endpoint)                .server(new ServerProvider())                .language(language)                .enabled(enabled);        if (configProvider != null) {            config = configProvider.provide(configBuilder);        } else {            config = configBuilder.build();        }        Rollbar rollbar = new Rollbar(config);        boolean ignoreExceptions = Booleans.parseBoolean(ignore, true);        return new RollbarAppender(name, filter, layout, ignoreExceptions, rollbar);    }    @Override    public void append(LogEvent event) {        if (event.getLoggerName() != null && event.getLoggerName().startsWith(PACKAGE_NAME)) {            LOGGER.warn("Recursive logging from [{}] for appender [{}].", event.getLoggerName(),                    getName());            return;        }        ThrowableProxy throwableProxy = event.getThrownProxy();        ThrowableWrapper rollbarThrowableWrapper = buildRollbarThrowableWrapper(throwableProxy);        Map<String, Object> custom = this.buildCustom(event);        String message = event.getMessage() != null ? event.getMessage().getFormattedMessage() : null;        Level level = this.getLevel(event);        rollbar.log(rollbarThrowableWrapper, custom, message, level, false);    }    @Override    public boolean stop(final long timeout, final TimeUnit timeUnit) {        super.stop(timeout, timeUnit);        try {            rollbar.close(true);        } catch (Exception e) {            LOGGER.error("Closing rollbar", e);        }        return true;    }    @Override    public void stop() {        this.stop(0, TimeUnit.MILLISECONDS);    }    private ThrowableWrapper buildRollbarThrowableWrapper(ThrowableProxy throwableProxy) {        if (throwableProxy == null) {            return null;        }        if (throwableProxy.getThrowable() != null) {            return new RollbarThrowableWrapper(throwableProxy.getThrowable());        }        String className = throwableProxy.getName();        String message = throwableProxy.getMessage();        ThrowableWrapper causeThrowableWrapper =                buildRollbarThrowableWrapper(throwableProxy.getCauseProxy());        StackTraceElement[] stackTraceElements = buildStackTraceElements(                throwableProxy.getStackTrace());        return new RollbarThrowableWrapper(className, message, stackTraceElements,                causeThrowableWrapper);    }    private StackTraceElement[] buildStackTraceElements(StackTraceElement[] stackTraceElements) {        StackTraceElement[] elements = new StackTraceElement[stackTraceElements.length];        for (int i = 0; i < stackTraceElements.length; i++) {            elements[i] = stackTraceElements[i];        }        return elements;    }    private Level getLevel(LogEvent event) {        org.apache.logging.log4j.Level level = event.getLevel();        Level rollbarLevel = Level.lookupByName(level.name());        if (rollbarLevel != null) {            return rollbarLevel;        }        if (org.apache.logging.log4j.Level.FATAL.equals(level)) {            return Level.CRITICAL;        }        return null;    }    private Map<String, Object> buildCustom(LogEvent event) {        Map<String, Object> custom = new HashMap<>();        custom.put(CUSTOM_LOGGER_NAME_KEY, event.getLoggerName());        custom.put(CUSTOM_THREAD_NAME_KEY, event.getThreadName());        custom.put(CUSTOM_MDC_NAME_KEY, this.buildMdc(event));        custom.put(CUSTOM_NDC_NAME_KEY, this.getNdc(event));        custom.put(CUSTOM_MAKER_NAME_KEY, this.getMarker(event));        Map<String, Object> rootCustom = new HashMap<>();        rootCustom.put(CUSTOM_NAMESPACE_KEY, custom);        return rootCustom;    }    private Map<String, Object> buildMdc(LogEvent event) {        if (event.getContextData() == null || event.getContextData().size() == 0) {            return null;        }        Map<String, Object> mdc = new HashMap<>();        for (Entry<String, String> mdcEntry : event.getContextData().toMap().entrySet()) {            mdc.put(mdcEntry.getKey(), mdcEntry.getValue());        }        return mdc;    }    private List<String> getNdc(LogEvent event) {        if (event.getContextStack() == null || event.getContextStack().size() == 0) {            return null;        }        return event.getContextStack().asList();    }    private String getMarker(LogEvent event) {        if (event.getMarker() == null) {            return null;        }        return event.getMarker().getName();    }}

The only thing we have to do is to "wrap" this appender code in a bundle fragment attached to pax-logging-log4j2. This "wrapping" is simply done with Maven.

Basically, there's the main tricks to do:

  1. We have to generate the log4j2 dat file using the log4j PluginProcessor.
  2. We have to embed rollbar-java dependency as private package of our bundle and import log4j2 packages (provided by Pax Logging)
  3. We have to embed log4j2 dat file as bundle resources.

That's all !

Finally, our pom.xml looks like:

<?xml version="1.0" encoding="UTF-8"?><project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">    <modelVersion>4.0.0</modelVersion>    <groupId>net.nanthrax.test</groupId>    <artifactId>rollbar-bundle</artifactId>    <version>1.7.3_1-SNAPSHOT</version>    <packaging>bundle</packaging>    <dependencies>        <dependency>            <groupId>com.rollbar</groupId>            <artifactId>rollbar-java</artifactId>            <version>1.7.3</version>        </dependency>        <dependency>            <groupId>org.apache.logging.log4j</groupId>            <artifactId>log4j-core</artifactId>            <version>2.11.0</version>            <scope>provided</scope>        </dependency>    </dependencies>    <build>        <plugins>            <plugin>                <groupId>org.apache.maven.plugins</groupId>                <artifactId>maven-compiler-plugin</artifactId>                <version>3.1</version>                <executions>                    <execution>                        <id>log4j-plugin-processor</id>                        <goals>                            <goal>compile</goal>                        </goals>                        <phase>process-classes</phase>                        <configuration>                            <proc>only</proc>                            <annotationProcessors>                                <annotationProcessor>org.apache.logging.log4j.core.config.plugins.processor.PluginProcessor</annotationProcessor>                            </annotationProcessors>                        </configuration>                    </execution>                </executions>                <configuration>                    <source>1.8</source>                    <target>1.8</target>                </configuration>            </plugin>            <plugin>                <groupId>org.apache.felix</groupId>                <artifactId>maven-bundle-plugin</artifactId>                <version>4.2.1</version>                <extensions>true</extensions>                <inherited>true</inherited>                <configuration>                    <instructions>                        <Fragment-Host>org.ops4j.pax.logging.pax-logging-log4j2</Fragment-Host>                        <Export-Package>!*</Export-Package>                        <Import-Package>                            org.osgi.framework;version="[1.8,2.0)",                            org.apache.logging.log4j*;version="[2,3)";resolution:=optional,                            *                        </Import-Package>                        <Private-Package>                            com.rollbar*,                            com.rollbar.log4j2*                        </Private-Package>                        <Include-Resource>                            {maven-resources},                            META-INF/org/apache/logging/log4j/core/config/plugins/Log4j2Plugins.dat=target/classes/META-INF/org/apache/logging/log4j/core/config/plugins/Log4j2Plugins.dat                        </Include-Resource>                    </instructions>                </configuration>            </plugin>        </plugins>    </build></project>

We now have our Rollbar bundle ready to use. As we did with pax-logging-log4j2-extra, our Rollbar bundle has to be added in etc/startup.properties. As our bundle embeds dependencies as private package, we just need our bundle, nothing else:

...mvn\:net.nanthrax.test/rollbar-bundle/1.7.3_1-SNAPSHOT = 30

Again, you can add this bundle in your Karaf custom runtime using the karaf-maven-plugin configuration:

                    <startupBundles>                        <bundle>mvn:net.nanthrax.test/rollbar-bundle/1.7.3_1-SNAPSHOT</bundle>                    </startupBundles>

Now, we can add Rollbar log4j2 configuration in etc/org.ops4j.pax.logging.cfg:

log4j2.rootLogger.level = INFOlog4j2.rootLogger.appenderRef.Rollbar.ref= Rollbarlog4j2.appender.rollbar.type = Rollbarlog4j2.appender.rollbar.name = Rollbarlog4j2.appender.rollbar.accessToken = foo

And it's done ! Our appender is working.

Summary

Apache Karaf logging service is very flexible and powerful. Pax Logging is easily extensible allowing you to add your own appenders or layouts.

You can find the full sample project here: https://github.com/jbonofre/karaf-log-appender

Comments

Popular posts from this blog

Exposing Apache Karaf configurations with Apache Arrow Flight

Getting started with Apache Karaf Minho

Using Apache Karaf with Kubernetes