open-telemetry / opentelemetry-java-instrumentation

OpenTelemetry auto-instrumentation and instrumentation libraries for Java
https://opentelemetry.io
Apache License 2.0
1.94k stars 850 forks source link

Can't get TraceId in Guava's AsyncEventbus @Subscribe method. #6273

Open xuminwlt opened 2 years ago

xuminwlt commented 2 years ago

Describe the bug

A simple demo use -javaagent with 1.15.0 version.

@Slf4j
@Component
public class EventBusPublisher {

    AsyncEventBus asyncEventBus;
    private ExecutorService pool = Executors.newFixedThreadPool(10);
    private AsyncCall asyncCall;

public void publish(Integer number) {
        asyncEventBus.post(number);
    }
Other class:
 @Subscribe
        public void listenInteger(Integer param) {
//use api get TraceId
            log.info("listenInteger:{}, {}", param, Span.current().getSpanContext().getTraceId());

        }

Steps to reproduce

eventBusPublisher.publish(1);

Can't get TraceId in subscribe method.

But I can get TraceId in normal executor.execute()

this.eventBusPublisher.getPool().execute(new Runnable() {
            public void run() {
                log.info("call:{}, {}", i, Span.current().getSpanContext().getTraceId());
            }
        });

I have got the code in guava , It's also use the same class and method executor.execute(.

final void dispatchEvent(final Object event) {
        this.executor.execute(new Runnable() {
            public void run() {
                try {
                    Subscriber.this.invokeSubscriberMethod(event);
                } catch (InvocationTargetException var2) {
                    Subscriber.this.bus.handleSubscriberException(var2.getCause(), Subscriber.this.context(event));
                }

            }
        });
    }

What did you expect to see? A clear and concise description of what you expected to see.

Why i get different result.

What did you see instead? A clear and concise description of what you saw instead.

What version are you using? (e.g., v1.15.0, ``, etc)

Environment Compiler: (e.g., "AdoptOpenJDK 11.0.6") OS: (e.g., "MacOS") Runtime (if different from JDK above): (e.g., "Oracle JRE 8u251")

mateuszrzeszutek commented 2 years ago

It's not a bug, but rather a missing feature -- we simply don't have an instrumentation for Guava's EventBus.

xuminwlt commented 2 years ago

Thanks, i have read the code of the EventBus LegacyAsyncDispatcher. There is a queue and a while {} scope defined in

private final ConcurrentLinkedQueue<EventWithSubscriber> queue =
        Queues.newConcurrentLinkedQueue();

--- 
EventWithSubscriber e;
      while ((e = queue.poll()) != null) {
        e.subscriber.dispatchEvent(e.event);
      }

And the thread Event run path will be:

Main Thread A(Tomcat Http Thread) do post(Event) -> queue.add(Event) 
-> Thread B(Tomcat Http Thread) poll the Event 
-> Thread B do Executor.execute() 
-> Thread A do something other 
-> Thread B do something other

When Thread B do post got the Event from Thread A and do dispatch (Executor.execute), Thread B also have other thing todo. The Thread B context need keep it's own Context.

The Thread B may do something like:

1. Spring Controller got a API call
2. EventBus post
2.0 EventBus poll a Event1(From Thread B)
2.0.1 Eventbus dispatch(Executor.execute-1) -> subscribe.doSomething()
2.1 EventBus poll a Event1(From Thread A)
2.1.1 EventBus dispatch(Executor.execute-2) -> subscribe.doSomething()
3 okhttp -> other thing

In my option. Enter the eventbus dispatch scope, store the current snapshot context, and wrap the main thread context to the event. Exit the eventbus scopre, set the snapshot context to current.

It's like a thread-cross producer-consumer question. any idea to do it?