Skip to content

Commit 6cff4f5

Browse files
lauritlaurit
committed
Log4j2: add option to fill code attributes
1 parent c90dd97 commit 6cff4f5

File tree

14 files changed

+227
-94
lines changed

14 files changed

+227
-94
lines changed

‎instrumentation/log4j/log4j-appender-2.17/javaagent/README.md‎

Lines changed: 9 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,11 @@
11
# Settings for the Log4j Appender instrumentation
22

3-
| System property | Type | Default | Description |
4-
|-----------------------------------------------------------------------------------| ------- | ------- |-----------------------------------------------------------------------------------------------------------------------|
5-
| `otel.instrumentation.log4j-appender.experimental-log-attributes` | Boolean | `false` | Enable the capture of experimental log attributes `thread.name` and `thread.id`. |
6-
| `otel.instrumentation.log4j-appender.experimental.capture-map-message-attributes` | Boolean | `false` | Enable the capture of `MapMessage` attributes. |
7-
| `otel.instrumentation.log4j-appender.experimental.capture-marker-attribute` | Boolean | `false` | Enable the capture of Log4j markers as attributes. |
8-
| `otel.instrumentation.log4j-appender.experimental.capture-mdc-attributes` | String | | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. |
3+
| System property | Type | Default | Description |
4+
|-----------------------------------------------------------------------------------|---------|---------|-----------------------------------------------------------------------------------------------------------------------------------------------|
5+
| `otel.instrumentation.log4j-appender.experimental-log-attributes` | Boolean | `false` | Enable the capture of experimental log attributes `thread.name` and `thread.id`. |
6+
| `otel.instrumentation.log4j-appender.experimental.capture-code-attributes` | Boolean | `false` | Enable the capture of [source code attributes]. Note that capturing source code attributes at logging sites might add a performance overhead. |
7+
| `otel.instrumentation.log4j-appender.experimental.capture-map-message-attributes` | Boolean | `false` | Enable the capture of `MapMessage` attributes. |
8+
| `otel.instrumentation.log4j-appender.experimental.capture-marker-attribute` | Boolean | `false` | Enable the capture of Log4j markers as attributes. |
9+
| `otel.instrumentation.log4j-appender.experimental.capture-mdc-attributes` | String | | Comma separated list of context data attributes to capture. Use the wildcard character `*` to capture all attributes. |
10+
11+
[source code attributes]: https://github.com/open-telemetry/semantic-conventions/blob/main/docs/general/attributes.md#source-code-attributes

‎instrumentation/log4j/log4j-appender-2.17/javaagent/build.gradle.kts‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -56,9 +56,10 @@ tasks {
5656

5757
tasks.withType<Test>().configureEach {
5858
// TODO run tests both with and without experimental log attributes
59+
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental-log-attributes=true")
60+
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-code-attributes=true")
5961
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-map-message-attributes=true")
6062
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-mdc-attributes=*")
61-
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental-log-attributes=true")
6263
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-marker-attribute=true")
6364
}
6465

‎instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jAppenderInstrumentation.java‎

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -73,14 +73,16 @@ public static void methodEnter(
7373
@Advice.This Logger logger,
7474
@Advice.Argument(0) Level level,
7575
@Advice.Argument(1) Marker marker,
76+
@Advice.Argument(2) String loggerClassName,
77+
@Advice.Argument(3) StackTraceElement location,
7678
@Advice.Argument(4) Message message,
7779
@Advice.Argument(5) Throwable t,
7880
@Advice.Local("otelCallDepth") CallDepth callDepth) {
7981
// need to track call depth across all loggers in order to avoid double capture when one
8082
// logging framework delegates to another
8183
callDepth = CallDepth.forClass(LoggerProvider.class);
8284
if (callDepth.getAndIncrement() == 0) {
83-
Log4jHelper.capture(logger, level, marker, message, t);
85+
Log4jHelper.capture(logger, loggerClassName, location, level, marker, message, t);
8486
}
8587
}
8688

@@ -96,6 +98,7 @@ public static class LogMessageAdvice {
9698
@Advice.OnMethodEnter(suppress = Throwable.class)
9799
public static void methodEnter(
98100
@Advice.This Logger logger,
101+
@Advice.Argument(0) String loggerClassName,
99102
@Advice.Argument(1) Level level,
100103
@Advice.Argument(2) Marker marker,
101104
@Advice.Argument(3) Message message,
@@ -105,7 +108,7 @@ public static void methodEnter(
105108
// logging framework delegates to another
106109
callDepth = CallDepth.forClass(LoggerProvider.class);
107110
if (callDepth.getAndIncrement() == 0) {
108-
Log4jHelper.capture(logger, level, marker, message, t);
111+
Log4jHelper.capture(logger, loggerClassName, null, level, marker, message, t);
109112
}
110113
}
111114

‎instrumentation/log4j/log4j-appender-2.17/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v2_17/Log4jHelper.java‎

Lines changed: 14 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,7 @@
2424
import org.apache.logging.log4j.Marker;
2525
import org.apache.logging.log4j.ThreadContext;
2626
import org.apache.logging.log4j.message.Message;
27+
import org.apache.logging.log4j.util.StackLocator;
2728

2829
public final class Log4jHelper {
2930

@@ -36,6 +37,9 @@ public final class Log4jHelper {
3637

3738
captureExperimentalAttributes =
3839
config.getBoolean("otel.instrumentation.log4j-appender.experimental-log-attributes", false);
40+
boolean captureCodeAttributes =
41+
config.getBoolean(
42+
"otel.instrumentation.log4j-appender.experimental.capture-code-attributes", false);
3943
boolean captureMapMessageAttributes =
4044
config.getBoolean(
4145
"otel.instrumentation.log4j-appender.experimental.capture-map-message-attributes",
@@ -51,13 +55,20 @@ public final class Log4jHelper {
5155
new LogEventMapper<>(
5256
ContextDataAccessorImpl.INSTANCE,
5357
captureExperimentalAttributes,
58+
captureCodeAttributes,
5459
captureMapMessageAttributes,
5560
captureMarkerAttribute,
5661
captureContextDataAttributes);
5762
}
5863

5964
public static void capture(
60-
Logger logger, Level level, Marker marker, Message message, Throwable throwable) {
65+
Logger logger,
66+
String loggerClassName,
67+
StackTraceElement location,
68+
Level level,
69+
Marker marker,
70+
Message message,
71+
Throwable throwable) {
6172
String instrumentationName = logger.getName();
6273
if (instrumentationName == null || instrumentationName.isEmpty()) {
6374
instrumentationName = "ROOT";
@@ -86,6 +97,8 @@ public static void capture(
8697
contextData,
8798
threadName,
8899
threadId,
100+
() ->
101+
location != null ? location : StackLocator.getInstance().calcLocation(loggerClassName),
89102
Context.current());
90103
builder.setTimestamp(Instant.now());
91104
builder.emit();

‎instrumentation/log4j/log4j-appender-2.17/javaagent/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/Log4j2Test.java‎

Lines changed: 43 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,12 @@
1111
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_MESSAGE;
1212
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_STACKTRACE;
1313
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_TYPE;
14+
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_FILEPATH;
15+
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_FUNCTION;
16+
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_LINENO;
17+
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_NAMESPACE;
18+
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_ID;
19+
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_NAME;
1420
import static java.util.concurrent.TimeUnit.MILLISECONDS;
1521

1622
import io.opentelemetry.api.common.AttributeKey;
@@ -22,7 +28,6 @@
2228
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
2329
import io.opentelemetry.sdk.logs.data.LogRecordData;
2430
import io.opentelemetry.sdk.testing.assertj.AttributeAssertion;
25-
import io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes;
2631
import java.time.Instant;
2732
import java.util.ArrayList;
2833
import java.util.Arrays;
@@ -35,6 +40,7 @@
3540
import org.apache.logging.log4j.ThreadContext;
3641
import org.apache.logging.log4j.message.StringMapMessage;
3742
import org.apache.logging.log4j.message.StructuredDataMessage;
43+
import org.assertj.core.api.AbstractLongAssert;
3844
import org.assertj.core.api.AssertAccess;
3945
import org.junit.jupiter.api.Test;
4046
import org.junit.jupiter.api.extension.RegisterExtension;
@@ -112,11 +118,12 @@ private static void test(
112118
List<AttributeAssertion> attributeAsserts =
113119
new ArrayList<>(
114120
Arrays.asList(
115-
equalTo(
116-
ThreadIncubatingAttributes.THREAD_NAME,
117-
Thread.currentThread().getName()),
118-
equalTo(
119-
ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
121+
equalTo(THREAD_NAME, Thread.currentThread().getName()),
122+
equalTo(THREAD_ID, Thread.currentThread().getId()),
123+
equalTo(CODE_NAMESPACE, Log4j2Test.class.getName()),
124+
equalTo(CODE_FUNCTION, "performLogging"),
125+
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
126+
equalTo(CODE_FILEPATH, "Log4j2Test.java")));
120127
if (logException) {
121128
attributeAsserts.addAll(
122129
Arrays.asList(
@@ -158,9 +165,12 @@ void testContextData() {
158165
.hasAttributesSatisfyingExactly(
159166
equalTo(AttributeKey.stringKey("key1"), "val1"),
160167
equalTo(AttributeKey.stringKey("key2"), "val2"),
161-
equalTo(
162-
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
163-
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
168+
equalTo(THREAD_NAME, Thread.currentThread().getName()),
169+
equalTo(THREAD_ID, Thread.currentThread().getId()),
170+
equalTo(CODE_NAMESPACE, Log4j2Test.class.getName()),
171+
equalTo(CODE_FUNCTION, "testContextData"),
172+
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
173+
equalTo(CODE_FILEPATH, "Log4j2Test.java")));
164174
}
165175

166176
@Test
@@ -180,9 +190,12 @@ void testStringMapMessage() {
180190
.hasAttributesSatisfyingExactly(
181191
equalTo(AttributeKey.stringKey("log4j.map_message.key1"), "val1"),
182192
equalTo(AttributeKey.stringKey("log4j.map_message.key2"), "val2"),
183-
equalTo(
184-
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
185-
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
193+
equalTo(THREAD_NAME, Thread.currentThread().getName()),
194+
equalTo(THREAD_ID, Thread.currentThread().getId()),
195+
equalTo(CODE_NAMESPACE, Log4j2Test.class.getName()),
196+
equalTo(CODE_FUNCTION, "testStringMapMessage"),
197+
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
198+
equalTo(CODE_FILEPATH, "Log4j2Test.java")));
186199
}
187200

188201
@Test
@@ -201,9 +214,12 @@ void testStringMapMessageWithSpecialAttribute() {
201214
.hasSeverityText("INFO")
202215
.hasAttributesSatisfyingExactly(
203216
equalTo(AttributeKey.stringKey("log4j.map_message.key1"), "val1"),
204-
equalTo(
205-
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
206-
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
217+
equalTo(THREAD_NAME, Thread.currentThread().getName()),
218+
equalTo(THREAD_ID, Thread.currentThread().getId()),
219+
equalTo(CODE_NAMESPACE, Log4j2Test.class.getName()),
220+
equalTo(CODE_FUNCTION, "testStringMapMessageWithSpecialAttribute"),
221+
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
222+
equalTo(CODE_FILEPATH, "Log4j2Test.java")));
207223
}
208224

209225
@Test
@@ -223,9 +239,12 @@ void testStructuredDataMapMessage() {
223239
.hasAttributesSatisfyingExactly(
224240
equalTo(AttributeKey.stringKey("log4j.map_message.key1"), "val1"),
225241
equalTo(AttributeKey.stringKey("log4j.map_message.key2"), "val2"),
226-
equalTo(
227-
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
228-
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
242+
equalTo(THREAD_NAME, Thread.currentThread().getName()),
243+
equalTo(THREAD_ID, Thread.currentThread().getId()),
244+
equalTo(CODE_NAMESPACE, Log4j2Test.class.getName()),
245+
equalTo(CODE_FUNCTION, "testStructuredDataMapMessage"),
246+
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
247+
equalTo(CODE_FILEPATH, "Log4j2Test.java")));
229248
}
230249

231250
@Test
@@ -238,8 +257,12 @@ public void testMarker() {
238257
testing.waitAndAssertLogRecords(
239258
logRecord ->
240259
logRecord.hasAttributesSatisfyingExactly(
241-
equalTo(ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
242-
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
260+
equalTo(THREAD_NAME, Thread.currentThread().getName()),
261+
equalTo(THREAD_ID, Thread.currentThread().getId()),
262+
equalTo(CODE_NAMESPACE, Log4j2Test.class.getName()),
263+
equalTo(CODE_FUNCTION, "testMarker"),
264+
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
265+
equalTo(CODE_FILEPATH, "Log4j2Test.java"),
243266
equalTo(AttributeKey.stringKey("log4j.marker"), markerName)));
244267
}
245268

‎instrumentation/log4j/log4j-appender-2.17/javaagent/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v2_17/Slf4jToLog4jTest.java‎

Lines changed: 25 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,12 @@
1111
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_MESSAGE;
1212
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_STACKTRACE;
1313
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_TYPE;
14+
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_FILEPATH;
15+
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_FUNCTION;
16+
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_LINENO;
17+
import static io.opentelemetry.semconv.incubating.CodeIncubatingAttributes.CODE_NAMESPACE;
18+
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_ID;
19+
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_NAME;
1420

1521
import io.opentelemetry.api.common.AttributeKey;
1622
import io.opentelemetry.api.logs.Severity;
@@ -19,11 +25,11 @@
1925
import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
2026
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
2127
import io.opentelemetry.sdk.testing.assertj.AttributeAssertion;
22-
import io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes;
2328
import java.util.ArrayList;
2429
import java.util.Arrays;
2530
import java.util.List;
2631
import java.util.stream.Stream;
32+
import org.assertj.core.api.AbstractLongAssert;
2733
import org.junit.jupiter.api.Test;
2834
import org.junit.jupiter.api.extension.RegisterExtension;
2935
import org.junit.jupiter.params.ParameterizedTest;
@@ -103,11 +109,12 @@ private static void test(
103109
List<AttributeAssertion> attributeAsserts =
104110
new ArrayList<>(
105111
Arrays.asList(
106-
equalTo(
107-
ThreadIncubatingAttributes.THREAD_NAME,
108-
Thread.currentThread().getName()),
109-
equalTo(
110-
ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
112+
equalTo(THREAD_NAME, Thread.currentThread().getName()),
113+
equalTo(THREAD_ID, Thread.currentThread().getId()),
114+
equalTo(CODE_NAMESPACE, Slf4jToLog4jTest.class.getName()),
115+
equalTo(CODE_FUNCTION, "performLogging"),
116+
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
117+
equalTo(CODE_FILEPATH, "Slf4jToLog4jTest.java")));
111118
if (logException) {
112119
attributeAsserts.addAll(
113120
Arrays.asList(
@@ -145,14 +152,16 @@ void testMdc() {
145152
.hasAttributesSatisfyingExactly(
146153
equalTo(AttributeKey.stringKey("key1"), "val1"),
147154
equalTo(AttributeKey.stringKey("key2"), "val2"),
148-
equalTo(
149-
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
150-
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
155+
equalTo(THREAD_NAME, Thread.currentThread().getName()),
156+
equalTo(THREAD_ID, Thread.currentThread().getId()),
157+
equalTo(CODE_NAMESPACE, Slf4jToLog4jTest.class.getName()),
158+
equalTo(CODE_FUNCTION, "testMdc"),
159+
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
160+
equalTo(CODE_FILEPATH, "Slf4jToLog4jTest.java")));
151161
}
152162

153163
@Test
154164
public void testMarker() {
155-
156165
String markerName = "aMarker";
157166
Marker marker = MarkerFactory.getMarker(markerName);
158167

@@ -161,8 +170,12 @@ public void testMarker() {
161170
testing.waitAndAssertLogRecords(
162171
logRecord ->
163172
logRecord.hasAttributesSatisfyingExactly(
164-
equalTo(ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
165-
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId()),
173+
equalTo(THREAD_NAME, Thread.currentThread().getName()),
174+
equalTo(THREAD_ID, Thread.currentThread().getId()),
175+
equalTo(CODE_NAMESPACE, Slf4jToLog4jTest.class.getName()),
176+
equalTo(CODE_FUNCTION, "testMarker"),
177+
satisfies(CODE_LINENO, AbstractLongAssert::isPositive),
178+
equalTo(CODE_FILEPATH, "Slf4jToLog4jTest.java"),
166179
equalTo(AttributeKey.stringKey("log4j.marker"), markerName)));
167180
}
168181

0 commit comments

Comments
 (0)