Instrumentation for jboss-logmanager getMdcCopy() (#6111)

[ahus1]

This allows, for example, in JSON logs to have the MDC to contain span and trace information.

Both the unit test and a manual integration test with a Quarkus application worked as expected for me.

I wondered if I should add a new instrumentation module as the new method was added in 1.3. As that was release in Apr 2012 and other methods stay identical, I decided not to do that unless someone else requires this.

Please advise if you'd like to see a different approach, and I'll update this PR.

Closes #6111

[linux-foundation-easycla]

The committers listed above are authorized under a signed CLA.

• ✅ login: ahus1 / name: Alexander Schwartz (576c8ff)

[laurit]

If possible we compile and test against the earliest version supported. If introducing a new instrumentation feature makes the instrumentation incompatible then the version number should be bumped everywhere, in module name, package name, docs etc.
As far as I understand you are only calling getMdcCopy from test, which is using groovy, so you can probably change this back to 1.1.0. In test you could check whether this method is present before calling it. Something like

opentelemetry-java-instrumentation/instrumentation/netty/netty-3.8/javaagent/src/test/groovy/Netty38ClientTest.groovy

Line 33 in efd40f8

if (builder.metaClass.getMetaMethod("setConnectTimeout", int) != null) {

When you run tests with -PtestLatestDeps=true tests will run against latest version of jboss-logmanager and thus test your changes too. Alternatively it is possible to define testSets using org.unbroken-dome.test-sets plugin so you can test with multiple versions each of which can have its own tests, see https://github.com/open-telemetry/opentelemetry-java-instrumentation/blob/main/instrumentation/jsf/jsf-mojarra-1.2/javaagent/build.gradle.kts Getting test sets to work exactly as you want can be tricky.

[ahus1]

Thank for the advice, I re-wrote the test, and also reverted the dependency version.

I found out the hard way that I must not use an if statement within the then block. I have to admit I've never used Spock to write tests, so I'm happy to hear a better way to do this.

[laurit]

Try

if (hasGetMdcCopy) {
  assert logRecords.get(2).getMdcCopy().get("trace_id") == span1.spanContext.traceId
  assert logRecords.get(2).getMdcCopy().get("span_id") == span1.spanContext.spanId
  assert logRecords.get(2).getMdcCopy().get("trace_flags") == "01"
}

[ahus1]

Thanks for pointing me to the assert keyword that seems to be necessary within an if block. Without that it evaluated always to true. Ready for a (final?) review.

[trask]

hi @ahus1!

it looks like getMdcCopy() does two things:

• makes a copy of the thread local MDC values and stores that into the LogRecord, so that the LogRecord can be passed to another thread for async logging
• returns a copy of that copy

I think the first point above is the primary use case (similar to log4j's getMDCCopy() which returns void), and so I'm not sure if this PR solves that case, or if I'm missing the use case for doing something with the return value from getMdcCopy().

[ahus1]

Hi @trask - thanks for reviewing this PR.

The getMdcCopy() is copying the thread-local MDC values, and it is also (in contrast to log4j) the only way to retrieve that map. This implementation is symmetric to the instrumentation of the get getMdc(key) call: it first runs the original method (which will do the copy), and then updates the result returned to the caller.

The getMdcCopy()is the method used when logging the record as JSON - the previous instrumentation will not log the MDC contents in the JSON output; see #6111.

For me, this is the way to augment the MDC map to contain the trace information, which AFAIK is the only way to display the trace information when logging the record as JSON. The map is retrieved here from the record: https://github.com/jboss-logging/jboss-logmanager/blob/c6d88b929aaab6fbc815c249bade8891661853f9/src/main/java/org/jboss/logmanager/formatters/StructuredFormatter.java#L215-L224

I tested this successfully when building the agent and running with in my case a Quarkus based app running in standard, non-native mode.

I hope this answers your questions about the intent of the changes, and why I chose this approach.

[trask]

it is also (in contrast to log4j) the only way to retrieve that map

oh yes, this is what I missed, thx!