Skip to content

Commit

Permalink
Prototype Log4j2 Appender (open-telemetry#4375)
Browse files Browse the repository at this point in the history
* WIP

* Use Log SDK snapshot

* Update to 1.9.0 release, refine

* Remove appenders from common log config

* Respond to PR feedback

* Update readme

* Switch to compileOnly log sdk dependency, use logger name as instrumentation name

* Switch to minimalist LogEvent mapping

* PR feedback

* PR feedback
  • Loading branch information
jack-berg authored and RashmiRam committed May 23, 2022
1 parent 430edae commit 7510b0a
Show file tree
Hide file tree
Showing 10 changed files with 552 additions and 13 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,7 @@ import io.opentelemetry.instrumentation.test.InstrumentationSpecification
import org.apache.logging.log4j.LogManager

abstract class Log4j2Test extends InstrumentationSpecification {
def cleanup() {
def setup() {
ListAppender.get().clearEvents()
}

Expand Down
72 changes: 60 additions & 12 deletions instrumentation/log4j/log4j-2.13.2/library/README.md
Original file line number Diff line number Diff line change
@@ -1,15 +1,8 @@
# Log4j 2 Integration

This module integrates instrumentation with Log4j 2 by injecting the trace ID and span ID from a
mounted span into
Log4j's [context data](https://logging.apache.org/log4j/2.x/manual/thread-context.html).

**Note**: Depending on your application, you may run into a [critical bug](https://issues.apache.org/jira/browse/LOG4J2-2838)
with Log4j 2.13.2. If log messages show a `NullPointerException` when adding this instrumentation,
please update to 2.13.3 or higher. The only change between 2.13.2 and 2.13.3 is the fix to this
issue.
This module provides Log4j2 extensions related to OpenTelemetry.

To use it, just add the module to your application's runtime classpath.
To use it, add the module to your application's runtime classpath.

**Maven**

Expand All @@ -33,14 +26,26 @@ dependencies {
}
```

Log4j will automatically pick up our integration and will have these keys added to the context when
a log statement is made when a span is active.
## OpenTelemetry Context Data Provider

`OpenTelemetryContextDataProvider` implements the Log4j2 `ContextDataProvider` SPI, and injects the
trace ID and span ID from an active span into
Log4j's [context data](https://logging.apache.org/log4j/2.x/manual/thread-context.html).

**Note**: Depending on your application, you may run into
a [critical bug](https://issues.apache.org/jira/browse/LOG4J2-2838)
with Log4j 2.13.2. If log messages show a `NullPointerException` when adding this instrumentation,
please update to 2.13.3 or higher. The only change between 2.13.2 and 2.13.3 is the fix to this
issue.

Log4j will automatically pick up the integration when you include this module. The following keys
will be added to the context when a log statement is made when a span is active:

- `trace_id`
- `span_id`
- `trace_flags`

You can use these keys when defining an appender in your `log4j.xml` configuration, for example
You can use these keys when defining an appender in your `log4j.xml` configuration, for example:

```xml
<?xml version="1.0" encoding="UTF-8"?>
Expand All @@ -58,3 +63,46 @@ You can use these keys when defining an appender in your `log4j.xml` configurati
</Loggers>
</Configuration>
```

## OpenTelemetry Appender

`OpenTelemetryAppender` is a Log4j2 [appender](https://logging.apache.org/log4j/2.x/manual/appenders.html) that can be used to forward log events to the [OpenTelemetry Log SDK](https:/open-telemetry/opentelemetry-java/tree/main/sdk/logs).

The following demonstrates how you might configure the appender in your `log4j.xml` configuration:

```xml
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN" packages="io.opentelemetry.instrumentation.log4j.v2_13_2">
<Appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} traceId: %X{trace_id} spanId: %X{span_id} 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>
```

Next, associate the `OpenTelemetryAppender` with a `SdkLogEmitterProvider` in your application:

```
SdkLogEmitterProvider logEmitterProvider =
SdkLogEmitterProvider.builder()
.setResource(Resource.create(...))
.addLogProcessor(...)
.build();
OpenTelemetryLog4j.initialize(logEmitterProvider);
```

**Note:** In order to initialize the `OpenTelemetryAppender` your application must depend on the
OpenTelemetry log sdk (`io.opentelemetry:opentelemetry-sdk-logs`).

In this example Log4j2 logs will be sent to both the console appender and
the `OpenTelemetryAppender`, which will drop the logs until `OpenTelemetryLog4j.initialize(..)` is
called. Once initialized, logs will be emitted to a `LogEmitter` obtained from
the `SdkLogEmitterProvider`.
5 changes: 5 additions & 0 deletions instrumentation/log4j/log4j-2.13.2/library/build.gradle.kts
Original file line number Diff line number Diff line change
Expand Up @@ -3,11 +3,16 @@ plugins {
}

dependencies {
compileOnly("io.opentelemetry:opentelemetry-sdk-logs")

library("org.apache.logging.log4j:log4j-core:2.13.2")

// Library instrumentation cannot be applied to 2.13.2 due to a bug in Log4J. The agent works
// around it.
testLibrary("org.apache.logging.log4j:log4j-core:2.13.3")

testImplementation(project(":instrumentation:log4j:log4j-2-common:testing"))
testImplementation("io.opentelemetry:opentelemetry-sdk-logs")

testImplementation("org.mockito:mockito-core")
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,102 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.instrumentation.log4j.v2_13_2;

import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.common.AttributesBuilder;
import io.opentelemetry.context.Context;
import io.opentelemetry.sdk.logs.LogBuilder;
import io.opentelemetry.sdk.logs.data.Severity;
import java.util.concurrent.TimeUnit;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.time.Instant;
import org.apache.logging.log4j.message.Message;

final class LogEventMapper {

// Visible for testing
static final AttributeKey<String> ATTR_THROWABLE_MESSAGE =
AttributeKey.stringKey("throwable.message");

/**
* Map the {@link LogEvent} data model onto the {@link LogBuilder}. Unmapped fields include:
*
* <ul>
* <li>Fully qualified class name - {@link LogEvent#getLoggerFqcn()}
* <li>Thread name - {@link LogEvent#getThreadName()}
* <li>Thread id - {@link LogEvent#getThreadId()}
* <li>Thread priority - {@link LogEvent#getThreadPriority()}
* <li>Thread priority - {@link LogEvent#getThreadPriority()}
* <li>Thrown details (stack trace, class name) - {@link LogEvent#getThrown()}
* <li>Marker - {@link LogEvent#getMarker()}
* <li>Nested diagnostic context - {@link LogEvent#getContextStack()}
* <li>Mapped diagnostic context - {@link LogEvent#getContextData()}
* </ul>
*/
static void mapLogEvent(LogBuilder builder, LogEvent logEvent) {
// TODO: map the LogEvent more completely when semantic conventions allow it
AttributesBuilder attributes = Attributes.builder();

// message
Message message = logEvent.getMessage();
if (message != null) {
builder.setBody(message.getFormattedMessage());
}

// time
Instant instant = logEvent.getInstant();
if (instant != null) {
builder.setEpoch(
TimeUnit.MILLISECONDS.toNanos(instant.getEpochMillisecond())
+ instant.getNanoOfMillisecond(),
TimeUnit.NANOSECONDS);
}

// level
Level level = logEvent.getLevel();
if (level != null) {
builder.setSeverity(levelToSeverity(level));
builder.setSeverityText(logEvent.getLevel().name());
}

// throwable
Throwable throwable = logEvent.getThrown();
if (throwable != null) {
attributes.put(ATTR_THROWABLE_MESSAGE, throwable.getMessage());
}

// span context
builder.setContext(Context.current());

builder.setAttributes(attributes.build());
}

private static Severity levelToSeverity(Level level) {
switch (level.getStandardLevel()) {
case ALL:
return Severity.TRACE;
case TRACE:
return Severity.TRACE2;
case DEBUG:
return Severity.DEBUG;
case INFO:
return Severity.INFO;
case WARN:
return Severity.WARN;
case ERROR:
return Severity.ERROR;
case FATAL:
return Severity.FATAL;
case OFF:
return Severity.UNDEFINED_SEVERITY_NUMBER;
}
return Severity.UNDEFINED_SEVERITY_NUMBER;
}

private LogEventMapper() {}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,78 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.instrumentation.log4j.v2_13_2;

import io.opentelemetry.sdk.logs.LogBuilder;
import io.opentelemetry.sdk.logs.SdkLogEmitterProvider;
import java.io.Serializable;
import java.util.concurrent.atomic.AtomicReference;
import org.apache.logging.log4j.core.Appender;
import org.apache.logging.log4j.core.Core;
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.Property;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.config.plugins.PluginBuilderFactory;

@Plugin(
name = OpenTelemetryAppender.PLUGIN_NAME,
category = Core.CATEGORY_NAME,
elementType = Appender.ELEMENT_TYPE)
public class OpenTelemetryAppender extends AbstractAppender {

static final String PLUGIN_NAME = "OpenTelemetry";

@PluginBuilderFactory
public static <B extends Builder<B>> B builder() {
return new Builder<B>().asBuilder();
}

static class Builder<B extends Builder<B>> extends AbstractAppender.Builder<B>
implements org.apache.logging.log4j.core.util.Builder<OpenTelemetryAppender> {

@Override
public OpenTelemetryAppender build() {
OpenTelemetryAppender appender =
new OpenTelemetryAppender(
getName(), getLayout(), getFilter(), isIgnoreExceptions(), getPropertyArray());
OpenTelemetryLog4j.registerInstance(appender);
return appender;
}
}

private final AtomicReference<SdkLogEmitterProvider> sdkLogEmitterProviderRef =
new AtomicReference<>();

private OpenTelemetryAppender(
String name,
Layout<? extends Serializable> layout,
Filter filter,
boolean ignoreExceptions,
Property[] properties) {
super(name, filter, layout, ignoreExceptions, properties);
}

@Override
public void append(LogEvent event) {
SdkLogEmitterProvider logEmitterProvider = sdkLogEmitterProviderRef.get();
if (logEmitterProvider == null) {
// appender hasn't been initialized
return;
}
LogBuilder builder =
logEmitterProvider.logEmitterBuilder(event.getLoggerName()).build().logBuilder();
LogEventMapper.mapLogEvent(builder, event);
builder.emit();
}

void initialize(SdkLogEmitterProvider sdkLogEmitterProvider) {
if (!sdkLogEmitterProviderRef.compareAndSet(null, sdkLogEmitterProvider)) {
throw new IllegalStateException("OpenTelemetryAppender has already been initialized.");
}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,64 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.instrumentation.log4j.v2_13_2;

import io.opentelemetry.sdk.logs.SdkLogEmitterProvider;
import java.util.ArrayList;
import java.util.List;
import javax.annotation.Nullable;
import javax.annotation.concurrent.GuardedBy;

public final class OpenTelemetryLog4j {

private static final Object lock = new Object();

@GuardedBy("lock")
private static SdkLogEmitterProvider sdkLogEmitterProvider;

@GuardedBy("lock")
@Nullable
private static Throwable initializeCaller;

@GuardedBy("lock")
private static final List<OpenTelemetryAppender> APPENDERS = new ArrayList<>();

public static void initialize(SdkLogEmitterProvider sdkLogEmitterProvider) {
List<OpenTelemetryAppender> instances;
synchronized (lock) {
if (OpenTelemetryLog4j.sdkLogEmitterProvider != null) {
throw new IllegalStateException(
"OpenTelemetryLog4j.initialize has already been called. OpenTelemetryLog4j.initialize "
+ "must be called only once. Previous invocation set to cause of this exception.",
initializeCaller);
}
OpenTelemetryLog4j.sdkLogEmitterProvider = sdkLogEmitterProvider;
instances = new ArrayList<>(APPENDERS);
initializeCaller = new Throwable();
}
for (OpenTelemetryAppender instance : instances) {
instance.initialize(sdkLogEmitterProvider);
}
}

static void registerInstance(OpenTelemetryAppender appender) {
synchronized (lock) {
if (sdkLogEmitterProvider != null) {
appender.initialize(sdkLogEmitterProvider);
}
APPENDERS.add(appender);
}
}

// Visible for testing
static void resetForTest() {
synchronized (lock) {
sdkLogEmitterProvider = null;
APPENDERS.clear();
}
}

private OpenTelemetryLog4j() {}
}
Loading

0 comments on commit 7510b0a

Please sign in to comment.