opentracing-contrib / java-spring-web

OpenTracing Spring Web instrumentation
Apache License 2.0
107 stars 59 forks source link

Bug: Span has already been finished; will not be reported again #129

Open shtaft opened 4 years ago

shtaft commented 4 years ago

Hey team! We've recently stumbled on a bit of a contrived bug in this library when using it with Webflux.

We are subscribing to a Flux. This Flux makes requests to a paged API. Each element emitted by the Flux is a response (page).

In our situation, we'd like to perform a one-time action on the first page. We achieved this using take. When calling take(1) on the Flux, a "complete" event is fired for the first element emitted by the flux, which is captured in the TracingClientResponseSubscriber onComplete handler here. Shortly afterwards, however, a cancel event is fired for the Flux (this is the behavior of take). This cancel event is picked up in the TracingClientResponseSubscriber subscription here.

The end result is that the span is "finished" twice, and a warning is logged.

Expected Behavior

Span is only finished once

Actual Behavior

Spans are finished twice when using the take API- once during a complete event, and again when a cancel event is fired. When using the Flux.take API, a cancel event can follow a complete event.

The work around currently is to not use take() or anything that will emit a complete event followed by a cancel event.

pavolloffay commented 4 years ago

hi @shtaft thanks for reporting this issue. The multiple finish type of error is sometimes hard to solve if the framework invokes calculation multiple times.

Would you like to submit a PR to fix this? IIRC in some cases we had used a wrapper for span to avoid double finish.

micand91 commented 3 years ago

Hi,

Is there any progress or proposed solution/workaround for this issue? My analysis concludes that this does not have any functional impact on our application, besides the WARN trace that pollutes the log. I am correct in analysis?