Observability of @Async annotated methods does not work

[jmecsei]

Here is an example how we can configure Spring if we want to observ the async methods:

    @Bean(name = "taskExecutor", destroyMethod = "shutdown")
    ThreadPoolTaskScheduler threadPoolTaskScheduler() {
        ThreadPoolTaskScheduler threadPoolTaskScheduler = new ThreadPoolTaskScheduler() {
            @Override
            protected ExecutorService initializeExecutor(ThreadFactory threadFactory, RejectedExecutionHandler rejectedExecutionHandler) {
                ExecutorService executorService = super.initializeExecutor(threadFactory, rejectedExecutionHandler);
                return ContextExecutorService.wrap(executorService, ContextSnapshot::captureAll);
            }
        };
        threadPoolTaskScheduler.initialize();
        return threadPoolTaskScheduler;
    }

I think this approach can not be work because, the Spring store the executor in local variable: https://github.com/spring-projects/spring-framework/blob/main/spring-context/src/m[…]ringframework/scheduling/concurrent/ThreadPoolTaskExecutor.java

Thus when we wrap the result : ContextExecutorService.wrap(executorService), the Spring uses this wrapped Executor only in shutdown() process. https://github.com/spring-projects/spring-framework/blob/main/spring-context/src/m[…]amework/scheduling/concurrent/ExecutorConfigurationSupport.java

I cc: @marcingrzejszczak according to our slack conversation

[jmecsei]

A small example to to reproduce the problem: https://github.com/jmecsei/micrometer-threadpool

[marcingrzejszczak]

@bclozel this will be related to instrumenting @Scheduled too I guess

[simonbasle]

This probably doesn't solve everything but this should get you a long way:

ThreadPoolTaskScheduler threadPoolTaskScheduler = new ThreadPoolTaskScheduler() {

	@Nullable
	ScheduledExecutorService contextScheduler;

	@Override
	public ScheduledExecutorService getScheduledExecutor() throws IllegalStateException {
		Assert.state(this.contextScheduler != null, "ThreadPoolTaskScheduler not initialized");
		return this.contextScheduler;
	}

	@Override
	protected ExecutorService initializeExecutor(ThreadFactory threadFactory, RejectedExecutionHandler rejectedExecutionHandler) {
		ExecutorService executorService = super.initializeExecutor(threadFactory, rejectedExecutionHandler);
		if (executorService instanceof ScheduledExecutorService scheduledExecutorService) {
			//the wrapped executor to be used in getScheduledExecutor(), which is used for actual task submission
			this.contextScheduler = ContextScheduledExecutorService.wrap(scheduledExecutorService, ContextSnapshot::captureAll);
			//returning the original, which will be affected to private scheduledExecutor field.
			//maintains the concrete type (notably, is it a configurable pool).
			return executorService;
		}
		throw new IllegalStateException("initializeExecutor didn't return a ScheduledExecutorService");
	}
};

[bclozel]

I don't think we should create dedicated observations for @Async methods - this is just a signal that tells Framework that this regular method should be executed asynchronously; this does not qualify as a signal that the developer wants this method to be instrumented. I think that @Scheduled methods are different there since this annotation carries a different meaning. This will be instrumented in #29883.

After chatting with @marcingrzejszczak, we agreed that context propagation should be taken care of in #29883. We'll reopen this issue if it turns out this is not enough.

I'm declining this issue as a result.

[vpavic]

Could this be reconsidered? I recently opened #30832 that was marked as a duplicate of this one.

this is just a signal that tells Framework that this regular method should be executed asynchronously

The way I see it, annotating some method with @Async is an implementation detail and I don't think that by itself should have an impact on whether some code is instrumented or not.

If some codepath is being instrumented, and somewhere along the lines it call a method that's @Async then my expectation would be that whatever happens in that method is instrumented the same way as if it wasn't @Async. Quite frequently @Async is used to invoke some non-essential but potentially expensive operations - for example, you don't want those to impact the thread that handles HTTP request but is still in some ways part of the request handling. I think it's a reasonable expectation that whatever is behind @Async to be a part of the parent trace.

[bclozel]

If some codepath is being instrumented, and somewhere along the lines it call a method that's @async then my expectation would be that whatever happens in that method is instrumented the same way as if it wasn't @async

So I guess this is not about creating observations but rather context propagation?

We could consider this, although @Async is so ubiquitous that I'm wondering if there are cases where propagating the current observation as parent doesn't make sense. For example, in cases of deferred work, using the caller context as the trace parent can break the traces because the execution is too long or happens way after the initial trace. For these cases, trace links are better choices.

After chatting with @marcingrzejszczak, we agreed that context propagation should be taken care of in #29883. We'll reopen this issue if it turns out this is not enough.

I don't think this happened in the end with the implementation for the reasons listed above. Let me think about this more.

[vpavic]

So I guess this is not about creating observations but rather context propagation?

This sounds correct as far as my expectations are concerned (ones that prompted me to open #30089). ATM I can't think of a scenario where I wouldn't want @Async code to be a part of the trace that invoked that code.

Also I should familiarize myself with the correct terminology in the whole observability area. 🙂

[marcingrzejszczak]

Wouldn't there be currently an option to just ask the user to wrap an executor service with Context Propagation API?

[bclozel]

Superseded by #31130