스프링

spring sleuth Executor를 bean으로 생성했을때 traceId가 공유되는 방식

du.study 2022. 11. 10. 00:31
728x90

오늘은 간단한 내용을 작성해보려 합니다.

 

Spring 에서 로그 추적을 위해 traceId를 남기고자 sleuth를 사용하고 있습니다.

운영과정에서 일부 비동기 로직에서 traceId가 남지않는것을 확인하였고, 이 부분에 대해 확인한것을 기록하고자 합니다.

 

사실 해결법은 매우 간단하지만(검색하면 바로) 왜 동작하는지는 알고 바꾸고자 한번 작성하게되었습니다.

 

먼저 bean으로 생성하는경우를 확인하고자 합니니다.

   @Bean(name = "예시니까 세팅은 전부 1")
    public Executor threadPoolTaskExecutor() {
        ThreadPoolTaskExecutor taskExecutor = new ThreadPoolTaskExecutor();
        taskExecutor.setCorePoolSize(1);
        taskExecutor.setMaxPoolSize(1);
        taskExecutor.setQueueCapacity(1.);
        taskExecutor.setThreadNamePrefix("test-");
        taskExecutor.initialize();
        return taskExecutor;
    }

다음과 같은 로직을 통하여 Executor를 생성하는경우, 그리고 sleuth를 dependency에 가지고 있는 경우, 

 

sleuth package에 있는 다음 클레스를 통해 빈 등록과정에서 조금 특이한 과정을 거치게 됩니다.
아래는 그 코드의 설정 부분을 가져왔습니다.

/**
 * Bean post processor that wraps a call to an {@link Executor} either in a JDK or CGLIB
 * proxy. Depending on whether the implementation has a final method or is final.
 *
 * @author Marcin Grzejszczak
 * @author Jesus Alonso
 * @author Denys Ivano
 * @author Vladislav Fefelov
 * @since 1.1.4
 */
class ExecutorBeanPostProcessor implements BeanPostProcessor {
.....
	@Override
	public Object postProcessAfterInitialization(Object bean, String beanName)
			throws BeansException {
		if (bean instanceof LazyTraceThreadPoolTaskExecutor
				|| bean instanceof TraceableScheduledExecutorService
				|| bean instanceof TraceableExecutorService
				|| bean instanceof LazyTraceAsyncTaskExecutor
				|| bean instanceof LazyTraceExecutor) {
			log.info("Bean is already instrumented " + beanName);
			return bean;
		}
		if (bean instanceof ThreadPoolTaskExecutor) {
			if (isProxyNeeded(beanName)) {
				return wrapThreadPoolTaskExecutor(bean);
			}
			else {
				log.info("Not instrumenting bean " + beanName);
			}
		}
		else if (bean instanceof ScheduledExecutorService) {
			if (isProxyNeeded(beanName)) {
				return wrapScheduledExecutorService(bean);
			}
			else {
				log.info("Not instrumenting bean " + beanName);
			}
		}
		else if (bean instanceof ExecutorService) {
			if (isProxyNeeded(beanName)) {
				return wrapExecutorService(bean);
			}
			else {
				log.info("Not instrumenting bean " + beanName);
			}
		}
		else if (bean instanceof AsyncTaskExecutor) {
			if (isProxyNeeded(beanName)) {
				return wrapAsyncTaskExecutor(bean);
			}
			else {
				log.info("Not instrumenting bean " + beanName);
			}
		}
		else if (bean instanceof Executor) {
			return wrapExecutor(bean);
		}
		return bean;
	}
.....
}

보면 빈을 등록하는 과정에서 각 Executor를 생성하는 로직이 들어있습니다. 

제가 설정한건 ThreadPoolTaskExecutor 였으니 이 내부에 생성하는 로직을 보면 다음과 같이 LazyTraceThreadPoolTaskExecutor

를 생성하는 로직이 있습니다.

Object createThreadPoolTaskExecutorProxy(Object bean, boolean cglibProxy,
    ThreadPoolTaskExecutor executor) {
  if (!cglibProxy) {
    return new LazyTraceThreadPoolTaskExecutor(this.beanFactory, executor);
  }
  return getProxiedObject(bean, cglibProxy, executor,
      () -> new LazyTraceThreadPoolTaskExecutor(this.beanFactory, executor));
}

그러면 LazyTraceThreadPoolTaskExecutor에서 execute할때 무슨 동작이 일어날까 해서 보았더니 아래 코드와 같이 bean에서 Tracing을 꺼내와 사용합니다.

@Override
public void execute(Runnable task) {
  this.delegate.execute(ContextUtil.isContextUnusable(this.beanFactory) ? task
      : new TraceRunnable(tracing(), spanNamer(), task));
}

private Tracing tracing() {
  if (this.tracing == null) {
    this.tracing = this.beanFactory.getBean(Tracing.class);
  }
  return this.tracing;
}

 

이러한 설정 덕분에 bean으로 초기 생성한경우, 별도의 설정없이도 각 thread간 traceId가 잘 유지되는데요. 

 

 

그렇다면 운영중에는 대체 왜 traceId가 전파가 안되었을까 하여 찾아보는 도중.. 각 @Component에서 threadPool을 생성하여 사용하는 로직을 발견했습니다.  예를 들자면..

 this.executorService = (ThreadPoolExecutor) Executors.newFixedThreadPool(1); // 예시니까 1

bean 생성자에 요런건 생성해두고 이런 thread를 사용하는 코드들이 남아있었고.. 공교롭게 이코드가 대부분의 로그를 찍고있었고 이를 이유로 traceId가 정상적으로 노출이 안되는 문제가 발생했었습니다.

 

이부분을 ThreadPoolExecutor를  bean으로 생성하여 주입하는 방식으로 문제를 해결하였습니다.

728x90