Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ability to instrument logs before OTel injection into OTel appenders #9798

Merged
merged 56 commits into from
Nov 17, 2023
Merged
Show file tree
Hide file tree
Changes from 18 commits
Commits
Show all changes
56 commits
Select commit Hold shift + click to select a range
5956df9
Ability to instrument logs before OTel injection into OTel appenders
jeanbisutti Nov 2, 2023
6943526
Fix Readme
jeanbisutti Nov 2, 2023
1c6776f
Readme improvement
jeanbisutti Nov 2, 2023
8c91e73
spotless
jeanbisutti Nov 2, 2023
086cddd
suppress warning
jeanbisutti Nov 2, 2023
65416b9
clean test
jeanbisutti Nov 2, 2023
65ab541
spotless
jeanbisutti Nov 2, 2023
718300c
Fix typo in Readme
jeanbisutti Nov 2, 2023
29e6023
Change default cache size
jeanbisutti Nov 3, 2023
7f092ba
Update instrumentation/log4j/log4j-appender-2.17/library/src/main/jav…
jeanbisutti Nov 3, 2023
1253bca
Code cleaning
jeanbisutti Nov 3, 2023
fedcd9e
Atomic boolean
jeanbisutti Nov 3, 2023
6fb666b
Remove unnecessary code
jeanbisutti Nov 3, 2023
c4662e7
FIx thread name and thread id values of replayed logs
jeanbisutti Nov 3, 2023
669d455
AtomicBoolean for Logback
jeanbisutti Nov 3, 2023
5e259bf
One Log4j test was not complete. FIx the test.
jeanbisutti Nov 3, 2023
e703d6e
Fix typo
jeanbisutti Nov 3, 2023
77acb85
Improve the tests and fix them
jeanbisutti Nov 3, 2023
b030088
Do not capture thread.id attribute with Logback instrumentation library
jeanbisutti Nov 3, 2023
32ac4b1
Update comment
jeanbisutti Nov 13, 2023
c05c785
Update serial version uid
jeanbisutti Nov 13, 2023
316ac45
Remove reference to LogEvent
jeanbisutti Nov 13, 2023
1f263fd
Update instrumentation/log4j/log4j-appender-2.17/library/src/main/jav…
jeanbisutti Nov 13, 2023
5a936f9
Add comment
jeanbisutti Nov 13, 2023
5daf6d1
Update instrumentation/log4j/log4j-appender-2.17/library/src/main/jav…
jeanbisutti Nov 14, 2023
e1656ab
Update instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/j…
jeanbisutti Nov 14, 2023
6bef8a6
spotless
jeanbisutti Nov 14, 2023
9e8fdd0
Update instrumentation/logback/logback-appender-1.0/library/src/main/…
jeanbisutti Nov 14, 2023
cae8936
poll update
jeanbisutti Nov 14, 2023
b737463
static import otel assertions
jeanbisutti Nov 14, 2023
4f4a275
comment added
jeanbisutti Nov 14, 2023
8712a4b
fix compilation issue
jeanbisutti Nov 14, 2023
cec3877
move nested class at the bottom
jeanbisutti Nov 14, 2023
43f9376
Document race condition
jeanbisutti Nov 15, 2023
2e32147
Update instrumentation/log4j/log4j-appender-2.17/library/src/main/jav…
jeanbisutti Nov 15, 2023
5497b5d
Update instrumentation/log4j/log4j-appender-2.17/library/src/main/jav…
jeanbisutti Nov 15, 2023
6a6ed85
Refactor tests
jeanbisutti Nov 15, 2023
0a73658
Merge branch 'otel-appender-cache' of https://github.com/jeanbisutti/…
jeanbisutti Nov 15, 2023
c073295
Merge branch 'main' into otel-appender-cache
jeanbisutti Nov 16, 2023
efc39db
Fix merge conflicts
jeanbisutti Nov 16, 2023
4a52819
Rename configuration property
jeanbisutti Nov 16, 2023
dcb0530
Update instrumentation/log4j/log4j-appender-2.17/library/src/main/jav…
jeanbisutti Nov 16, 2023
352f843
Renaming
jeanbisutti Nov 16, 2023
a534355
Add comment
jeanbisutti Nov 16, 2023
8ecbde1
Static import
jeanbisutti Nov 16, 2023
08d85a9
final
jeanbisutti Nov 16, 2023
839216a
Fix merge issue
jeanbisutti Nov 16, 2023
54fe766
Merge remote-tracking branch 'upstream/main' into otel-appender-cache
trask Nov 17, 2023
fcb95be
use readwritelock
trask Nov 17, 2023
9f473db
Fix tests
jeanbisutti Nov 17, 2023
d2eff96
Create queue in the start() method + renaming
jeanbisutti Nov 17, 2023
55c3367
remove local variable (version on main)
jeanbisutti Nov 17, 2023
fe088b8
Locking for Log4j 2
jeanbisutti Nov 17, 2023
dbb3b76
fix spotless
jeanbisutti Nov 17, 2023
e3168ba
Fix test latest deps
trask Nov 17, 2023
18d3386
optimization
trask Nov 17, 2023
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -27,10 +27,12 @@ public final class Log4jHelper {

private static final LogEventMapper<Map<String, String>> mapper;

private static final boolean captureExperimentalAttributes;

static {
InstrumentationConfig config = InstrumentationConfig.get();

boolean captureExperimentalAttributes =
captureExperimentalAttributes =
config.getBoolean("otel.instrumentation.log4j-appender.experimental-log-attributes", false);
boolean captureMapMessageAttributes =
config.getBoolean(
Expand Down Expand Up @@ -66,7 +68,21 @@ public static void capture(
.build()
.logRecordBuilder();
Map<String, String> contextData = ThreadContext.getImmutableContext();
mapper.mapLogEvent(builder, message, level, marker, throwable, contextData);

if (captureExperimentalAttributes) {
Thread currentThread = Thread.currentThread();
mapper.mapLogEvent(
builder,
message,
level,
marker,
throwable,
contextData,
currentThread.getName(),
currentThread.getId());
} else {
mapper.mapLogEvent(builder, message, level, marker, throwable, contextData, null, -1);
}
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
builder.setTimestamp(Instant.now());
builder.emit();
}
Expand Down
13 changes: 7 additions & 6 deletions instrumentation/log4j/log4j-appender-2.17/library/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -93,11 +93,12 @@ Setting can be configured as XML attributes, for example:

The available settings are:

| XML Attribute | Type | Default | Description |
| ------------------------------- | ------- | ------- | --------------------------------------------------------------------------------------------------------------------- |
| `captureExperimentalAttributes` | Boolean | `false` | Enable the capture of experimental span attributes `thread.name` and `thread.id`. |
| `captureMapMessageAttributes` | Boolean | `false` | Enable the capture of `MapMessage` attributes. |
| `captureMarkerAttribute;` | Boolean | `false` | Enable the capture of Log4j markers as attributes. |
| `captureContextDataAttributes` | String | | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. |
| XML Attribute | Type | Default | Description |
|---------------------------------|---------|---------|------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|
| `captureExperimentalAttributes` | Boolean | `false` | Enable the capture of experimental span attributes `thread.name` and `thread.id`. |
| `captureMapMessageAttributes` | Boolean | `false` | Enable the capture of `MapMessage` attributes. |
| `captureMarkerAttribute;` | Boolean | `false` | Enable the capture of Log4j markers as attributes. |
| `captureContextDataAttributes` | String | | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. |
| `firstLogsCacheSize` | Integer | 1000 | Log telemetry is emitted after the initialization of the OpenTelemetry Log4j appender with an OpenTelemetry object. This setting allows you to modify the size of the cache used to replay the first logs. |
trask marked this conversation as resolved.
Show resolved Hide resolved

[source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.md#source-code-attributes
Original file line number Diff line number Diff line change
@@ -0,0 +1,209 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.instrumentation.log4j.appender.v2_17;

import java.util.Map;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Marker;
import org.apache.logging.log4j.ThreadContext;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.impl.ThrowableProxy;
import org.apache.logging.log4j.core.time.Instant;
import org.apache.logging.log4j.message.Message;
import org.apache.logging.log4j.message.StringMapMessage;
import org.apache.logging.log4j.message.StructuredDataMessage;
import org.apache.logging.log4j.util.ReadOnlyStringMap;

class LogEventToReplay implements LogEvent {

private static final long serialVersionUID = -3639807661256104630L;
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved

private final LogEvent logEvent;
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
private final String loggerName;
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
private final Message message;
private final Level level;
private final Instant instant;
private final Throwable thrown;
private final Marker marker;
private final ReadOnlyStringMap contextData;
private final String threadName;
private final long threadId;

// Log4j 2 seems to reuse Message objects
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
private static class MessageCopy implements Message {
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved

private static final long serialVersionUID = 6921483958779195777L;
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
private final String formattedMessage;
private final String format;
private final Object[] parameters;
private final Throwable throwable;

public MessageCopy(Message message) {
this.formattedMessage = message.getFormattedMessage();
this.format = message.getFormat();
this.parameters = message.getParameters();
this.throwable = message.getThrowable();
}

@Override
public String getFormattedMessage() {
return formattedMessage;
}

@Override
public String getFormat() {
return format;
}

@Override
public Object[] getParameters() {
return parameters;
}

@Override
public Throwable getThrowable() {
return throwable;
}
}

LogEventToReplay(LogEvent logEvent) {
this.logEvent = logEvent;
this.loggerName = logEvent.getLoggerName();
Message messageOrigin = logEvent.getMessage();
if (messageOrigin instanceof StructuredDataMessage) {
StructuredDataMessage structuredDataMessage = (StructuredDataMessage) messageOrigin;
trask marked this conversation as resolved.
Show resolved Hide resolved
this.message =
new StructuredDataMessage(
structuredDataMessage.getId(),
structuredDataMessage.getFormat(),
structuredDataMessage.getType(),
structuredDataMessage.getData());
} else if (messageOrigin instanceof StringMapMessage) {
this.message = messageOrigin;
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
} else {
this.message = new MessageCopy(logEvent.getMessage());
}

this.level = logEvent.getLevel();
this.instant = logEvent.getInstant();
this.thrown = logEvent.getThrown();
this.marker = logEvent.getMarker();
this.contextData = logEvent.getContextData();
this.threadName = logEvent.getThreadName();
this.threadId = logEvent.getThreadId();
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
}

@Override
public LogEvent toImmutable() {
trask marked this conversation as resolved.
Show resolved Hide resolved
return logEvent.toImmutable();
}

@SuppressWarnings("deprecation") // Delegate
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
@Override
public Map<String, String> getContextMap() {
return logEvent.getContextMap();
}

@Override
public ReadOnlyStringMap getContextData() {
return contextData;
}

@Override
public ThreadContext.ContextStack getContextStack() {
return logEvent.getContextStack();
}

@Override
public String getLoggerFqcn() {
return logEvent.getLoggerFqcn();
}

@Override
public Level getLevel() {
return level;
}

@Override
public String getLoggerName() {
return loggerName;
}

@Override
public Marker getMarker() {
return marker;
}

@Override
public Message getMessage() {
return message;
}

@Override
public long getTimeMillis() {
return logEvent.getTimeMillis();
}

@Override
public Instant getInstant() {
return instant;
}

@Override
public StackTraceElement getSource() {
return logEvent.getSource();
}

@Override
public String getThreadName() {
return threadName;
}

@Override
public long getThreadId() {
return threadId;
}

@Override
public int getThreadPriority() {
return logEvent.getThreadPriority();
}

@Override
public Throwable getThrown() {
return thrown;
}

@Override
public ThrowableProxy getThrownProxy() {
return logEvent.getThrownProxy();
}

@Override
public boolean isEndOfBatch() {
return logEvent.isEndOfBatch();
}

@Override
public boolean isIncludeLocation() {
return logEvent.isIncludeLocation();
}

@Override
public void setEndOfBatch(boolean endOfBatch) {
logEvent.setEndOfBatch(endOfBatch);
}

@Override
public void setIncludeLocation(boolean locationRequired) {
logEvent.setIncludeLocation(locationRequired);
}

@Override
public long getNanoTime() {
return logEvent.getNanoTime();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -15,7 +15,10 @@
import java.io.Serializable;
import java.util.Arrays;
import java.util.List;
import java.util.concurrent.ArrayBlockingQueue;
import java.util.concurrent.BlockingQueue;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.function.BiConsumer;
import java.util.stream.Collectors;
import javax.annotation.Nullable;
Expand Down Expand Up @@ -48,6 +51,10 @@ public class OpenTelemetryAppender extends AbstractAppender {
private final LogEventMapper<ReadOnlyStringMap> mapper;
private volatile OpenTelemetry openTelemetry;

private BlockingQueue<LogEventToReplay> eventsToReplay = new ArrayBlockingQueue<>(1000);
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved

private final AtomicBoolean logCacheWarningDisplayed = new AtomicBoolean();
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved

/**
* Installs the {@code openTelemetry} instance on any {@link OpenTelemetryAppender}s identified in
* the {@link LoggerContext}.
Expand Down Expand Up @@ -82,6 +89,7 @@ public static class Builder<B extends Builder<B>> extends AbstractAppender.Build
@PluginBuilderAttribute private boolean captureMapMessageAttributes;
@PluginBuilderAttribute private boolean captureMarkerAttribute;
@PluginBuilderAttribute private String captureContextDataAttributes;
@PluginBuilderAttribute private int firstLogsCacheSize;

@Nullable private OpenTelemetry openTelemetry;

Expand Down Expand Up @@ -121,6 +129,17 @@ public B setCaptureContextDataAttributes(String captureContextDataAttributes) {
return asBuilder();
}

/**
* Log telemetry is emitted after the initialization of the OpenTelemetry Logback appender with
* an {@link OpenTelemetry} object. This setting allows you to modify the size of the cache used
* to replay the first logs.
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
*/
@CanIgnoreReturnValue
public B setFirstLogsCacheSize(int firstLogsCacheSize) {
this.firstLogsCacheSize = firstLogsCacheSize;
return asBuilder();
}

/** Configures the {@link OpenTelemetry} used to append logs. */
@CanIgnoreReturnValue
public B setOpenTelemetry(OpenTelemetry openTelemetry) {
Expand All @@ -144,6 +163,7 @@ public OpenTelemetryAppender build() {
captureMapMessageAttributes,
captureMarkerAttribute,
captureContextDataAttributes,
firstLogsCacheSize,
openTelemetry);
}
}
Expand All @@ -158,17 +178,23 @@ private OpenTelemetryAppender(
boolean captureMapMessageAttributes,
boolean captureMarkerAttribute,
String captureContextDataAttributes,
int firstLogsCacheSize,
OpenTelemetry openTelemetry) {

super(name, filter, layout, ignoreExceptions, properties);
List<String> captureContextDataAttributesAsList =
splitAndFilterBlanksAndNulls(captureContextDataAttributes);
this.mapper =
new LogEventMapper<>(
ContextDataAccessorImpl.INSTANCE,
captureExperimentalAttributes,
captureMapMessageAttributes,
captureMarkerAttribute,
splitAndFilterBlanksAndNulls(captureContextDataAttributes));
captureContextDataAttributesAsList);
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
this.openTelemetry = openTelemetry;
if (firstLogsCacheSize != 0) {
this.eventsToReplay = new ArrayBlockingQueue<>(firstLogsCacheSize);
}
}

private static List<String> splitAndFilterBlanksAndNulls(String value) {
Expand All @@ -187,10 +213,30 @@ private static List<String> splitAndFilterBlanksAndNulls(String value) {
*/
public void setOpenTelemetry(OpenTelemetry openTelemetry) {
this.openTelemetry = openTelemetry;
while (!eventsToReplay.isEmpty()) {
try {
LogEvent eventToReplay = eventsToReplay.poll(10, TimeUnit.MILLISECONDS);
append(eventToReplay);
} catch (InterruptedException e) {
// Ignore
}
}
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
}

@SuppressWarnings("SystemOut")
@Override
public void append(LogEvent event) {
if (openTelemetry == OpenTelemetry.noop()) {
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
if (eventsToReplay.remainingCapacity() > 0) {
LogEventToReplay logEventToReplay = new LogEventToReplay(event);
eventsToReplay.offer(logEventToReplay);
} else if (!logCacheWarningDisplayed.getAndSet(true)) {
System.err.println(
jeanbisutti marked this conversation as resolved.
Show resolved Hide resolved
"Log cache size of the OpenTelemetry appender is too small. firstLogsCacheSize value has to be increased");
}
return;
}

String instrumentationName = event.getLoggerName();
if (instrumentationName == null || instrumentationName.isEmpty()) {
instrumentationName = "ROOT";
Expand All @@ -209,7 +255,9 @@ public void append(LogEvent event) {
event.getLevel(),
event.getMarker(),
event.getThrown(),
contextData);
contextData,
event.getThreadName(),
event.getThreadId());

Instant timestamp = event.getInstant();
if (timestamp != null) {
Expand Down
Loading
Loading