Context lost when using Logback async appender

[ataraxis]

Describe the bug

When logging to an otel appender from an async appender, trace id and span id are missing.

Logging directly to the otel appender:

Trace ID: c19c9a3ae2dab1b1950e6073eddb5b8d
Span ID: 38035d648fa52857

Logging through the async appender:

Trace ID:
Span ID:

Steps to reproduce

    <appender name="otel-async" class="ch.qos.logback.classic.AsyncAppender">
        <appender-ref ref="otel-sync" />
    </appender>

    <appender name="otel-sync" class="io.opentelemetry.instrumentation.logback.appender.v1_0.OpenTelemetryAppender">
        <captureExperimentalAttributes>true</captureExperimentalAttributes>
        <captureMarkerAttribute>true</captureMarkerAttribute>
        <captureKeyValuePairAttributes>true</captureKeyValuePairAttributes>
    </appender>

    <root level="DEBUG">
        <appender-ref ref="otel-async"/>
    </root>

Expected behavior

Context would be propagated through the async appender to the otel appender so that trace and span ids would be included in log records.

Actual behavior

Trace and span ids are missing.

Javaagent or library instrumentation version

2.12.0

Environment

JDK: OpenJDK 21
OS: Ubuntu 23.10

Additional context

No response

[trask]

hi @ataraxis!

we had a similar report that was fixed in 2.12.0

it looks like you're already using that version, so could you take a look at #13047 and see what might be different between what your issue is and what was just recently fixed in 2.12.0?

[ataraxis]

I actually opened #12979 as well. That issue was with OpenTelemetryAppender.install not installing the sdk on appenders only referenced through an async appender. That fix worked (much appreciated!) but that led me to discover this issue, which is that the context is not propagated through the async appender to the referenced otel appender.

AsyncAppender is writing events to a java.util.concurrent.ArrayBlockingQueue and then draining from that queue in a separate worker thread. Before adding the event to the queue, it calls ILoggingEvent.prepareForDeferredProcessing. Maybe that could somehow be used to add trace and span ids to the event which the otel appender could pick up?

[laurit]

I'm not sure this is worth the effort, perhaps it would be sufficient to just document that trace and span id won't be available when otel appender is used along with AsyncAppender. Otel appender is asynchronous anyway since the exporting happens in another thread, is there a benefit in wrapping it to AsyncAppender? I guess if you really want to use the AsyncAppender you could probably make it work by having an appender that wraps AsyncAppender and adds otel context to the logging event (you could wrap the logging event in a custom class or see whether there is writable map inside the event) and another appender that runs before the otel appender that restores context from the event before delegating to the otel appender.