Skip to content

Commit c0e4684

Browse files
oliver-zhangSylvainJugetrask
authored
Add code attributes for log4j1 (#13947)
Co-authored-by: SylvainJuge <[email protected]> Co-authored-by: Trask Stalnaker <[email protected]>
1 parent fc4f525 commit c0e4684

File tree

4 files changed

+98
-14
lines changed

4 files changed

+98
-14
lines changed

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

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,7 @@ configurations {
3434
tasks.withType<Test>().configureEach {
3535
// TODO run tests both with and without experimental log attributes
3636
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-mdc-attributes=*")
37+
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-code-attributes=true")
3738
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental-log-attributes=true")
3839
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental-log-attributes=true")
3940
jvmArgs("-Dotel.instrumentation.common.experimental.controller-telemetry.enabled=true")

‎instrumentation/log4j/log4j-appender-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/Log4jAppenderInstrumentation.java‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -48,6 +48,7 @@ public static class ForcedLogAdvice {
4848
@Advice.OnMethodEnter(suppress = Throwable.class)
4949
public static void methodEnter(
5050
@Advice.This Category logger,
51+
@Advice.Argument(0) String fqcn,
5152
@Advice.Argument(1) Priority level,
5253
@Advice.Argument(2) Object message,
5354
@Advice.Argument(3) Throwable t,
@@ -56,7 +57,7 @@ public static void methodEnter(
5657
// framework delegates to another
5758
callDepth = CallDepth.forClass(LoggerProvider.class);
5859
if (callDepth.getAndIncrement() == 0) {
59-
LogEventMapper.INSTANCE.capture(logger, level, message, t);
60+
LogEventMapper.INSTANCE.capture(fqcn, logger, level, message, t);
6061
}
6162
}
6263

‎instrumentation/log4j/log4j-appender-1.2/javaagent/src/main/java/io/opentelemetry/javaagent/instrumentation/log4j/appender/v1_2/LogEventMapper.java‎

Lines changed: 56 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -14,8 +14,10 @@
1414
import io.opentelemetry.api.logs.LogRecordBuilder;
1515
import io.opentelemetry.api.logs.Severity;
1616
import io.opentelemetry.context.Context;
17+
import io.opentelemetry.instrumentation.api.internal.SemconvStability;
1718
import io.opentelemetry.instrumentation.api.internal.cache.Cache;
1819
import io.opentelemetry.javaagent.bootstrap.internal.AgentInstrumentationConfig;
20+
import io.opentelemetry.semconv.CodeAttributes;
1921
import io.opentelemetry.semconv.ExceptionAttributes;
2022
import io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes;
2123
import java.io.PrintWriter;
@@ -28,13 +30,19 @@
2830
import org.apache.log4j.Category;
2931
import org.apache.log4j.MDC;
3032
import org.apache.log4j.Priority;
33+
import org.apache.log4j.spi.LocationInfo;
3134

3235
public final class LogEventMapper {
3336

3437
private static final Cache<String, AttributeKey<String>> mdcAttributeKeys = Cache.bounded(100);
3538

3639
public static final LogEventMapper INSTANCE = new LogEventMapper();
3740

41+
private static final AttributeKey<String> CODE_FILEPATH = AttributeKey.stringKey("code.filepath");
42+
private static final AttributeKey<String> CODE_FUNCTION = AttributeKey.stringKey("code.function");
43+
private static final AttributeKey<Long> CODE_LINENO = AttributeKey.longKey("code.lineno");
44+
private static final AttributeKey<String> CODE_NAMESPACE =
45+
AttributeKey.stringKey("code.namespace");
3846
// copied from org.apache.log4j.Level because it was only introduced in 1.2.12
3947
private static final int TRACE_INT = 5000;
4048

@@ -60,7 +68,13 @@ private LogEventMapper() {
6068
captureMdcAttributes.size() == 1 && captureMdcAttributes.get(0).equals("*");
6169
}
6270

63-
public void capture(Category logger, Priority level, Object message, Throwable throwable) {
71+
boolean captureCodeAttributes =
72+
AgentInstrumentationConfig.get()
73+
.getBoolean(
74+
"otel.instrumentation.log4j-appender.experimental.capture-code-attributes", false);
75+
76+
public void capture(
77+
String fqcn, Category logger, Priority level, Object message, Throwable throwable) {
6478
String instrumentationName = logger.getName();
6579
if (instrumentationName == null || instrumentationName.isEmpty()) {
6680
instrumentationName = "ROOT";
@@ -104,6 +118,47 @@ public void capture(Category logger, Priority level, Object message, Throwable t
104118
attributes.put(ThreadIncubatingAttributes.THREAD_ID, currentThread.getId());
105119
}
106120

121+
if (captureCodeAttributes) {
122+
LocationInfo locationInfo = new LocationInfo(new Throwable(), fqcn);
123+
String fileName = locationInfo.getFileName();
124+
if (fileName != null) {
125+
if (SemconvStability.isEmitStableCodeSemconv()) {
126+
attributes.put(CodeAttributes.CODE_FILE_PATH, fileName);
127+
}
128+
if (SemconvStability.isEmitOldCodeSemconv()) {
129+
attributes.put(CODE_FILEPATH, fileName);
130+
}
131+
}
132+
133+
if (SemconvStability.isEmitStableCodeSemconv()) {
134+
attributes.put(
135+
CodeAttributes.CODE_FUNCTION_NAME,
136+
locationInfo.getClassName() + "." + locationInfo.getMethodName());
137+
}
138+
if (SemconvStability.isEmitOldCodeSemconv()) {
139+
attributes.put(CODE_NAMESPACE, locationInfo.getClassName());
140+
attributes.put(CODE_FUNCTION, locationInfo.getMethodName());
141+
}
142+
143+
String lineNumber = locationInfo.getLineNumber();
144+
int codeLineNo = -1;
145+
if (!lineNumber.equals("?")) {
146+
try {
147+
codeLineNo = Integer.parseInt(lineNumber);
148+
} catch (NumberFormatException e) {
149+
// ignore
150+
}
151+
}
152+
if (codeLineNo >= 0) {
153+
if (SemconvStability.isEmitStableCodeSemconv()) {
154+
attributes.put(CodeAttributes.CODE_LINE_NUMBER, codeLineNo);
155+
}
156+
if (SemconvStability.isEmitOldCodeSemconv()) {
157+
attributes.put(CODE_LINENO, codeLineNo);
158+
}
159+
}
160+
}
161+
107162
builder.setAllAttributes(attributes.build());
108163

109164
// span context

‎instrumentation/log4j/log4j-appender-1.2/javaagent/src/test/java/io/opentelemetry/instrumentation/log4j/appender/v1_2/Log4j1Test.java‎

Lines changed: 39 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -11,17 +11,19 @@
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.ThreadIncubatingAttributes.THREAD_ID;
15+
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_NAME;
1416
import static java.util.concurrent.TimeUnit.MILLISECONDS;
1517

1618
import io.opentelemetry.api.common.AttributeKey;
1719
import io.opentelemetry.api.logs.Severity;
1820
import io.opentelemetry.api.trace.SpanContext;
1921
import io.opentelemetry.instrumentation.testing.junit.AgentInstrumentationExtension;
2022
import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
23+
import io.opentelemetry.instrumentation.testing.junit.code.SemconvCodeStabilityUtil;
2124
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
2225
import io.opentelemetry.sdk.logs.data.LogRecordData;
2326
import io.opentelemetry.sdk.testing.assertj.AttributeAssertion;
24-
import io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes;
2527
import java.lang.reflect.Field;
2628
import java.time.Instant;
2729
import java.util.ArrayList;
@@ -67,6 +69,26 @@ private static Stream<Arguments> provideParameters() {
6769
Arguments.of(true, true));
6870
}
6971

72+
@Test
73+
public void testCodeAttributes() {
74+
logger.info("this is test message");
75+
List<AttributeAssertion> assertions =
76+
SemconvCodeStabilityUtil.codeFileAndLineAssertions("Log4j1Test.java");
77+
assertions.addAll(
78+
SemconvCodeStabilityUtil.codeFunctionAssertions(Log4j1Test.class, "testCodeAttributes"));
79+
assertions.add(equalTo(THREAD_NAME, Thread.currentThread().getName()));
80+
assertions.add(equalTo(THREAD_ID, Thread.currentThread().getId()));
81+
82+
testing.waitAndAssertLogRecords(
83+
logRecord ->
84+
logRecord
85+
.hasBody("this is test message")
86+
.hasInstrumentationScope(InstrumentationScopeInfo.builder("abc").build())
87+
.hasSeverity(Severity.INFO)
88+
.hasSeverityText("INFO")
89+
.hasAttributesSatisfyingExactly(assertions));
90+
}
91+
7092
@ParameterizedTest
7193
@MethodSource("provideParameters")
7294
public void test(boolean logException, boolean withParent) throws InterruptedException {
@@ -122,11 +144,8 @@ private static void test(
122144
List<AttributeAssertion> attributeAsserts =
123145
new ArrayList<>(
124146
Arrays.asList(
125-
equalTo(
126-
ThreadIncubatingAttributes.THREAD_NAME,
127-
Thread.currentThread().getName()),
128-
equalTo(
129-
ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
147+
equalTo(THREAD_NAME, Thread.currentThread().getName()),
148+
equalTo(THREAD_ID, Thread.currentThread().getId())));
130149
if (logException) {
131150
attributeAsserts.addAll(
132151
Arrays.asList(
@@ -135,6 +154,11 @@ private static void test(
135154
satisfies(
136155
EXCEPTION_STACKTRACE, v -> v.contains(Log4j1Test.class.getName()))));
137156
}
157+
attributeAsserts.addAll(
158+
SemconvCodeStabilityUtil.codeFunctionAssertions(
159+
Log4j1Test.class, "performLogging"));
160+
attributeAsserts.addAll(
161+
SemconvCodeStabilityUtil.codeFileAndLineAssertions("Log4j1Test.java"));
138162
logRecord.hasAttributesSatisfyingExactly(attributeAsserts);
139163

140164
LogRecordData logRecordData = AssertAccess.getActual(logRecord);
@@ -159,19 +183,22 @@ void testMdc() {
159183
MDC.remove("key2");
160184
}
161185

186+
List<AttributeAssertion> assertions =
187+
SemconvCodeStabilityUtil.codeFileAndLineAssertions("Log4j1Test.java");
188+
assertions.addAll(SemconvCodeStabilityUtil.codeFunctionAssertions(Log4j1Test.class, "testMdc"));
189+
assertions.add(equalTo(AttributeKey.stringKey("key1"), "val1"));
190+
assertions.add(equalTo(AttributeKey.stringKey("key2"), "val2"));
191+
assertions.add(equalTo(THREAD_NAME, Thread.currentThread().getName()));
192+
assertions.add(equalTo(THREAD_ID, Thread.currentThread().getId()));
193+
162194
testing.waitAndAssertLogRecords(
163195
logRecord ->
164196
logRecord
165197
.hasBody("xyz")
166198
.hasInstrumentationScope(InstrumentationScopeInfo.builder("abc").build())
167199
.hasSeverity(Severity.INFO)
168200
.hasSeverityText("INFO")
169-
.hasAttributesSatisfyingExactly(
170-
equalTo(AttributeKey.stringKey("key1"), "val1"),
171-
equalTo(AttributeKey.stringKey("key2"), "val2"),
172-
equalTo(
173-
ThreadIncubatingAttributes.THREAD_NAME, Thread.currentThread().getName()),
174-
equalTo(ThreadIncubatingAttributes.THREAD_ID, Thread.currentThread().getId())));
201+
.hasAttributesSatisfyingExactly(assertions));
175202
}
176203

177204
private static void performLogging(

0 commit comments

Comments
 (0)