Add code attributes for Logback #6591

jeanbisutti · 2022-09-12T15:29:01Z

Add code attributes for Logback:

SemanticAttributes.CODE_FILEPATH
SemanticAttributes.CODE_NAMESPACE
SemanticAttributes.CODE_FUNCTION
SemanticAttributes.CODE_LINENO

jeanbisutti · 2022-09-12T15:41:30Z

.../main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppender.java

@@ -25,6 +25,7 @@ public class OpenTelemetryAppender extends UnsynchronizedAppenderBase<ILoggingEv
      new LogEmitterProviderHolder();

  private volatile boolean captureExperimentalAttributes = false;
+  private volatile boolean captureCodeAttributes = false;


I wanted first that the captureCodeAttributes property would be an AtomicBoolean, but I have noticed after that captureExperimentalAttributes is a boolean, so I keep the same way of doing

trask

nice 👍

instrumentation/logback/logback-appender-1.0/javaagent/build.gradle.kts

laurit · 2022-09-12T16:41:44Z

.../main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppender.java

@@ -62,6 +65,17 @@ public void setCaptureExperimentalAttributes(boolean captureExperimentalAttribut
    this.captureExperimentalAttributes = captureExperimentalAttributes;
  }

+  /**
+   * Sets whether the code attributes (file name, class name, method name and line number) should be
+   * set to logs.


https://logback.qos.ch/manual/layouts.html states Generating the line number information is not particularly fast. Thus, its use should be avoided unless execution speed is not an issue. (same for other code attributes). Should we also mention this here?

Sure, I have added a sentence about this.

trask · 2022-09-12T18:59:51Z

I'm looking into the CI failure, I suspect that is my doing...

trask · 2022-09-12T19:24:30Z

I merged in main to fix CI

mateuszrzeszutek · 2022-09-13T09:45:02Z

...java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java

+      StackTraceElement[] callerData = loggingEvent.getCallerData();
+      if (callerData != null && callerData.length > 0) {
+        StackTraceElement firstStackElement = callerData[0];
+        attributes.put(SemanticAttributes.CODE_FILEPATH, firstStackElement.getFileName());


StackTraceElement#getFileName() might return null, let's null-check it before passing it to attributes

Done, I did not know that null attributes have not to bet set

mateuszrzeszutek · 2022-09-13T09:45:35Z

...java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java

+        attributes.put(SemanticAttributes.CODE_FILEPATH, firstStackElement.getFileName());
+        attributes.put(SemanticAttributes.CODE_NAMESPACE, firstStackElement.getClassName());
+        attributes.put(SemanticAttributes.CODE_FUNCTION, firstStackElement.getMethodName());
+        attributes.put(SemanticAttributes.CODE_LINENO, firstStackElement.getLineNumber());


StackTraceElement#getLineNumber() might return -1 -- in which case we probably don't want to add the attribute at all, since it represents an absent value.

mateuszrzeszutek · 2022-09-13T09:46:34Z

instrumentation/logback/logback-appender-1.0/javaagent/src/test/groovy/LogbackTest.groovy

        assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_TYPE)).isEqualTo(IllegalStateException.getName())
        assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_MESSAGE)).isEqualTo("hello")
        assertThat(log.getAttributes().get(SemanticAttributes.EXCEPTION_STACKTRACE)).contains(LogbackTest.name)
      } else {
-        assertThat(log.getAttributes().size()).isEqualTo(2)
+        assertThat(log.getAttributes().size()).isEqualTo(2 + 4)  // 4 code attributes


Can you add code attributes assertions to the javaagent test too?

Because of the nature of the Groovy test, the attribute values are not very readable:

file = NativeMethodAccessorImpl.java codeClass = jdk.internal.reflect.NativeMethodAccessorImpl method = invoke0

The attribute values are checked in a library test.

Eh, forgot that was groovy. Nevermind then 👍

ya, it would be nice to have validation that the attributes are working inside of the Java agent as well, but can get to that later, I've opened #6604 to track

mateuszrzeszutek · 2022-09-13T09:48:14Z

.../io/opentelemetry/instrumentation/logback/appender/v1_0/OpenTelemetryAppenderConfigTest.java

@@ -115,13 +114,27 @@ void logWithExtras() {
        .isLessThan(TimeUnit.MILLISECONDS.toNanos(Instant.now().toEpochMilli()));
    assertThat(logData.getSeverity()).isEqualTo(Severity.INFO);
    assertThat(logData.getSeverityText()).isEqualTo("INFO");
-    assertThat(logData.getAttributes().size()).isEqualTo(3);
+    assertThat(logData.getAttributes().size()).isEqualTo(3 + 4); // 4 code attributes


WDYT about refactoring this to use OpenTelemetryAssertions and AttributesAssert? Would be way more terse than the current code

I was not aware about these classes. Thanks! I have a first look at the OpenTelemetryAssertions and AttributesAssert classes. From what I have seen, I have not the feeling that the assertions would be shorter and easier to read (for example the assertAttributes method of AttributesAssert requires a Map). Maybe I could look at this thing more in depth and propose potential improvements in another PR?

Sure, that sounds fine 👍

...java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java

…java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java Co-authored-by: Mateusz Rzeszutek <mrzeszutek@splunk.com>

trask · 2022-09-13T15:27:28Z

instrumentation/logback/logback-appender-1.0/javaagent/src/test/groovy/LogbackTest.groovy

@@ -44,6 +44,13 @@ class LogbackTest extends AgentInstrumentationSpecification {
      waitForTraces(1)
    }

+    String jvmVersion = System.getProperty("java.vm.specification.version")
+    int codeAttributes = 3
+    boolean jvmVersionGreaterThanOrEqualTo18 = jvmVersion.startsWith("1.8") && Integer.parseInt(jvmVersion) >= 18


won't this throw NumberFormatException for 1.8?

if you need to test locally with different Java versions, check out https://github.com/open-telemetry/opentelemetry-java-instrumentation/blob/main/docs/contributing/running-tests.md#executing-tests-with-specific-java-version

trask · 2022-09-13T15:28:24Z

instrumentation/logback/logback-appender-1.0/javaagent/src/test/groovy/LogbackTest.groovy

+    int codeAttributes = 3
+    boolean jvmVersionGreaterThanOrEqualTo18 = jvmVersion.startsWith("1.8") && Integer.parseInt(jvmVersion) >= 18
+    if (jvmVersionGreaterThanOrEqualTo18) {
+      codeAttributes = 4 // Java 18 specificity on line number


can you add a bit more detail to this comment, I'm not familiar with why Java 18 would have different behavior here

I have added a thing

trask · 2022-09-13T15:29:00Z

@jeanbisutti heads up I merged main into your branch to get CI fix for markdown link

trask · 2022-09-13T15:55:40Z

instrumentation/logback/logback-appender-1.0/javaagent/src/test/groovy/LogbackTest.groovy

@@ -44,6 +44,13 @@ class LogbackTest extends AgentInstrumentationSpecification {
      waitForTraces(1)
    }

+    String jvmVersion = System.getProperty("java.vm.specification.version")


can we use this instead? (this is the property we check for java version in the agent)

Suggested change

String jvmVersion = System.getProperty("java.vm.specification.version")

String jvmVersion = System.getProperty("java.version")

No. System.getProperty("java.version") contains the minor JVM version and the number parsing just after will fail

trask · 2022-09-13T15:57:27Z

instrumentation/logback/logback-appender-1.0/javaagent/src/test/groovy/LogbackTest.groovy

+    int codeAttributes = 3
+    boolean jvmVersionGreaterThanOrEqualTo18 = !jvmVersion.startsWith("1.8") && Integer.parseInt(jvmVersion) >= 18
+    if (jvmVersionGreaterThanOrEqualTo18) {
+      codeAttributes = 4 // Java 18 specificity on line number (lineNumber > 0 check)


I wonder if this is because of groovy, I would be surprised to see different behavior for a regular Java class, I may try to convert this test to Java after merging it

Line number is negative for Java <= 17 and this Groovy test, everything is fine for the library test based on JUnit 5

* Add code attributes for Logback * Rename property * Add a note about performance * Add null check on file name * Add check on line number * Fix test following new behavior * spotless * Update instrumentation/logback/logback-appender-1.0/library/src/main/java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java Co-authored-by: Mateusz Rzeszutek <mrzeszutek@splunk.com> * Fix test * Adapt test for Java 18 * codenarc * Test fix Co-authored-by: Trask Stalnaker <trask.stalnaker@gmail.com> Co-authored-by: Mateusz Rzeszutek <mrzeszutek@splunk.com>

Add code attributes for Logback

7528865

jeanbisutti requested a review from a team as a code owner September 12, 2022 15:29

jeanbisutti marked this pull request as draft September 12, 2022 15:29

jeanbisutti commented Sep 12, 2022

View reviewed changes

jeanbisutti marked this pull request as ready for review September 12, 2022 15:42

trask approved these changes Sep 12, 2022

View reviewed changes

instrumentation/logback/logback-appender-1.0/javaagent/build.gradle.kts Outdated Show resolved Hide resolved

laurit reviewed Sep 12, 2022

View reviewed changes

jeanbisutti added 2 commits September 12, 2022 10:57

Rename property

1ebe9f4

Add a note about performance

d9bbf85

Merge remote-tracking branch 'upstream/main' into logback-stack-elements

52f05e8

trask added this to the v1.18.0 milestone Sep 13, 2022

mateuszrzeszutek reviewed Sep 13, 2022

View reviewed changes

jeanbisutti added 4 commits September 13, 2022 03:31

Add null check on file name

8d1cf4d

Add check on line number

df6d85a

Fix test following new behavior

6d9d706

spotless

5db9ded

jeanbisutti requested a review from mateuszrzeszutek September 13, 2022 12:26

mateuszrzeszutek approved these changes Sep 13, 2022

View reviewed changes

...java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java Outdated Show resolved Hide resolved

jeanbisutti and others added 4 commits September 13, 2022 16:02

Update instrumentation/logback/logback-appender-1.0/library/src/main/…

887fe3a

…java/io/opentelemetry/instrumentation/logback/appender/v1_0/internal/LoggingEventMapper.java Co-authored-by: Mateusz Rzeszutek <mrzeszutek@splunk.com>

Fix test

e363a1f

Adapt test for Java 18

dba1c75

Merge remote-tracking branch 'upstream/main' into logback-stack-elements

8037182

trask mentioned this pull request Sep 13, 2022

Add code attribute assertions to logback javaagent tests #6604

Open

codenarc

33b65c5

trask reviewed Sep 13, 2022

View reviewed changes

Test fix

4dd5c6b

trask reviewed Sep 13, 2022

View reviewed changes

trask merged commit f135169 into open-telemetry:main Sep 13, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add code attributes for Logback #6591

Add code attributes for Logback #6591

jeanbisutti commented Sep 12, 2022

jeanbisutti Sep 12, 2022

trask left a comment

laurit Sep 12, 2022

jeanbisutti Sep 12, 2022

trask commented Sep 12, 2022

trask commented Sep 12, 2022

mateuszrzeszutek Sep 13, 2022

jeanbisutti Sep 13, 2022

mateuszrzeszutek Sep 13, 2022

jeanbisutti Sep 13, 2022

mateuszrzeszutek Sep 13, 2022

jeanbisutti Sep 13, 2022

mateuszrzeszutek Sep 13, 2022

trask Sep 13, 2022

mateuszrzeszutek Sep 13, 2022

jeanbisutti Sep 13, 2022

mateuszrzeszutek Sep 13, 2022

trask Sep 13, 2022

trask Sep 13, 2022

jeanbisutti Sep 13, 2022

trask commented Sep 13, 2022

trask Sep 13, 2022

jeanbisutti Sep 13, 2022

trask Sep 13, 2022

jeanbisutti Sep 13, 2022

	String jvmVersion = System.getProperty("java.vm.specification.version")
	String jvmVersion = System.getProperty("java.version")

Add code attributes for Logback #6591

Add code attributes for Logback #6591

Conversation

jeanbisutti commented Sep 12, 2022

Choose a reason for hiding this comment

trask left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

trask commented Sep 12, 2022

trask commented Sep 12, 2022

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

trask commented Sep 13, 2022

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment