ObservationAwareBaggageThreadLocalAccessor loses scopes in the wrong order

[Antosch]

Hello,

i currently use observations to handle traces. As it is currently not possible to update Baggage using the Observation API, i need to use the Tracer API directly to interact with baggage. My root problem is that i use observations in a multithreaded environment and that baggage creation somehow interferes with the traces and spans. In my case, the spans and traces are not closed properly although the observation does. As i investigated this matter further i could reproduce the behaviour with a @ParameterizedTest.
I hope that resolving this problem, can resolve my root problem.

I added a minimal reproducer for you to see the issue. Basically, i have 3 tests and an otelTracer setup.

The first test is a normal junit test which opens an observation, creates some baggage, closes the baggage, closes the observation, and then verifies that the trace context is not set outside the observation.

The second tests does the same, but using @ParameterizedTest. This test fails as the trace context is not properly closed after the observation.

The third test is calling the first test again. This time it fails, because somehow the trace context is still set from the second test.
Disabling the second test and running the whole test class again fixes the test.

My best guess is that @ParameterizedTest somehow executes the tests in parallel which interferes with the baggage scopes which in return results in wrong spans and traces.

Thanks in advance for the help and keep up the good work!

Reproducer:
micrometer-baggage-interferes-with-observation.zip

[marcingrzejszczak]

Can you check if the problem is still there using the latest snapshots? We've managed to do some improvements related to the baggage api and thread locals

[Antosch]

Hey, thanks for the suggestion. So i tried it with the 1.2.3-SNAPSHOT and with the ObservationAwareBaggageThreadLocalAccessor and it still did not work. Then i debugged the reproducer a litte more and found the problem.

The problem is that i create multiple baggage entries via tracer.createBaggageInScope() and save the scopes within a List. I assumed that closing the scopes before existing my observation was enough, but it seems that the scopes need to be closed in the reversed order that i opened them. After switching from a List to a Stack data structure and closed the scopes in reverse order, everything worked fine. (This also works on the current version 1.2.2)

I still do not know why the baggage closing order messes with observation and traces this much though.

[marcingrzejszczak]

That actually makes sense. You have to close it in the reverse order because the scopes are reverting to a previous value on close and most likely there's an issue with reverting to a wrong scope at certain moment.

[Antosch]

Hey @marcingrzejszczak ,

i noticed that micrometer-tracing 1.2.3 was released. I think that ObservationAwareBaggageThreadLocalAccessor has the same bug that was responsible for the behaviour i described above. It closes the scopes in the same order that they are opened instead of the reversed order.

In think that changing this line to return scopeClosingBaggageAndScope(entry, baggage).andThen(scope); fixes the problem.

I hope i didn't miss anything but using the current ObservationAwareBaggageThreadLocalAccessor results in the same error i had before reversing the closing order.

[jonatan-ivanov]

Do you want to open a PR to fix this (with a test that reproduces the issue)?
(I haven't dig deeper into the proposed solution but based on the above in this issue it makes sense for the first sight.)

Btw I think these are slightly connected, feel free to add 👍🏼 to them if they would be useful to you:

• Baggage support in Observation #563
• Propagating values from Observation.Context to Trace's Baggage #455

[Antosch]

Hey, will do :)

[Antosch]

Hey I created the PR. Just maybe this will also fix #625 since it was so for me.

[marcingrzejszczak]

Thank you for the PR and the fix @Antosch !