Skip to content

Add code attributes for log4j1 #13947

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

Open
wants to merge 23 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from 20 commits
Commits
Show all changes
23 commits
Select commit Hold shift + click to select a range
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 @@ -34,6 +34,7 @@ configurations {
tasks.withType<Test>().configureEach {
// TODO run tests both with and without experimental log attributes
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-mdc-attributes=*")
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental.capture-code-attributes=true")
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental-log-attributes=true")
jvmArgs("-Dotel.instrumentation.log4j-appender.experimental-log-attributes=true")
jvmArgs("-Dotel.instrumentation.common.experimental.controller-telemetry.enabled=true")
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,7 @@ public static class ForcedLogAdvice {
@Advice.OnMethodEnter(suppress = Throwable.class)
public static void methodEnter(
@Advice.This Category logger,
@Advice.Argument(0) String fqcn,
@Advice.Argument(1) Priority level,
@Advice.Argument(2) Object message,
@Advice.Argument(3) Throwable t,
Expand All @@ -56,7 +57,7 @@ public static void methodEnter(
// framework delegates to another
callDepth = CallDepth.forClass(LoggerProvider.class);
if (callDepth.getAndIncrement() == 0) {
LogEventMapper.INSTANCE.capture(logger, level, message, t);
LogEventMapper.INSTANCE.capture(fqcn, logger, level, message, t);
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -14,8 +14,10 @@
import io.opentelemetry.api.logs.LogRecordBuilder;
import io.opentelemetry.api.logs.Severity;
import io.opentelemetry.context.Context;
import io.opentelemetry.instrumentation.api.internal.SemconvStability;
import io.opentelemetry.instrumentation.api.internal.cache.Cache;
import io.opentelemetry.javaagent.bootstrap.internal.AgentInstrumentationConfig;
import io.opentelemetry.semconv.CodeAttributes;
import io.opentelemetry.semconv.ExceptionAttributes;
import io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes;
import java.io.PrintWriter;
Expand All @@ -28,13 +30,19 @@
import org.apache.log4j.Category;
import org.apache.log4j.MDC;
import org.apache.log4j.Priority;
import org.apache.log4j.spi.LocationInfo;

public final class LogEventMapper {

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

public static final LogEventMapper INSTANCE = new LogEventMapper();

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

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

public void capture(Category logger, Priority level, Object message, Throwable throwable) {
boolean captureCodeAttributes =
AgentInstrumentationConfig.get()
.getBoolean(
"otel.instrumentation.log4j-appender.experimental.capture-code-attributes", false);

public void capture(
String fqcn, Category logger, Priority level, Object message, Throwable throwable) {
String instrumentationName = logger.getName();
if (instrumentationName == null || instrumentationName.isEmpty()) {
instrumentationName = "ROOT";
Expand Down Expand Up @@ -104,6 +118,47 @@ public void capture(Category logger, Priority level, Object message, Throwable t
attributes.put(ThreadIncubatingAttributes.THREAD_ID, currentThread.getId());
}

if (captureCodeAttributes) {
LocationInfo locationInfo = new LocationInfo(new Throwable(), fqcn);
String fileName = locationInfo.getFileName();
if (fileName != null) {
if (SemconvStability.isEmitStableCodeSemconv()) {
attributes.put(CodeAttributes.CODE_FILE_PATH, fileName);
}
if (SemconvStability.isEmitOldCodeSemconv()) {
attributes.put(CODE_FILEPATH, fileName);
}
}

if (SemconvStability.isEmitStableCodeSemconv()) {
attributes.put(
CodeAttributes.CODE_FUNCTION_NAME,
locationInfo.getClassName() + "." + locationInfo.getMethodName());
}
if (SemconvStability.isEmitOldCodeSemconv()) {
attributes.put(CODE_NAMESPACE, locationInfo.getClassName());
attributes.put(CODE_FUNCTION, locationInfo.getMethodName());
}

String lineNumber = locationInfo.getLineNumber();
int codeLineNo = -1;
if (!lineNumber.equals("?")) {
try {
codeLineNo = Integer.parseInt(lineNumber);
} catch (NumberFormatException e) {
// ignore
}
}
if (codeLineNo >= 0) {
if (SemconvStability.isEmitStableCodeSemconv()) {
attributes.put(CodeAttributes.CODE_LINE_NUMBER, codeLineNo);
}
if (SemconvStability.isEmitOldCodeSemconv()) {
attributes.put(CODE_LINENO, codeLineNo);
}
}
}

builder.setAllAttributes(attributes.build());

// span context
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -11,13 +11,16 @@
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_MESSAGE;
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_STACKTRACE;
import static io.opentelemetry.semconv.ExceptionAttributes.EXCEPTION_TYPE;
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_ID;
import static io.opentelemetry.semconv.incubating.ThreadIncubatingAttributes.THREAD_NAME;
import static java.util.concurrent.TimeUnit.MILLISECONDS;

import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.logs.Severity;
import io.opentelemetry.api.trace.SpanContext;
import io.opentelemetry.instrumentation.testing.junit.AgentInstrumentationExtension;
import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
import io.opentelemetry.instrumentation.testing.junit.code.SemconvCodeStabilityUtil;
import io.opentelemetry.sdk.common.InstrumentationScopeInfo;
import io.opentelemetry.sdk.logs.data.LogRecordData;
import io.opentelemetry.sdk.testing.assertj.AttributeAssertion;
Expand All @@ -38,6 +41,7 @@
import org.junit.jupiter.params.provider.Arguments;
import org.junit.jupiter.params.provider.MethodSource;

@SuppressWarnings("deprecation") // using deprecated semconv
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[minor] probably not needed anymore

class Log4j1Test {

static {
Expand Down Expand Up @@ -67,6 +71,26 @@ private static Stream<Arguments> provideParameters() {
Arguments.of(true, true));
}

@Test
public void testCodeAttributes() {
logger.info("this is test message");
List<AttributeAssertion> assertions =
SemconvCodeStabilityUtil.codeFileAndLineAssertions("Log4j1Test.java");
assertions.addAll(
SemconvCodeStabilityUtil.codeFunctionAssertions(Log4j1Test.class, "testCodeAttributes"));
assertions.add(equalTo(THREAD_NAME, Thread.currentThread().getName()));
assertions.add(equalTo(THREAD_ID, Thread.currentThread().getId()));

testing.waitAndAssertLogRecords(
logRecord ->
logRecord
.hasBody("this is test message")
.hasInstrumentationScope(InstrumentationScopeInfo.builder("abc").build())
.hasSeverity(Severity.INFO)
.hasSeverityText("INFO")
.hasAttributesSatisfyingExactly(assertions));
}

@ParameterizedTest
@MethodSource("provideParameters")
public void test(boolean logException, boolean withParent) throws InterruptedException {
Expand Down
Loading