Skip to content

Close scope is not idempotent #5055

@lmolkova

Description

@lmolkova

Describe the bug
The following test (with obviously wrong behavior) fails

@Test
void closeTest()  {
    var span1 = getTracer().spanBuilder("foo").startSpan();
    var scope1 = span1.makeCurrent();
    var span2 = getTracer().spanBuilder("bar").startSpan();
    var scope2 = span2.makeCurrent();

    // span2 is current
    scope2.close();

    // span1 is current
    scope1.close();

     // no current span
    assertFalse(Span.current().getSpanContext().isValid());

    // !!!
    scope2.close();

    // fails here, span1 is current
    assertFalse(Span.current().getSpanContext().isValid());
}

What happens:

  • scope2 captures span1 as 'before' state
  • so any time scope2 is closed, it restores span1 and makes it current.

Context beforeAttach = current();
if (toAttach == beforeAttach) {
return NoopScope.INSTANCE;
}
THREAD_LOCAL_STORAGE.set(toAttach);
return () -> {
if (current() != toAttach) {
logger.log(
Level.FINE,
"Context in storage not the expected context, Scope.close was not called correctly");
}
THREAD_LOCAL_STORAGE.set(beforeAttach);
};
}

Steps to reproduce
the test above

What did you expect to see?
Close should be idempotent - after scope is closed, calling close should be noop.

It's also strongly encouraged according to docs

What did you see instead?
close is not idempotent.

What version and what artifacts are you using?
Artifacts: opentelemetry-api, opentelemetry-sdk
Version: 1.21.0
How did you reference these artifacts? (excerpt from your build.gradle, pom.xml, etc)

<opentelemetry-version>1.21.0</opentelemetry-version>
...
        <dependency>
            <groupId>io.opentelemetry</groupId>
            <artifactId>opentelemetry-sdk</artifactId>
            <version>${opentelemetry-version}</version>
        </dependency>
        <dependency>
            <groupId>io.opentelemetry</groupId>
            <artifactId>opentelemetry-api</artifactId>
            <version>${opentelemetry-version}</version>
        </dependency>

Environment
Compiler: "AdoptOpenJDK 17.0.4.8"
OS: windows

Additional context
I'm trying to propagate spans in Camel (so that camel spans are correlated with spans from underlying libraries). Camel tracing is based on events that are not tracing-specific. Consequently, it's impossible (without significant refactoring) to guarantee that current span scope will be called exactly once.
And while it's possible to implement idempotency with wrapping scope, OTel should do it out of the box.

It also seems that

if (current() != toAttach) {
logger.log(
Level.FINE,
"Context in storage not the expected context, Scope.close was not called correctly");
}
THREAD_LOCAL_STORAGE.set(beforeAttach);

is a bit dangerous regardless of idempotency. Arguably, if this.current() != toAttach , it's best to do nothing or set an invalid context to minimize the side-effects of wrong operations with scope.

The proposal here is to do

      if (current() == toAttach) {
          THREAD_LOCAL_STORAGE.set(beforeAttach);
      } else {
        logger.log(
            Level.WARN,
            "Context in storage not the expected context, Scope.close was not called correctly");
     }

Another proposal is to remember the thread id span was made current on and do nothing when attempting to close scope on a different thread.
Otherwise, what happens is that 'before' span from the different thread leaks to another thread where it can no longer be closed.

Metadata

Metadata

Assignees

Labels

BugSomething isn't working

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions