java-spring-cloud icon indicating copy to clipboard operation
java-spring-cloud copied to clipboard

Support propagating trace context to callback

Open JasonMing opened this issue 4 years ago • 7 comments

Implements #286 .

The CompletableFuture returned by ListenableFuture.completable() is not injected yet, because there is too much methods to be processed. And the injection to CompletableFuture should be feature of java-concurrent project. I'll open an issue for CompletableFuture injection in java-concurrent project.

JasonMing avatar May 01 '20 16:05 JasonMing

@JasonMing thanks for the comments. Ping me when I would re-review/merge.

pavolloffay avatar May 06 '20 06:05 pavolloffay

@pavolloffay I fix some CRs, and some might still need more discussions.

span removed from TracedListenableFuture

The ListenableFutures are always created and returned immediately, as you said, it better indicates intentions that we just propagate spans. However, tracer has been kept for now. I afraid changing Tracer to ScopeManager would break user's behavior and make them confusing about how to get the ScopeManager.

span still kept in TracedListenableFutureCallback

Sometimes, the context(span) in listener should be use the one on creating future instead of adding listener.

ListenableFuture<?> call() {
    try (Scope scope = GlobalTracer.get().activate(span)) {
        return taskExecutor.submitListenable(() -> ......);
    }
}

void main() {
    // The listener adds here is out of the expected scope.
    // But the listener operations should consider as a part of call() but not main()
    call().addListener(....);
}

JasonMing avatar May 06 '20 08:05 JasonMing

@JasonMing could you be more specific about the open questions?

In your code snippet about the scope created in call() would be the same as in main()

pavolloffay avatar May 07 '20 07:05 pavolloffay

@pavolloffay here is an example (some insignificant codes are hidden)

private static ListenableFuture<?> call() {
  // create a sub span of 'main'
  Span span = GlobalTracer.get().buildSpan("call").start();
  try (Scope scope = GlobalTracer.get().activateSpan(span)) {
    return TASK_EXECUTOR.submitListenable(() -> {

      // the async task started in scope 'call',  current activeSpan() should be 'call'
      LOGGER.info("async task span: " + GlobalTracer.get().activeSpan());

      // simulate blocking calls, let callback run out of main thread
      LockSupport.parkNanos(TimeUnit.MILLISECONDS.toNanos(1000));
    });
  } finally {
    span.finish();
  }
}

public static void main(String[] args) {
  // the root span 'main'
  Span span = GlobalTracer.get().buildSpan("main").start();
  try (Scope scope = GlobalTracer.get().activateSpan(span)) {
    ListenableFuture<?> future = call();

    // here, we add callback after 'call()' method returned, in the 'main' scope
    future.addCallback(r -> {

      // current activeSpan() should be 'call', not 'main'
      LOGGER.info("callback span: " + GlobalTracer.get().activeSpan());

    }, e -> {});
  } finally {
    span.finish();
  }
}

If we remove the span in TracedListenableFutureCallback, force getting span from current context. The callback span will be changed to 'main', because the callback is added in 'main' scope. However, we cannot force all the users adding callback in the task starting scope. So, we should propagate the specific span to the callback instead of getting from current context directly.

JasonMing avatar May 08 '20 08:05 JasonMing

Can we store the active span when submitListenable is created and use it as an active span for callbacks?

It will also often happen that active span from call will be finished when future/callback will be called.

pavolloffay avatar May 08 '20 14:05 pavolloffay

Yes, that's what I do now. The ListenableFuture returned by submitListenable has already captured the active span in the callsite's thread. This span will be propagated to all ListenableFutureCallback which registered by addCallback. That why I want to keep the span field/constructor-parameter in ListenableFutureCallback.

JasonMing avatar May 08 '20 17:05 JasonMing

Drive-by comment, use as you wish. This feature probably won't stop at maintaining a span, as people will now start to expect that spans activated in one of the callbacks should be the new active span in callbacks in following stages.

If you like, have a look at context-propagation-java8/ContextAwareCompletableFuture.java.

Doing this correctly not as easy as it seems at first.

sjoerdtalsma avatar May 11 '20 05:05 sjoerdtalsma