Duplicated trace ID with otel bridge

[lukasznowak-viacom]

I am observing duplicated trace IDs when using otel bridge. I am using the latest version (1.2.5). When property

io.opentelemetry.context.enableStrictContext is enabled I see such ERRORs:

i.o.c.StrictContextStorage: Scope garbage collected before being closed.-
java.lang.AssertionError: Thread [reactor-http-epoll-9] opened a scope of {opentelemetry-baggage-key={device_id=ImmutableEntry{value=7576d03a-593a-4e09-9459-a53e9deb4418, metadata=ImmutableEntryMetadata{value=propagation=unlimited}}}, opentelemetry-trace-span-key=SdkSpan{traceId=7305ff546f375ed3b0acce33e7ea1bf3, spanId=bb508a76a286652e, parentSpanContext=ImmutableSpanContext{traceId=7305ff546f375ed3b0acce33e7ea1bf3, spanId=11ac041847a6c4a9, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, name=http post, kind=SERVER, attributes=AttributesMap{data={method=POST, exception=none, uri=UNKNOWN, status=200, outcome=SUCCESS, http.url=/accessToken/refresh}, capacity=128, totalAddedValues=6}, status=ImmutableStatusData{statusCode=UNSET, description=}, totalRecordedEvents=0, totalRecordedLinks=0, startEpochNanos=1716298815277691753, endEpochNanos=1716298815355359022}, otelTraceContext=ImmutableSpanContext{traceId=7305ff546f375ed3b0acce33e7ea1bf3, spanId=bb508a76a286652e, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}} here:
	at io.micrometer.tracing.otel.bridge.EventPublishingContextWrapper$1.attach(EventPublishingContextWrapper.java:50) ~[micrometer-tracing-bridge-otel-1.2.5.jar!/:1.2.5]
	at io.opentelemetry.context.Context.makeCurrent(Context.java:202) ~[opentelemetry-context-1.31.0.jar!/:1.31.0]
	at io.micrometer.tracing.otel.bridge.OtelBaggageInScope.makeCurrent(OtelBaggageInScope.java:183) ~[micrometer-tracing-bridge-otel-1.2.5.jar!/:1.2.5]
	at io.micrometer.tracing.otel.bridge.OtelBaggageManager.createBaggageInScope(OtelBaggageManager.java:191) ~[micrometer-tracing-bridge-otel-1.2.5.jar!/:1.2.5]
	at io.micrometer.tracing.otel.bridge.OtelTracer.createBaggageInScope(OtelTracer.java:191) ~[micrometer-tracing-bridge-otel-1.2.5.jar!/:1.2.5]
	at tech.viacom.commons.tracing.DefaultDeviceIdPropagation.set(DeviceIdPropagation.kt:14) ~[auth-commons-starter-1.0.593.jar!/:1.0.593]
	at tech.paramount.up.gateway.boundary.web.request.DefaultDeviceIdExtractorAndPropagator.extractAndPropagate(DeviceIdExtractorAndPropagator.kt:26) ~[!/:0.0.144-SNAPSHOT]
	at tech.paramount.up.gateway.boundary.web.routes.general.RefreshTokenRequestProcessor$apply$1.invoke(RefreshTokenRoute.kt:77) ~[!/:0.0.144-SNAPSHOT]
	at tech.paramount.up.gateway.boundary.web.routes.general.RefreshTokenRequestProcessor$apply$1.invoke(RefreshTokenRoute.kt:74) ~[!/:0.0.144-SNAPSHOT]
	at tech.paramount.up.gateway.boundary.web.routes.general.RefreshTokenRequestProcessor.apply$lambda$0(RefreshTokenRoute.kt:74) ~[!/:0.0.144-SNAPSHOT]
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:113) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2571) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.request(FluxMapFuseable.java:171) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.MonoFlatMap$FlatMapInner.onSubscribe(MonoFlatMap.java:291) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onSubscribe(FluxMapFuseable.java:96) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.MonoJust.subscribe(MonoJust.java:55) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:76) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:165) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:158) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.MonoContextWriteRestoringThreadLocals$ContextWriteRestoringThreadLocalsSubscriber.onNext(MonoContextWriteRestoringThreadLocals.java:110) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxFilterFuseable$FilterFuseableSubscriber.onNext(FluxFilterFuseable.java:118) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.Operators$BaseFluxToMonoOperator.completePossiblyEmpty(Operators.java:2097) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.MonoCollect$CollectSubscriber.onComplete(MonoCollect.java:145) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxMap$MapSubscriber.onComplete(FluxMap.java:144) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxContextWriteRestoringThreadLocals$ContextWriteRestoringThreadLocalsSubscriber.onComplete(FluxContextWriteRestoringThreadLocals.java:149) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxPeekFuseable$PeekConditionalSubscriber.onComplete(FluxPeekFuseable.java:940) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxContextWriteRestoringThreadLocals$ContextWriteRestoringThreadLocalsSubscriber.onComplete(FluxContextWriteRestoringThreadLocals.java:149) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxMap$MapConditionalSubscriber.onComplete(FluxMap.java:275) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxContextWriteRestoringThreadLocals$ContextWriteRestoringThreadLocalsSubscriber.onComplete(FluxContextWriteRestoringThreadLocals.java:149) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.netty.channel.FluxReceive.terminateReceiver(FluxReceive.java:483) ~[reactor-netty-core-1.1.18.jar!/:1.1.18]
	at reactor.netty.channel.FluxReceive.drainReceiver(FluxReceive.java:275) ~[reactor-netty-core-1.1.18.jar!/:1.1.18]
	at reactor.netty.channel.FluxReceive.request(FluxReceive.java:133) ~[reactor-netty-core-1.1.18.jar!/:1.1.18]
	at reactor.core.publisher.FluxContextWriteRestoringThreadLocals$ContextWriteRestoringThreadLocalsSubscriber.request(FluxContextWriteRestoringThreadLocals.java:163) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxMap$MapConditionalSubscriber.request(FluxMap.java:295) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxContextWriteRestoringThreadLocals$ContextWriteRestoringThreadLocalsSubscriber.request(FluxContextWriteRestoringThreadLocals.java:163) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxPeekFuseable$PeekConditionalSubscriber.request(FluxPeekFuseable.java:783) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxContextWriteRestoringThreadLocals$ContextWriteRestoringThreadLocalsSubscriber.request(FluxContextWriteRestoringThreadLocals.java:163) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxMap$MapSubscriber.request(FluxMap.java:164) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.Operators$BaseFluxToMonoOperator.request(Operators.java:2067) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxFilterFuseable$FilterFuseableSubscriber.request(FluxFilterFuseable.java:191) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.request(FluxMapFuseable.java:171) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.MonoContextWriteRestoringThreadLocals$ContextWriteRestoringThreadLocalsSubscriber.request(MonoContextWriteRestoringThreadLocals.java:156) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.request(MonoFlatMap.java:194) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.set(Operators.java:2367) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onSubscribe(FluxOnErrorResume.java:74) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:117) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.MonoContextWriteRestoringThreadLocals$ContextWriteRestoringThreadLocalsSubscriber.onSubscribe(MonoContextWriteRestoringThreadLocals.java:95) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onSubscribe(FluxMapFuseable.java:96) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxFilterFuseable$FilterFuseableSubscriber.onSubscribe(FluxFilterFuseable.java:87) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.Operators$BaseFluxToMonoOperator.onSubscribe(Operators.java:2051) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxMap$MapSubscriber.onSubscribe(FluxMap.java:92) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxContextWriteRestoringThreadLocals$ContextWriteRestoringThreadLocalsSubscriber.onSubscribe(FluxContextWriteRestoringThreadLocals.java:104) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxPeekFuseable$PeekConditionalSubscriber.onSubscribe(FluxPeekFuseable.java:816) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxContextWriteRestoringThreadLocals$ContextWriteRestoringThreadLocalsSubscriber.onSubscribe(FluxContextWriteRestoringThreadLocals.java:104) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxMap$MapConditionalSubscriber.onSubscribe(FluxMap.java:194) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.core.publisher.FluxContextWriteRestoringThreadLocals$ContextWriteRestoringThreadLocalsSubscriber.onSubscribe(FluxContextWriteRestoringThreadLocals.java:104) ~[reactor-core-3.6.5.jar!/:3.6.5]
	at reactor.netty.channel.FluxReceive.startReceiver(FluxReceive.java:172) ~[reactor-netty-core-1.1.18.jar!/:1.1.18]
	at reactor.netty.channel.FluxReceive.lambda$subscribe$2(FluxReceive.java:150) ~[reactor-netty-core-1.1.18.jar!/:1.1.18]
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173) ~[netty-common-4.1.109.Final.jar!/:4.1.109.Final]
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166) ~[netty-common-4.1.109.Final.jar!/:4.1.109.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470) ~[netty-common-4.1.109.Final.jar!/:4.1.109.Final]
	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:405) ~[netty-transport-classes-epoll-4.1.109.Final.jar!/:4.1.109.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) ~[netty-common-4.1.109.Final.jar!/:4.1.109.Final]
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.109.Final.jar!/:4.1.109.Final]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.109.Final.jar!/:4.1.109.Final]
	at java.base/java.lang.Thread.run(Unknown Source) ~[na:na

After switching otel to brave I see no duplicates anymore. The problem is only visible at one of our environments. I can't reproduce it locally unfortunately.

Any idea what could be the reason of this issue?

[marcingrzejszczak]

This might be related to #701

[marcingrzejszczak]

That issue is actually most likely a misusage of the API. Can you show us how you are actually working with baggage?

[github-actions]

If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.

[github-actions]

Closing due to lack of requested feedback. If you would like us to look at this issue, please provide the requested information and we will re-open.