Spring/Ticketing 프로젝트

비동기 환경에서 Request를 유지하려면 어떻게 해야할까?

minturtle 2024. 11. 15. 15:42
반응형

개요

  • Spring Web MVC 환경에서 request 마다 유지되는 값이 존재할 때, 고민해야할 점이 하나 생겼습니다. 바로 비동기 환경에서 request 마다 유지되는 값을 전달해 줄 수 있을까? 만약 잘 동작하지 않는다면 어떻게 해야할까? 에 대한 고민입니다.

 

상황 설명

  • 상황은 아래와 같습니다. 아래와 같이 Logging을 찍는 AOP 코드가 있다고 가정해보겠습니다.
@Component
@Scope(scopeName = "request", proxyMode = ScopedProxyMode.TARGET_CLASS)
class RequestId(
    val id :String = createId()
){
    companion object{
        fun createId() : String{
            return UUID.randomUUID().toString().substring(0, 7)
        }
    }
}
@Aspect
@Component
class LoggingAspect(
    private val requestId: RequestId
) {
    private val log = LoggerFactory.getLogger(LoggingAspect::class.java)

    @Pointcut("@within(com.example.demo.aspect.Logging) || @annotation(com.example.demo.aspect.Logging)")
    fun loggingPointcut() {}

    @Around("loggingPointcut()")
    fun logExecutionTime(joinPoint: ProceedingJoinPoint): Any?{
        val methodSignature = joinPoint.signature as MethodSignature
        val className = joinPoint.target.javaClass.simpleName
        val methodName = methodSignature.name

        log.info("[{}] started {}.{}",requestId.id, className, methodName)
        val proceed = joinPoint.proceed()
        log.info("[{}] ended {}.{}",requestId.id, className, methodName)

        return proceed
    }
}
  • requestId는 Request Scope Bean으로, requestId는 각 요청마다 고유의 8글자 ID를 가져 요청을 구분하는 역할을 합니다.
// 요청 1
[d1fec1e] started TestController.testAsync
[d1fec1e] started TestService.testAsync
// 요청 2
[11f2b54] started TestController.testAsync
[11f2b54] started TestService.testAsync
  • 근데 만약 비동기 메서드를 호출할 때는 어떻게 동작하게 될지 궁금해서 한번 간단하게 코드를 작성해보았습니다.

Spring의 @Async 어노테이션을 사용하여 비동기적인 호출

  • 만약 AsyncService의 메서드가 Async 어노테이션이 적용되어 있으면 어떨까요? 먼저 코드를 보겠습니다.
@Logging
fun testB(): String{
    asyncService.methodB()
    return Random.nextInt().toString()
}
@Async
@Logging
fun methodB(){
    println("async method completed")
}

 

[ca8773f] started TestService.testB [ca8773f] ended TestService.testB org.springframework.beans.factory.support.ScopeNotActiveException: Error creating bean with name 'scopedTarget.requestId': Scope 'request' is not active for the current thread; consider defining a scoped proxy for this bean if you intend to refer to it from a singleton at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:385) ~[spring-beans-6.1.13.jar:6.1.13] at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:200) ~[spring-beans-6.1.13.jar:6.1.13] at org.springframework.aop.target.SimpleBeanTargetSource.getTarget(SimpleBeanTargetSource.java:35) ~[spring-aop-6.1.13.jar:6.1.13] at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:704) ~[spring-aop-6.1.13.jar:6.1.13] at com.example.demo.bean.RequestId$$SpringCGLIB$$0.getId(<generated>) ~[main/:na] at com.example.demo.aspect.LoggingAspect.logExecutionTime(LoggingAspect.kt:31) ~[main/:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[na:na] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na] at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
  • AsyncService의 로그가 정상적으로 찍히지 않았고, Exception이 throw되었습니다. Exception은 LoggingAspect에서 Request Scope를 벗어났기 때문에 RequestId 빈을 가져올 수 없다는 것이었습니다.

 

해결 방안 1 : LoggingAspect의 순서를 지정해주기

  • 그럼 이 경우에는 어떻게 해야할까요? 먼저 내가 가장 먼저 생각한 방법은 AsyncService의 실제 메서드(methodB)가 비동기 적으로 실행되기 전에 먼저 로그를 찍는 것이었습니다. 예상하는 프로세스는 다음과 같습니다.
LoggingAspect의 start log 출력 -> 비동기 메서드(Async 프록시) 실행 -> 비동기 메서드의 결과를 기다리지 않고 end log를 출력
@Logging
fun testB(): String{
    asyncService.methodB()
    return Random.nextInt().toString()
}
@Async
@Logging
fun methodB(){
    println("async method completed")
}

 

[ca8773f] started TestService.testB [ca8773f] ended TestService.testB org.springframework.beans.factory.support.ScopeNotActiveException: Error creating bean with name 'scopedTarget.requestId': Scope 'request' is not active for the current thread; consider defining a scoped proxy for this bean if you intend to refer to it from a singleton at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:385) ~[spring-beans-6.1.13.jar:6.1.13] at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:200) ~[spring-beans-6.1.13.jar:6.1.13] at org.springframework.aop.target.SimpleBeanTargetSource.getTarget(SimpleBeanTargetSource.java:35) ~[spring-aop-6.1.13.jar:6.1.13] at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:704) ~[spring-aop-6.1.13.jar:6.1.13] at com.example.demo.bean.RequestId$$SpringCGLIB$$0.getId(<generated>) ~[main/:na] at com.example.demo.aspect.LoggingAspect.logExecutionTime(LoggingAspect.kt:31) ~[main/:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na] at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[na:na] at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na] at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
  • AsyncService의 로그가 정상적으로 찍히지 않았고, Exception이 throw되었습니다. Exception은 LoggingAspect에서 Request Scope를 벗어났기 때문에 RequestId 빈을 가져올 수 없다는 것이었습니다.

 

 

해결 방안 2 : executor의 TaskDecorator을 적용하기

  • 그래서 다음으로 생각한 방법은 @Async가 실행할 Executor이 실행되기 전에 requestId를 다음 스레드에 전파하는 방식입니다. @Async는 executor을 지정해 줄 수 있는데, executor에 데코레이터 패턴을 적용하여 실제 비동기 메서드(methodB)가 실행되기 전에 값을 옮겨 줄 수 있다고 합니다.

 

  • 다만 이 방식은 Proxy기반의 Request Scope Bean으로는 어려웠고, ThreadLocal로 저장 방식을 변경해야만 가능했습니다.
  • 따라서 먼저 기존의 코드를 RequestIdHolder에서 꺼내오도록 변경하였습니다.
object RequestIdHolder {

    private val threadLocal = ThreadLocal<RequestId>()

    fun get() : RequestId?{
        return threadLocal.get()
    }
    fun setAndGetResult(requestId: RequestId = RequestId()): RequestId{
        threadLocal.set(requestId)
        return requestId
    }
    fun release(){
        threadLocal.remove()
    }

}
@Around("loggingPointcut()")
fun logExecutionTime(joinPoint: ProceedingJoinPoint): Any?{
		 // ...
    val requestId = RequestIdHolder.get() ?: RequestIdHolder.setAndGetResult()
    // ...
    RequestIdHolder.release()
}

 

  • 마지막으로 Executor를 선언한 코드는 다음과 같습니다.
@Configuration
class AsyncThreadPoolConfig {


    @Bean
    fun asyncExecutor1(): Executor {
        val executor = ThreadPoolTaskExecutor()
        executor.corePoolSize = 5
        val taskDecorator = TaskDecorator {
            val currentRequestId = RequestIdHolder.get() ?: RequestIdHolder.setAndGetResult()
            Runnable {
                RequestIdHolder.setAndGetResult(currentRequestId)
                it.run()
                RequestIdHolder.release()
            }
        }
        executor.setTaskDecorator(
            taskDecorator
        )
        executor.initialize()
        return executor
    }
}

 

  • 코드를 설명하면 다음과 같습니다.
val currentRequestId = RequestIdHolder.get() ?:
	 RequestIdHolder.setAndGetResult()

요청이 유지되고 있는, 즉 LoggingAspect에 의해 RequestId가 ThreadLocal에 설정된 Thread에서 requestId 정보를 가져옵니다. setAndGetResult 메서드는 이전의 메서드가 LoggingAspect를 사용하지 않다가, @Async 메서드가 최초로 LoggingAspect를 사용한다면 호출되는 메서드 입니다.

 

 

Runnable {
	RequestIdHolder.setAndGetResult(currentRequestId)
	it.run()
	RequestIdHolder.release()
}
  • 해당 코드는 Runnable, 즉 Async 메서드가 실행되기 전에 이전의 RequestId를 Set하는 메서드입니다. 이렇게 함으로써 다른 스레드를 사용하더라도 RequestId를 전파할 수 있습니다.

결론

  • 이렇게 함으로써 정상적으로 에 requestId를 전파할 수 있었습니다.
[52da28b] started TestService.testB
[52da28b] started AsyncService.methodB
[52da28b] ended TestService.testB
async method completed
[52da28b] ended AsyncService.methodB

 

반응형