Prototype Log4j2 Appender #4375
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -3,11 +3,15 @@ plugins { | |
| } | ||
|
|
||
| dependencies { | ||
| api("io.opentelemetry:opentelemetry-sdk-logs:1.9.0-alpha") | ||
|
There was a problem hiding this comment. That will make all clients of this library instrumentation depend on SDK. I assume all users must depend only on API. There was a problem hiding this comment. Users need to call There was a problem hiding this comment. But this reminds me that I need to update the readme to show usage! There was a problem hiding this comment. @iNikem Yeah - we have open-telemetry/opentelemetry-java#3807 to track fixing this. There was a problem hiding this comment. Sleeping on this, I realized we can keep this code here by making this There was a problem hiding this comment. Though I still think it might be simpler to continue to prototype with the code in the SDK repo. What do you think? There was a problem hiding this comment. I'm definitely wary about adding an API API to support this. I think There was a problem hiding this comment.
Prototyping in the SDK has the advantage that the SDK and the appender can develop in lockstep, rather than the appender waiting on SDK releases, which is nice. But I think a lot of the SDK flux has been flushed out (of course assuming no significant changes to the experimental log spec) and so I don't expect to see much value from having the appender in the SDK. |
||
|
|
||
| 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("org.mockito:mockito-core") | ||
| } | ||
| Original file line number | Diff line number | Diff line change | ||||
|---|---|---|---|---|---|---|
| @@ -0,0 +1,141 @@ | ||||||
| /* | ||||||
| * Copyright The OpenTelemetry Authors | ||||||
| * SPDX-License-Identifier: Apache-2.0 | ||||||
| */ | ||||||
|
|
||||||
| package io.opentelemetry.instrumentation.log4j.v2_13_2; | ||||||
|
|
||||||
| import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.SPAN_ID; | ||||||
| import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.TRACE_FLAGS; | ||||||
| import static io.opentelemetry.instrumentation.api.log.LoggingContextConstants.TRACE_ID; | ||||||
|
|
||||||
| import io.opentelemetry.api.common.AttributeKey; | ||||||
| import io.opentelemetry.api.common.Attributes; | ||||||
| import io.opentelemetry.api.common.AttributesBuilder; | ||||||
| import io.opentelemetry.api.trace.Span; | ||||||
| import io.opentelemetry.api.trace.SpanContext; | ||||||
| import io.opentelemetry.api.trace.SpanId; | ||||||
| import io.opentelemetry.api.trace.TraceFlags; | ||||||
| import io.opentelemetry.api.trace.TraceId; | ||||||
| import io.opentelemetry.api.trace.TraceState; | ||||||
| import io.opentelemetry.context.Context; | ||||||
| import io.opentelemetry.sdk.logs.LogBuilder; | ||||||
| import io.opentelemetry.sdk.logs.data.Severity; | ||||||
| import java.util.Collections; | ||||||
| import java.util.HashMap; | ||||||
| import java.util.List; | ||||||
| import java.util.Map; | ||||||
| import java.util.concurrent.TimeUnit; | ||||||
| import org.apache.logging.log4j.Level; | ||||||
| import org.apache.logging.log4j.Marker; | ||||||
| import org.apache.logging.log4j.core.LogEvent; | ||||||
| import org.apache.logging.log4j.message.Message; | ||||||
| import org.apache.logging.log4j.util.ReadOnlyStringMap; | ||||||
|
|
||||||
| final class LogEventMapper { | ||||||
|
|
||||||
| // Visible for testing | ||||||
| static final AttributeKey<String> ATTR_LOGGER_NAME = AttributeKey.stringKey("logger.name"); | ||||||
|
There was a problem hiding this comment. I don't see any semantic conventions for logs defined yet, can we leave them out until they're defined? There was a problem hiding this comment. If leaving any, I guess logger.name, throwable.name, throwable.message are the only ones I'd keep as they may be necessary for playing with a prototype, but others seem too detailed, or unclear (e.g., I'm not familiar with term There was a problem hiding this comment. ndc = Nested Diagnostic Context Nested diagnostic context is thread context that acts like a stack. You push items onto it, and pop them off. Mapped diagnostic context is thread context that acts like a map. Frankly, I haven't used Nested Diagnostic Context, and have only used Mapped Diagnostic Context in a limited way in applications I've written. I took the stance of making sure that all data in the log4j2 data model somehow was mapped into the otel log data model. You're suggesting the opposite, where only a limited part of the log4j2 data model is mapped. I see pros and cons of each stance:
Personally, I prefer the full mapping approach published in an "alpha" artifact. Definitely interested in other perspectives on this though. There was a problem hiding this comment. I've seen it's easier to add an attribute and not really go anywhere in the spec with it than the opposite. By not including too much, we can hear about what users really need and then build the spec around it, rather than being ad-hoc. While I don't like to disappoint folks, actually hearing about that disappointment is very valuable feedback. There was a problem hiding this comment. That resonates with me. Also, if we were to do a complete mapping and the required semantic conventions never materialized, we may have to pull support for that mapping, which would be an unpleasant breaking change for users. Updated to a minimalist mapping in new commit. |
||||||
| static final AttributeKey<String> ATTR_THREAD_NAME = AttributeKey.stringKey("thread.name"); | ||||||
| static final AttributeKey<Long> ATTR_THREAD_ID = AttributeKey.longKey("thread.id"); | ||||||
| static final AttributeKey<Long> ATTR_THREAD_PRIORITY = AttributeKey.longKey("thread.priority"); | ||||||
| static final AttributeKey<String> ATTR_THROWABLE_NAME = AttributeKey.stringKey("throwable.name"); | ||||||
| static final AttributeKey<String> ATTR_THROWABLE_MESSAGE = | ||||||
| AttributeKey.stringKey("throwable.message"); | ||||||
| static final AttributeKey<List<String>> ATTR_NDC = AttributeKey.stringArrayKey("ndc"); | ||||||
| static final AttributeKey<String> ATTR_FQCN = AttributeKey.stringKey("fqcn"); | ||||||
| static final AttributeKey<String> ATTR_MARKER = AttributeKey.stringKey("marker"); | ||||||
|
|
||||||
| private static final Map<Level, Severity> LEVEL_SEVERITY_MAP; | ||||||
|
|
||||||
| static { | ||||||
| Map<Level, Severity> levelSeverityMap = new HashMap<>(); | ||||||
| levelSeverityMap.put(Level.ALL, Severity.TRACE); | ||||||
jack-berg marked this conversation as resolved.
Show resolved
Hide resolved
|
||||||
| levelSeverityMap.put(Level.TRACE, Severity.TRACE2); | ||||||
| levelSeverityMap.put(Level.DEBUG, Severity.DEBUG); | ||||||
| levelSeverityMap.put(Level.INFO, Severity.INFO); | ||||||
| levelSeverityMap.put(Level.WARN, Severity.WARN); | ||||||
| levelSeverityMap.put(Level.ERROR, Severity.ERROR); | ||||||
| levelSeverityMap.put(Level.FATAL, Severity.FATAL); | ||||||
| LEVEL_SEVERITY_MAP = Collections.unmodifiableMap(levelSeverityMap); | ||||||
| } | ||||||
|
|
||||||
| static void mapLogEvent(LogBuilder builder, LogEvent logEvent) { | ||||||
| AttributesBuilder attributes = Attributes.builder(); | ||||||
|
|
||||||
| // message | ||||||
| Message message = logEvent.getMessage(); | ||||||
| if (message != null) { | ||||||
| builder.setBody(message.getFormattedMessage()); | ||||||
| } | ||||||
|
|
||||||
| // time | ||||||
| builder.setEpoch(logEvent.getNanoTime(), TimeUnit.NANOSECONDS); | ||||||
jack-berg marked this conversation as resolved.
Show resolved
Hide resolved
|
||||||
|
|
||||||
| // level | ||||||
| Level level = logEvent.getLevel(); | ||||||
| if (level != null) { | ||||||
| builder.setSeverity( | ||||||
| LEVEL_SEVERITY_MAP.getOrDefault(level, Severity.UNDEFINED_SEVERITY_NUMBER)); | ||||||
| builder.setSeverityText(logEvent.getLevel().name()); | ||||||
|
There was a problem hiding this comment.
Suggested change
And shouldn't this text come from our severity and not logging framework level? There was a problem hiding this comment. From the spec, the severity text field "is the original string representation of the severity as it is known at the source". But this does bring up the point that I have made a number of subjective decisions in mapping between the Log4j2 LogEvent data model and the otel log data model. Please take a close look at the attribute name's I've chosen for various things and let me know if you agree / disagree. |
||||||
| } | ||||||
|
|
||||||
| // logger | ||||||
| attributes.put(ATTR_LOGGER_NAME, logEvent.getLoggerName()); | ||||||
|
|
||||||
| // fully qualified class name | ||||||
|
There was a problem hiding this comment. Hmm - I wonder what this is, I thought the only "class name" type of thing is the logger name, if you derive it from a class. Otherwise each log message would be quite expensive |
||||||
| attributes.put(ATTR_FQCN, logEvent.getLoggerFqcn()); | ||||||
|
|
||||||
| // thread | ||||||
| attributes.put(ATTR_THREAD_NAME, logEvent.getThreadName()); | ||||||
| attributes.put(ATTR_THREAD_ID, logEvent.getThreadId()); | ||||||
| attributes.put(ATTR_THREAD_PRIORITY, logEvent.getThreadPriority()); | ||||||
|
|
||||||
| // throwable | ||||||
| Throwable throwable = logEvent.getThrown(); | ||||||
| if (throwable != null) { | ||||||
| attributes.put(ATTR_THROWABLE_NAME, throwable.getClass().getName()); | ||||||
| attributes.put(ATTR_THROWABLE_MESSAGE, throwable.getMessage()); | ||||||
| } | ||||||
|
|
||||||
| // marker | ||||||
| Marker marker = logEvent.getMarker(); | ||||||
| if (marker != null) { | ||||||
| attributes.put(ATTR_MARKER, marker.getName()); | ||||||
| } | ||||||
|
|
||||||
| // nested diagnostic context | ||||||
| List<String> contextStackList = logEvent.getContextStack().asList(); | ||||||
| if (contextStackList.size() > 0) { | ||||||
| attributes.put(ATTR_NDC, contextStackList); | ||||||
| } | ||||||
|
|
||||||
| // mapped diagnostic context (included span context) | ||||||
| ReadOnlyStringMap contextData = logEvent.getContextData(); | ||||||
| if (contextData != null) { | ||||||
| Map<String, String> contextMap = contextData.toMap(); | ||||||
| if (contextMap != null) { | ||||||
| String traceId = | ||||||
|
There was a problem hiding this comment. I would like to first try with There was a problem hiding this comment. Sounds like a good plan. |
||||||
| contextMap.containsKey(TRACE_ID) ? contextMap.remove(TRACE_ID) : TraceId.getInvalid(); | ||||||
| String spanId = | ||||||
| contextMap.containsKey(SPAN_ID) ? contextMap.remove(SPAN_ID) : SpanId.getInvalid(); | ||||||
| TraceFlags traceFlags = | ||||||
| contextMap.containsKey(TRACE_FLAGS) | ||||||
| ? TraceFlags.fromHex(contextMap.remove(TRACE_FLAGS), 0) | ||||||
| : TraceFlags.getDefault(); | ||||||
| Context context = | ||||||
| Context.root() | ||||||
| .with( | ||||||
| Span.wrap( | ||||||
| SpanContext.create(traceId, spanId, traceFlags, TraceState.getDefault()))); | ||||||
| builder.setContext(context); | ||||||
|
|
||||||
| contextMap.forEach(attributes::put); | ||||||
|
There was a problem hiding this comment. I don't think we should fill arbitrary attributes, I don't think we ever do anything similar for spans There was a problem hiding this comment. Kind of related to the the conversation about doing a complete mapping or not. Not filling arbitrary attributes from mapped diagnostic context is limiting the usefulness of the log4j2 api. It means if you want to use otel logs in a more "machine generated events" type of way, that you'd want to use the otel log sdk in your application instead of the log4j2 api. There was a problem hiding this comment. I think we'd generally use baggage for more arbitrary attributes? Though we haven't even specced it for spans. But I'd still suggest keeping things smaller for now to make sure the spec grows rather than going all in |
||||||
| } | ||||||
| } | ||||||
|
|
||||||
| builder.setAttributes(attributes.build()); | ||||||
| } | ||||||
|
|
||||||
| private LogEventMapper() {} | ||||||
| } | ||||||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,76 @@ | ||
| /* | ||
| * 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.LogEmitter; | ||
| 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 newBuilder() { | ||
jack-berg marked this conversation as resolved.
Show resolved
Hide resolved
|
||
| return new Builder<B>().asBuilder(); | ||
| } | ||
|
|
||
| public static class Builder<B extends Builder<B>> extends AbstractAppender.Builder<B> | ||
jack-berg marked this conversation as resolved.
Show resolved
Hide resolved
|
||
| 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<LogEmitter> logEmitterRef = 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) { | ||
| LogEmitter logEmitter = logEmitterRef.get(); | ||
| if (logEmitter == null) { | ||
| // appender hasn't been initialized | ||
| return; | ||
| } | ||
| LogBuilder builder = logEmitter.logBuilder(); | ||
| LogEventMapper.mapLogEvent(builder, event); | ||
| builder.emit(); | ||
| } | ||
|
|
||
| void initialize(LogEmitter logEmitter) { | ||
| if (!logEmitterRef.compareAndSet(null, logEmitter)) { | ||
| throw new IllegalStateException("OpenTelemetryAppender has already been initialized."); | ||
| } | ||
| } | ||
| } | ||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,59 @@ | ||
| /* | ||
| * Copyright The OpenTelemetry Authors | ||
| * SPDX-License-Identifier: Apache-2.0 | ||
| */ | ||
|
|
||
| package io.opentelemetry.instrumentation.log4j.v2_13_2; | ||
|
|
||
| import io.opentelemetry.sdk.logs.LogEmitter; | ||
| import io.opentelemetry.sdk.logs.SdkLogEmitterProvider; | ||
| import java.util.ArrayList; | ||
| import java.util.List; | ||
| import javax.annotation.concurrent.GuardedBy; | ||
|
|
||
| public final class OpenTelemetryLog4j { | ||
|
|
||
| private static final Object LOCK = new Object(); | ||
jack-berg marked this conversation as resolved.
Show resolved
Hide resolved
|
||
|
|
||
| @GuardedBy("LOCK") | ||
| private static LogEmitter logEmitter; | ||
|
|
||
| @GuardedBy("LOCK") | ||
| private static final List<OpenTelemetryAppender> APPENDERS = new ArrayList<>(); | ||
|
|
||
| public static void initialize(SdkLogEmitterProvider sdkLogEmitterProvider) { | ||
|
There was a problem hiding this comment. How is this going to work as a javaagent instrumentation? In the agent we keep all the SDK classes hidden in the agent classloader, they're basically unavailable from the application classloader. The agent won't be able to register its emitterProvider in the application's There was a problem hiding this comment. We'll need it - open-telemetry/opentelemetry-java#3807 There was a problem hiding this comment. Took a stab at extracting out the appender API here. |
||
| LogEmitter logEmitter; | ||
| List<OpenTelemetryAppender> instances; | ||
| synchronized (LOCK) { | ||
| if (OpenTelemetryLog4j.logEmitter != null) { | ||
| throw new IllegalStateException("SdkLogEmitterProvider has already been set."); | ||
| } | ||
| logEmitter = | ||
| sdkLogEmitterProvider.logEmitterBuilder(OpenTelemetryLog4j.class.getName()).build(); | ||
| OpenTelemetryLog4j.logEmitter = logEmitter; | ||
| instances = new ArrayList<>(APPENDERS); | ||
| } | ||
| for (OpenTelemetryAppender instance : instances) { | ||
| instance.initialize(logEmitter); | ||
| } | ||
| } | ||
|
|
||
| static void registerInstance(OpenTelemetryAppender appender) { | ||
| synchronized (LOCK) { | ||
| if (logEmitter != null) { | ||
| appender.initialize(logEmitter); | ||
| } | ||
| APPENDERS.add(appender); | ||
| } | ||
| } | ||
|
|
||
| // Visible for testing | ||
| static void resetForTest() { | ||
| synchronized (LOCK) { | ||
| logEmitter = null; | ||
| APPENDERS.clear(); | ||
| } | ||
| } | ||
|
|
||
| private OpenTelemetryLog4j() {} | ||
| } | ||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Don't think we need version here since we apply BOM for io.opentelemetry. Similar for all usages
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yes, I'm just waiting for this project to update its BOM dependency on 1.9.0 and then will drop the version here.