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

Post a Comment

Popular posts from this blog

Quarkus and "meta" extension

Quarkus is a great Java framework with a large ecosystem thanks to the extensions . Basically, if using Maven, your pom.xml contains the list of the extensions you want to use, meaning something like this: ... <dependency> <groupId>io.quarkus</groupId> <artifactId>quarkus-grpc</artifactId> </dependency> <dependency> <groupId>io.quarkus</groupId> <artifactId>quarkus-opentelemetry</artifactId> </dependency> ... It can quickly become large, and sometime you can have "conflict" between extensions (for example if you mix in the same dependencies set reactive and non reactive extensions). Quarkus "meta" extension To simplify the dependencies for the extensions you want to use (especially if it's basically the same extensions in all your services), you can create your own "meta" extension. This extension doesn't contain actual code, it "wraps" other exten
Read more

Getting started with Apache Karaf Minho

Image
Apache Karaf Minho Apache Karaf Minho is a new runtime, completely created from scratch. The objectives are: super easy to use and run ligtning fast, including GraalVM support Kubernetes compliant to be easily used on the cloud helping to optimize cloud costs by supporting applications colocation providing turnkey services allowing you to create Minho applications in a minute Minho is composed by: minho-boot is the core of Minho. It contains the runtime launcher and the core services (service registry, lifecycle service, configuration service, ...). minho-* services provided additional functionnalities in the runtime. You can use these services to create your own services, it's also where you will find the services managing sepcific kind of applications, allowing colocation. minho-tooling optionally provide convenient tools to create your own runtime. It includes minho-maven-plugin for instance. In this blog post, we will take a quick tour on A
Read more

Apache Karaf Minho and OpenTelemetry

Image
Telemetry is an important part of a software stack, especially on distributed system (where services call each others). OpenTelemetry is a CNCF project coming from OpenTracing and OpenCensus. It provides API to easily instrument your code and tools to collect and export telemetry data (metrics, logs and traces). Before going into how to use OpenTelemetry with Minho, we have to understand some key concepts: Span is a single building block representing an operation or some unit of work that you want to capture. They are capable of standing on their own, referencing (or following) from other spans, storing metadata, tags, etc. Trace is a visualisation of the life of a request (or series of other operations) that is made up of one or more spans. This collection of spans work together to paint a picture of the overall request, allowing you to easily reconstruct what happened within each span, etc. SpanContext is a wrapper of key values pairs that associates a trace to one or mor
Read more