OpenTelemetryAppender with Pax Log

[jherkel]

I use Opentelemetry Java agent with Karaf. It works but now I would like to receive all logs from karaf (4.4.6). I'm able to receive only opentelemetry internal logs but not logs from my application or karaf itself.

I have checked examples but it seems to me that this is a little bit different case as in examples.

Part of opentelemetry java agent is also Log4j2 appender
https://github.com/open-telemetry/opentelemetry-java-instrumentation/blob/main/instrumentation/log4j/log4j-appender-2.17/library/src/main/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/OpenTelemetryAppender.java

log4j2 can be configured something like this:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN" packages="io.opentelemetry.instrumentation.log4j.appender.v2_17">
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout
          pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} trace_id: %X{trace_id} span_id: %X{span_id} trace_flags: %X{trace_flags} - %msg%n"/>
    </Console>
    <OpenTelemetry name="OpenTelemetryAppender"/>
  </Appenders>
  <Loggers>
    <Root>
      <AppenderRef ref="OpenTelemetryAppender" level="All"/>
      <AppenderRef ref="Console" level="All"/>
    </Root>
  </Loggers>
</Configuration>

But I don't have any idea how to export OpenTelemetryAppender to pax log so that log4j2 would be able to register a new type of appender.

So in general, could you advise me if it is even possible (there are some "special" things that javagent does). And if it is possible can you give me some hints (examples,blog) what I have to do.

[grgrzybek]

Hello!

<OpenTelemetry> is a plugin-based appender for log4j and in theory it should be possible to use it simply by configuring it for Pax Logging.

pax-logging-log4j2 is configuring Log4j2 Logging Manager using all its discovery mechanism, which include plugin discovery.

https://github.com/ops4j/org.ops4j.pax.logging/tree/main/pax-logging-samples/fragment-log4j2 is an example plugin that adds new appender called <List>:

@Plugin(name = "List", category = Core.CATEGORY_NAME, elementType = Appender.ELEMENT_TYPE)
public class ListAppender extends AbstractAppender {

which is then declared in META-INF/org/apache/logging/log4j/core/config/plugins/Log4j2Plugins.dat resource generated using org.apache.logging.log4j.core.config.plugins.processor.PluginProcessor annotation processor for maven-compiler-plugin.

In order for pax-logging-log4j2 to see this descriptor, the <List> appender plugin has to be packaged within a fragment bundle attached to pax-logging-log4j2 host bundle.

Because https://github.com/open-telemetry/opentelemetry-java-instrumentation/blob/main/instrumentation/log4j/log4j-appender-2.17/library/build.gradle.kts it's a Gradle-based build, I can't easily check what is the result of such build...

I checked https://repo1.maven.org/maven2/io/opentelemetry/instrumentation/opentelemetry-log4j-appender-2.17/2.10.0-alpha/ and it contains proper (at first glance) /META-INF/org/apache/logging/log4j/core/config/plugins/Log4j2Plugins.dat resource, so I'd:

1. create a new fragment bundle with Fragment-Host: org.ops4j.pax.logging.pax-logging-log4j2 META-INF/MANIFEST.MF OSGi header
2. private-package entire io.opentelemetry.instrumentation/opentelemetry-log4j-appender-2.17 library including the Log4j2Plugins.dat resource
3. install it in Karaf
4. refresh pax-logging-log4j2 bundle (to pick up the new fragment)

For now I can't give you more than the above context, because I really can't afford doing it myself now ;) sorry...

[jbonofre]

I agree with @grgrzybek : adding the appender (using fragment) should work.

You have an example here: https://github.com/apache/karaf/tree/main/examples/karaf-log-appender-example

For context, you also have Apache Karaf Decanter that can log to get log messages sent to prometheus for instance.

[jherkel]

Thank for hints but maybe I wasn't clear enough. This appender is part of opentelemetry-javaagent.jar. So I don't know how to create osgi fragment for this because this jar is outside karaf (I setup it via setenv JAVA_OPTS") and it is not a karaf bundle.

[grgrzybek]

In special branch https://github.com/ops4j/org.ops4j.pax.logging/commits/example-556/ I created a sample Maven module with a fragment that embeds io.opentelemetry.instrumentation:opentelemetry-log4j-appender-2.17. See https://github.com/ops4j/org.ops4j.pax.logging/tree/example-556/pax-logging-samples/fragment-log4j2-opentelemetry

The config produces a fragment with this Bundle-ClassPath header:

Bundle-ClassPath: .,opentelemetry-log4j-appender-2.17-2.10.0-alpha.jar
 ,opentelemetry-log4j-context-data-2.17-autoconfigure-2.10.0-alpha.jar
 ,opentelemetry-instrumentation-api-2.10.0.jar,opentelemetry-instrumen
 tation-api-incubator-2.10.0-alpha.jar,opentelemetry-api-1.44.1.jar,op
 entelemetry-context-1.44.1.jar,opentelemetry-api-incubator-1.44.1-alp
 ha.jar,opentelemetry-semconv-1.28.0-alpha.jar

Them on fresh Karaf 4.4.6:

I installed this fragment:

karaf@root()> install mvn:org.ops4j.pax.logging/pax-logging-sample-fragment-log4j2-opentelemetry/2.2.8-SNAPSHOT
Bundle ID: 53

Refreshed the host:

karaf@root()> refresh org.ops4j.pax.logging.pax-logging-log4j2

And immediately in the console (because when you refresh logging implementation, you can't use it to log information ;) - so only basic debug logging from pax-logging-api (fallback logging) was used) I saw:

[DEBUG] Adding bundle org.ops4j.pax.logging.pax-logging-log4j2:2.2.7 (5) : starting                                                                                                                                              
org.ops4j.pax.logging.pax-logging-api [log4j2] ERROR : Could not create plugin of type class io.opentelemetry.instrumentation.log4j.appender.v2_17.OpenTelemetryAppender for element OpenTelemetry: java.lang.NoClassDefFoundError: io/opentelemetry/context/ImplicitContextKeyed
org.ops4j.pax.logging.pax-logging-api [log4j2] ERROR : Unable to invoke factory method in class io.opentelemetry.instrumentation.log4j.appender.v2_17.OpenTelemetryAppender for element OpenTelemetry: java.lang.NoClassDefFoundError: io/opentelemetry/context/ImplicitContextKeyed
org.ops4j.pax.logging.pax-logging-api [log4j2] ERROR : Null object returned for OpenTelemetry in Appenders.
org.ops4j.pax.logging.pax-logging-api [log4j2] ERROR : Unable to locate appender "OpenTelemetry" for logger config "root"

It simply means that embedding just:

<dependency>
    <groupId>io.opentelemetry.instrumentation</groupId>
    <artifactId>opentelemetry-log4j-appender-2.17</artifactId>
</dependency>

is not sufficient...

From my experience I know that sometimes these big projects or projects that simply ship tens of different artifacts under the same group ID and version, are not easy - you can't quickly tell which dependencies are needed.

Using mvn dependency:tree for rescue:

[INFO] \- io.opentelemetry.instrumentation:opentelemetry-log4j-appender-2.17:jar:2.10.0-alpha:compile
[INFO]    +- io.opentelemetry.instrumentation:opentelemetry-instrumentation-api:jar:2.10.0:compile
[INFO]    |  +- io.opentelemetry:opentelemetry-api-incubator:jar:1.44.1-alpha:runtime
[INFO]    |  \- io.opentelemetry.semconv:opentelemetry-semconv:jar:1.28.0-alpha:compile
[INFO]    +- io.opentelemetry.instrumentation:opentelemetry-instrumentation-api-incubator:jar:2.10.0-alpha:compile
[INFO]    +- io.opentelemetry:opentelemetry-api:jar:1.44.1:compile
[INFO]    |  \- io.opentelemetry:opentelemetry-context:jar:1.44.1:compile
[INFO]    \- io.opentelemetry.instrumentation:opentelemetry-log4j-context-data-2.17-autoconfigure:jar:2.10.0-alpha:runtime

I found that I have to embed 8 JARs in total, but it allowed me to refresh the pax-logging-log4j2 bundle correctly:

karaf@root()> refresh org.ops4j.pax.logging.pax-logging-log4j2
karaf@root()> [DEBUG] Adding bundle org.ops4j.pax.logging.pax-logging-log4j2:2.2.7 (5) : starting

karaf@root()> la | grep Logging
 4 │ Active   │   8 │ 2.2.7              │ OPS4J Pax Logging - API
 5 │ Active   │   8 │ 2.2.7              │ OPS4J Pax Logging - Log4Jv2 implementation, Fragments: 53
53 │ Resolved │  80 │ 2.2.8.SNAPSHOT     │ OPS4J Pax Logging - Samples - Fragment for Log4J2, Hosts: 5

The configuration I used in etc/org.ops4j.pax.logging.cfg is (only changes):

# Root logger
log4j2.rootLogger.level = INFO
...
log4j2.rootLogger.appenderRef.OpenTelemetry.ref = OpenTelemetry

...
log4j2.appender.tele.type = OpenTelemetry
log4j2.appender.tele.name = OpenTelemetry

Under the debugger I saw proper appender attached to my logger:

m_delegate = {org.apache.logging.log4j.core.Logger@11805} "org.apache.karaf.shell.support.ShellUtil:INFO in pax-logging"
 context: org.apache.logging.log4j.core.LoggerContext  = {org.apache.logging.log4j.core.LoggerContext@12001} 
 ...
 name: java.lang.String  = {@12018} "org.apache.karaf.shell.support.ShellUtil"
 privateConfig: org.apache.logging.log4j.core.Logger$PrivateConfig  = {org.apache.logging.log4j.core.Logger$PrivateConfig@12017} "PrivateConfig [loggerConfig=root, config=org.apache.logging.log4j.core.config.properties.PropertiesConfiguration@7263e151, loggerConfigLevel=INFO, intLevel=400, logger=org.apache.karaf.shell.support.ShellUtil:INFO in pax-logging]"
  ...
  logger: org.apache.logging.log4j.core.Logger  = {org.apache.logging.log4j.core.Logger@11805} "org.apache.karaf.shell.support.ShellUtil:INFO in pax-logging"
  loggerConfig: org.apache.logging.log4j.core.config.LoggerConfig  = {org.apache.logging.log4j.core.config.LoggerConfig@12023} "root"
   ...
   appenders: org.apache.logging.log4j.core.config.AppenderControlArraySet  = {org.apache.logging.log4j.core.config.AppenderControlArraySet@12031} "AppenderControlArraySet [appenderArray=[org.apache.logging.log4j.core.config.AppenderControl@343942ed[appender=PaxOsgi, appenderName=PaxOsgi, level=null, intLevel=2147483647, recursive=java.lang.ThreadLocal@26012e90, filter=null], org.apache.logging.log4j.core.config.AppenderControl@70e75141[appender=RollingFile, appenderName=RollingFile, level=null, intLevel=2147483647, recursive=java.lang.ThreadLocal@63ea4c01, filter=null], org.apache.logging.log4j.core.config.AppenderControl@9bef7d37[appender=Console, appenderName=Console, level=null, intLevel=2147483647, recursive=java.lang.ThreadLocal@2df976a1, filter=OFF], org.apache.logging.log4j.core.config.AppenderControl@53e5c06f[appender=OpenTelemetry, appenderName=OpenTelemetry, level=null, intLevel=2147483647, recursive=java.lang.ThreadLocal@40fd7326, filter=null]]]"
    appenderArray: org.apache.logging.log4j.core.config.AppenderControl[]  = {org.apache.logging.log4j.core.config.AppenderControl[4]@12036} 
     ...
     3 = {org.apache.logging.log4j.core.config.AppenderControl@12040} "org.apache.logging.log4j.core.config.AppenderControl@53e5c06f[appender=OpenTelemetry, appenderName=OpenTelemetry, level=null, intLevel=2147483647, recursive=java.lang.ThreadLocal@40fd7326, filter=null]"
      appender: org.apache.logging.log4j.core.Appender  = {io.opentelemetry.instrumentation.log4j.appender.v2_17.OpenTelemetryAppender@12046} "OpenTelemetry"
       eventsToReplay: java.util.concurrent.BlockingQueue  = {java.util.concurrent.ArrayBlockingQueue@12049}  size = 2
       filter: org.apache.logging.log4j.core.Filter  = null
       handler: org.apache.logging.log4j.core.ErrorHandler  = {org.apache.logging.log4j.core.appender.DefaultErrorHandler@12052} 
       ignoreExceptions: boolean  = true
       layout: org.apache.logging.log4j.core.Layout  = null
       lock: java.util.concurrent.locks.ReadWriteLock  = {java.util.concurrent.locks.ReentrantReadWriteLock@12051} "java.util.concurrent.locks.ReentrantReadWriteLock@6fa7a007[Write locks = 0, Read locks = 0]"
       mapper: io.opentelemetry.instrumentation.log4j.appender.v2_17.internal.LogEventMapper  = {io.opentelemetry.instrumentation.log4j.appender.v2_17.internal.LogEventMapper@12048} 
       name: java.lang.String  = {@12047} "OpenTelemetry"
       openTelemetry: io.opentelemetry.api.OpenTelemetry  = null
       propertyArray: org.apache.logging.log4j.core.config.Property[]  = {org.apache.logging.log4j.core.config.Property[0]@12053} 
       replayLimitWarningLogged: java.util.concurrent.atomic.AtomicBoolean  = {java.util.concurrent.atomic.AtomicBoolean@12050} "false"
       state: org.apache.logging.log4j.core.LifeCycle$State  = {@12012} "STARTED"

That's all I can do for now - I hope this'll help you check how it works, because I'm not (yet?) very familiar with Open Telemetry (I know there has to be some event collector available?)

[jherkel]

Thank a lot, I will check it.

[grgrzybek]

@jherkel any news about this one?

[jherkel]

Sorry for the late response. I have tried it but there was a problem with null pointer exception. I couldn't spend more time on this so I switched to opentelemetry collector (it parsed json output from log4j2). Not optimal but working and we can live with it for now.

[grgrzybek]

If you give me full stack trace with this NPE, I can try checking what's the problem.