Propagating TraceId Context Across Async Work

Where the Problem Started

The frustrating part of tracing is not having too few logs; it is having many logs that cannot be tied back to one request. Async work changes threads, and context can disappear at that boundary. When traceId is lost, incident analysis becomes much harder. This post records how I restored traceId propagation in a Spring Boot async flow.

In a Spring Boot service, when server logic fails, traceId is often the fastest way to find the related logs. For example, you can search for "${traceId}" in an AWS CloudWatch log group.

That makes consistent traceId logging important. In single-threaded synchronous work, it is usually straightforward.

But when you want asynchronous work, the logic may continue on another thread while it runs. In those cases, the traceId from the original thread (parent thread) can fail to propagate to the worker thread (child thread). This needs to propagate so that, if a problem occurs in the worker thread, you can follow the traceId and investigate the error efficiently.

In Spring Boot 2.x, Spring Sleuth handled traceId propagation smoothly. After moving to Spring Boot 3.x, Sleuth was deprecated and the tracing path moved toward Micrometer. Micrometer is commonly used for metrics and tracing integration, but the async traceId propagation I relied on before no longer happened automatically. This became one of several migration issues that appeared while moving existing project logic to Spring Boot 3.x.

Implementation Path

implementation("io.micrometer", "micrometer-observation")
implementation("io.micrometer", "micrometer-tracing")
implementation("io.micrometer", "micrometer-tracing-bridge-brave")
implementation("io.micrometer", "context-propagation")

Add the tracing and context propagation dependencies. The context propagation project is available here: https://github.com/micrometer-metrics/context-propagation.

@Configuration
class AsynchronousConfiguration: AsyncConfigurer {
    @Bean
    fun threadPoolTaskExecutor(): ThreadPoolTaskExecutor = ThreadPoolTaskExecutor().apply {
        corePoolSize = CORE_POOL_SIZE
        maxPoolSize = MAX_POOL_SIZE
        queueCapacity = QUEUE_CAPACITY
        setThreadNamePrefix("async-")
    }

    @Bean(ASYNC_TASK_EXECUTOR_BEAN_NAME)
    fun asyncTaskExecutor(delegate: ThreadPoolTaskExecutor): DelegatingSecurityContextAsyncTaskExecutor {
        return DelegatingSecurityContextAsyncTaskExecutor(delegate)
    }

    companion object {
        const val ASYNC_TASK_EXECUTOR_BEAN_NAME = "asyncTaskExecutor"
        const val CORE_POOL_SIZE = 10
        const val MAX_POOL_SIZE = 50
        const val QUEUE_CAPACITY = 50
    }
}

Assume a standard asynchronous configuration class. Declaring threadPoolTaskExecutor as a bean lets us configure thread pool settings such as core size, max size, and queue capacity.

After that, asynchronous methods can refer to this executor by name.

I used a small service method to observe how the async thread behaves.

One async method calls another, creating a parent/child-style async flow that makes trace propagation easier to inspect.

@Async(AsynchronousConfiguration.ASYNC_TASK_EXECUTOR_BEAN_NAME)
    fun startParentTask(traceId: String) {

        val parentThreadName = Thread.currentThread().name
        log.info("Parent task started with traceId: $traceId on thread: $parentThreadName")

        childService.startChildTask(traceId)

        Thread.sleep(1000)

        log.info("Parent task completed with traceId: $traceId on thread: $parentThreadName")
    }

First is the parent method. For thread tracing in the logs, it receives a randomly generated traceId as an argument along with the current thread name, then logs with slf4j.

I add a sleep to the Thread to artificially force the logic to take some time while it runs.

@Async(AsynchronousConfiguration.ASYNC_TASK_EXECUTOR_BEAN_NAME)
    fun startChildTask(traceId: String) {
        val childThreadName = Thread.currentThread().name
        val traceId = Thread.currentThread().stackTrace
        log.info("Child task started with traceId: $traceId on thread: $childThreadName")

        Thread.sleep(1000)

        log.info("Child task completed with traceId: $traceId on thread: $childThreadName")
    }

The child method follows the same shape.

@GetMapping("/test-trace")
    fun testTraceId(): String {
        val traceId = java.util.UUID.randomUUID().toString()
        log.info("Starting asynchronous job with traceId: $traceId")
        parentService.startParentTask(traceId)
        return "Asynchronous job started with traceId: $traceId"
    }

This controller is only for testing. It creates a random traceId, logs the request entry point, and starts the async flow so multiple requests can be sent in quick succession.

logging:
  pattern:
    dateformat: "yyyy-MM-dd HH:mm:ss.SSS"
    level: "%5p [${spring.application.name:},%X{traceId:-},%X{spanId:-}]"

Configure the log pattern so traceId and spanId are visible in every line.

Create a propagation bean through TaskDecorator.

 @Bean
    fun taskDecorator(): TaskDecorator {
        return TaskDecorator { runnable: Runnable? ->
            ContextSnapshot.captureAll(*arrayOfNulls(0)).wrap(
                runnable!!,
            )
        }
    }

https://blog.gangnamunni.com/post/mdc-context-task-decorator/ This is a somewhat old post from Gangnam Unni’s tech blog, but it solves an issue in a similar situation.

https://docs.spring.io/spring-framework/docs/current/javadoc-api/org/springframework/core/task/TaskDecorator.html This is the official TaskDecorator documentation. As the name suggests, it wraps a task before execution, which makes it a useful hook for monitoring, metrics, and context propagation.

After creating the decorator, attach it to the threadPoolTaskExecutor.

@Bean
    fun threadPoolTaskExecutor(): ThreadPoolTaskExecutor = ThreadPoolTaskExecutor().apply {
        corePoolSize = CORE_POOL_SIZE
        maxPoolSize = MAX_POOL_SIZE
        queueCapacity = QUEUE_CAPACITY
        setThreadNamePrefix("async-")
        setTaskDecorator(taskDecorator()) << 이거 추가
    }

Send several requests and check whether the logs keep the same trace context across async execution.

2024-03-09 19:51:03.182  INFO [,65ec3f17e6d38686445bf9e99014b824,445bf9e99014b824] 25486 --- [nio-8080-exec-1] kr.projects.trace.TraceController        : Starting asynchronous job with traceId: 3f0f0f1e-c0b3-4cef-99e3-7cbfd809e164
2024-03-09 19:51:03.183  INFO [,65ec3f17e6d38686445bf9e99014b824,445bf9e99014b824] 25486 --- [nio-8080-exec-1] kr.projects.trace.ParentService          : Parent task started with traceId: 3f0f0f1e-c0b3-4cef-99e3-7cbfd809e164 on thread: http-nio-8080-exec-1
2024-03-09 19:51:03.183  INFO [,65ec3f17e6d38686445bf9e99014b824,445bf9e99014b824] 25486 --- [nio-8080-exec-1] kr.projects.trace.ChildService           : Child task started with traceId: [Ljava.lang.StackTraceElement;@6223d89e on thread: http-nio-8080-exec-1
2024-03-09 19:51:04.189  INFO [,65ec3f17e6d38686445bf9e99014b824,445bf9e99014b824] 25486 --- [nio-8080-exec-1] kr.projects.trace.ChildService           : Child task completed with traceId: [Ljava.lang.StackTraceElement;@6223d89e on thread: http-nio-8080-exec-1
2024-03-09 19:51:05.191  INFO [,65ec3f17e6d38686445bf9e99014b824,445bf9e99014b824] 25486 --- [nio-8080-exec-1] kr.projects.trace.ParentService          : Parent task completed with traceId: 3f0f0f1e-c0b3-4cef-99e3-7cbfd809e164 on thread: http-nio-8080-exec-1
2024-03-09 19:51:44.421  INFO [,65ec3f40987e7c543582282a039a134d,3582282a039a134d] 25486 --- [nio-8080-exec-2] kr.projects.trace.TraceController        : Starting asynchronous job with traceId: dfebee98-f8e6-450e-be36-bd9703a46923
2024-03-09 19:51:44.434  INFO [,65ec3f40987e7c543582282a039a134d,3582282a039a134d] 25486 --- [nio-8080-exec-2] kr.projects.trace.ParentService          : Parent task started with traceId: dfebee98-f8e6-450e-be36-bd9703a46923 on thread: http-nio-8080-exec-2
2024-03-09 19:51:44.436  INFO [,65ec3f40987e7c543582282a039a134d,3582282a039a134d] 25486 --- [nio-8080-exec-2] kr.projects.trace.ChildService           : Child task started with traceId: [Ljava.lang.StackTraceElement;@7cf9c5a5 on thread: http-nio-8080-exec-2
2024-03-09 19:51:44.620  INFO [,65ec3f405ae8bf117fd3ec3d607efd2d,7fd3ec3d607efd2d] 25486 --- [nio-8080-exec-3] kr.projects.trace.TraceController        : Starting asynchronous job with traceId: 3e7b5aaf-0ee9-477b-9db9-0a8d98746945
2024-03-09 19:51:44.637  INFO [,65ec3f405ae8bf117fd3ec3d607efd2d,7fd3ec3d607efd2d] 25486 --- [nio-8080-exec-3] kr.projects.trace.ParentService          : Parent task started with traceId: 3e7b5aaf-0ee9-477b-9db9-0a8d98746945 on thread: http-nio-8080-exec-3
2024-03-09 19:51:44.637  INFO [,65ec3f405ae8bf117fd3ec3d607efd2d,7fd3ec3d607efd2d] 25486 --- [nio-8080-exec-3] kr.projects.trace.ChildService           : Child task started with traceId: [Ljava.lang.StackTraceElement;@7ebc7ff2 on thread: http-nio-8080-exec-3
2024-03-09 19:51:44.824  INFO [,65ec3f4064b2ba57b991da1e9a58f904,b991da1e9a58f904] 25486 --- [nio-8080-exec-4] kr.projects.trace.TraceController        : Starting asynchronous job with traceId: db6dee41-5500-4f49-a902-d4ed52dfdf1a
2024-03-09 19:51:44.825  INFO [,65ec3f4064b2ba57b991da1e9a58f904,b991da1e9a58f904] 25486 --- [nio-8080-exec-4] kr.projects.trace.ParentService          : Parent task started with traceId: db6dee41-5500-4f49-a902-d4ed52dfdf1a on thread: http-nio-8080-exec-4
2024-03-09 19:51:44.825  INFO [,65ec3f4064b2ba57b991da1e9a58f904,b991da1e9a58f904] 25486 --- [nio-8080-exec-4] kr.projects.trace.ChildService           : Child task started with traceId: [Ljava.lang.StackTraceElement;@2c146429 on thread: http-nio-8080-exec-4
2024-03-09 19:51:45.023  INFO [,65ec3f4105c42d6e1380816172851f52,1380816172851f52] 25486 --- [nio-8080-exec-5] kr.projects.trace.TraceController        : Starting asynchronous job with traceId: 08d2f0c0-b588-4a84-a65c-8d6c1a06993f
2024-03-09 19:51:45.024  INFO [,65ec3f4105c42d6e1380816172851f52,1380816172851f52] 25486 --- [nio-8080-exec-5] kr.projects.trace.ParentService          : Parent task started with traceId: 08d2f0c0-b588-4a84-a65c-8d6c1a06993f on thread: http-nio-8080-exec-5
2024-03-09 19:51:45.024  INFO [,65ec3f4105c42d6e1380816172851f52,1380816172851f52] 25486 --- [nio-8080-exec-5] kr.projects.trace.ChildService           : Child task started with traceId: [Ljava.lang.StackTraceElement;@27562cf1 on thread: http-nio-8080-exec-5
2024-03-09 19:51:45.220  INFO [,65ec3f41b88d12392f0aed8c54e60a0a,2f0aed8c54e60a0a] 25486 --- [nio-8080-exec-6] kr.projects.trace.TraceController        : Starting asynchronous job with traceId: 26adfe5e-2730-4a31-97eb-49c0eacb9a28
2024-03-09 19:51:45.220  INFO [,65ec3f41b88d12392f0aed8c54e60a0a,2f0aed8c54e60a0a] 25486 --- [nio-8080-exec-6] kr.projects.trace.ParentService          : Parent task started with traceId: 26adfe5e-2730-4a31-97eb-49c0eacb9a28 on thread: http-nio-8080-exec-6
2024-03-09 19:51:45.220  INFO [,65ec3f41b88d12392f0aed8c54e60a0a,2f0aed8c54e60a0a] 25486 --- [nio-8080-exec-6] kr.projects.trace.ChildService           : Child task started with traceId: [Ljava.lang.StackTraceElement;@6b7c68eb on thread: http-nio-8080-exec-6
2024-03-09 19:51:45.438  INFO [,65ec3f40987e7c543582282a039a134d,3582282a039a134d] 25486 --- [nio-8080-exec-2] kr.projects.trace.ChildService           : Child task completed with traceId: [Ljava.lang.StackTraceElement;@7cf9c5a5 on thread: http-nio-8080-exec-2
2024-03-09 19:51:45.638  INFO [,65ec3f405ae8bf117fd3ec3d607efd2d,7fd3ec3d607efd2d] 25486 --- [nio-8080-exec-3] kr.projects.trace.ChildService           : Child task completed with traceId: [Ljava.lang.StackTraceElement;@7ebc7ff2 on thread: http-nio-8080-exec-3
2024-03-09 19:51:45.829  INFO [,65ec3f4064b2ba57b991da1e9a58f904,b991da1e9a58f904] 25486 --- [nio-8080-exec-4] kr.projects.trace.ChildService           : Child task completed with traceId: [Ljava.lang.StackTraceElement;@2c146429 on thread: http-nio-8080-exec-4
2024-03-09 19:51:46.026  INFO [,65ec3f4105c42d6e1380816172851f52,1380816172851f52] 25486 --- [nio-8080-exec-5] kr.projects.trace.ChildService           : Child task completed with traceId: [Ljava.lang.StackTraceElement;@27562cf1 on thread: http-nio-8080-exec-5
2024-03-09 19:51:46.224  INFO [,65ec3f41b88d12392f0aed8c54e60a0a,2f0aed8c54e60a0a] 25486 --- [nio-8080-exec-6] kr.projects.trace.ChildService           : Child task completed with traceId: [Ljava.lang.StackTraceElement;@6b7c68eb on thread: http-nio-8080-exec-6
2024-03-09 19:51:46.442  INFO [,65ec3f40987e7c543582282a039a134d,3582282a039a134d] 25486 --- [nio-8080-exec-2] kr.projects.trace.ParentService          : Parent task completed with traceId: dfebee98-f8e6-450e-be36-bd9703a46923 on thread: http-nio-8080-exec-2
2024-03-09 19:51:46.639  INFO [,65ec3f405ae8bf117fd3ec3d607efd2d,7fd3ec3d607efd2d] 25486 --- [nio-8080-exec-3] kr.projects.trace.ParentService          : Parent task completed with traceId: 3e7b5aaf-0ee9-477b-9db9-0a8d98746945 on thread: http-nio-8080-exec-3
2024-03-09 19:51:46.830  INFO [,65ec3f4064b2ba57b991da1e9a58f904,b991da1e9a58f904] 25486 --- [nio-8080-exec-4] kr.projects.trace.ParentService          : Parent task completed with traceId: db6dee41-5500-4f49-a902-d4ed52dfdf1a on thread: http-nio-8080-exec-4
2024-03-09 19:51:47.032  INFO [,65ec3f4105c42d6e1380816172851f52,1380816172851f52] 25486 --- [nio-8080-exec-5] kr.projects.trace.ParentService          : Parent task completed with traceId: 08d2f0c0-b588-4a84-a65c-8d6c1a06993f on thread: http-nio-8080-exec-5
2024-03-09 19:51:47.226  INFO [,65ec3f41b88d12392f0aed8c54e60a0a,2f0aed8c54e60a0a] 25486 --- [nio-8080-exec-6] kr.projects.trace.ParentService          : Parent task completed with traceId: 26adfe5e-2730-4a31-97eb-49c0eacb9a28 on thread: http-nio-8080-exec-6

Traceability Takeaway

TraceId propagation is not about making logs look neat. It is about preserving the ability to reconstruct a request in production. Whenever a thread boundary appears, context propagation has to be handled explicitly, and migrations must check whether automatic behavior from older tracing libraries has disappeared.

In each line, the second and third values inside the brackets after INFO are the traceId and spanId. Even when execution crosses an async boundary, the original trace context is preserved.