Spring BeanPostProcessor 관련 WARN 로그 발생 원인 및 해결

1. 배경

스프링부트 실행 시 다음과 같은 WARN 로그 발생.

2025-06-25T11:05:17.775+09:00  WARN 39055 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'shedlockConfig' of type [com.aptner.utility.config.ShedlockConfig$$SpringCGLIB$$0] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying). Is this bean getting eagerly injected into a currently created BeanPostProcessor [proxyScheduledLockAopBeanPostProcessor]? Check the corresponding BeanPostProcessor declaration and its dependencies.
2025-06-25T11:05:17.778+09:00  WARN 39055 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'databaseRoutingConfiguration' of type [com.aptner.utility.config.datasource.DatabaseRoutingConfiguration$$SpringCGLIB$$0] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying). Is this bean getting eagerly injected into a currently created BeanPostProcessor [proxyScheduledLockAopBeanPostProcessor]? Check the corresponding BeanPostProcessor declaration and its dependencies.
2025-06-25T11:05:18.082+09:00  WARN 39055 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'readWriteDataSource' of type [com.zaxxer.hikari.HikariDataSource] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying). Is this bean getting eagerly injected into a currently created BeanPostProcessor [proxyScheduledLockAopBeanPostProcessor]? Check the corresponding BeanPostProcessor declaration and its dependencies.
2025-06-25T11:05:18.214+09:00  WARN 39055 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'readOnlyDataSource' of type [com.zaxxer.hikari.HikariDataSource] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying). Is this bean getting eagerly injected into a currently created BeanPostProcessor [proxyScheduledLockAopBeanPostProcessor]? Check the corresponding BeanPostProcessor declaration and its dependencies.
2025-06-25T11:05:18.220+09:00  WARN 39055 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'routingDataSource' of type [com.aptner.utility.config.datasource.TransactionRoutingDataSource] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying). Is this bean getting eagerly injected into a currently created BeanPostProcessor [proxyScheduledLockAopBeanPostProcessor]? Check the corresponding BeanPostProcessor declaration and its dependencies.
2025-06-25T11:05:18.221+09:00  WARN 39055 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'dataSource' of type [org.springframework.jdbc.datasource.LazyConnectionDataSourceProxy] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying). Is this bean getting eagerly injected into a currently created BeanPostProcessor [proxyScheduledLockAopBeanPostProcessor]? Check the corresponding BeanPostProcessor declaration and its dependencies.
2025-06-25T11:05:18.230+09:00  WARN 39055 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'lockProvider' of type [net.javacrumbs.shedlock.provider.jdbctemplate.JdbcTemplateLockProvider] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying). Is this bean getting eagerly injected into a currently created BeanPostProcessor [proxyScheduledLockAopBeanPostProcessor]? Check the corresponding BeanPostProcessor declaration and its dependencies.

모두가 가리키는 곳은!

 

Bean X of type Y is not eligible for getting processed by all BeanPostProcessors…
Is this bean getting eagerly injected into a currently created BeanPostProcessor?
Check the corresponding BeanPostProcessor declaration and its dependencies.

 

해석해 봅시다…

“빈 X가 너무 일찍 생성되어 일부 BeanPostProcessor의 처리를 놓쳤을 수 있습니다.

혹시 지금 생성 중인 BeanPostProcessor가 이 빈을 먼저 참조한 건 아닌지 확인해 보세요.”

 

왜 이런 일이 일어나죠? 어떻게 해결하죠?

 

2. 조치 과정

2-1. 스프링의 빈 생성 시점

1. @Component, @Service, @Repository, @Configuration, @Controller 등
   빈으로 등록할 대상 클래스들을 찾는다.
2. 이중 BeanPostProcessor를 먼저 인스턴스화하여 컨테이너에 등록한다. 예를 들어, @Transactional이 붙은 서비스 빈을 프록시로 감싸주는 AnnotationAwareAspectJAutoProxyCreator도 이 단계에서 등록되는 BeanPostProcessor 중 하나다.
3. 이후 나머지 일반 bean을 인스턴스화되면서 BPP들의 후처리를 거치게 된다. 이때 AOP, 트랜잭션, 프록시 생성과 같은 처리가 이루어진다.

2-2. WARN 발생의 이유

• 2 → 3 순서로 가지 않고, 3 → 2 순서로 가는 bean이 발생했다? 스프링은 이를 눈치채고 warning을 띄운다.
• 다시 말해 BPP가 ‘모두(왜 ‘모두’인지는 끝에…)’ 등록되지 않았는데 일반 bean이 먼저 생성되었음을 알려주는 로그이다.
• 이 경우 @Transactional, @Async, @Scheduled, AOP 프록시 등의 적용에 문제가 ‘생길 수도’ 있으므로 spring이 이를 감지하고 경고를 날린다.

2-3. 그럼 왜 이 bean들은 먼저 등록되었을까?

// 문제가 되는 bean들

// DatabaseRoutingConfiguration.class
databaseRoutingConfiguration
readWriteDataSource
readOnlyDataSource
routingDataSource
dataSource

// ShedlockConfig.class
shedlockConfig
lockProvider

1. ShedlockConfig bean 생성 시 dataSource bean을 들고오려 하면서 미리 초기화 시도가 일어난다.

@Bean
public LockProvider lockProvider(@Qualifier("dataSource") DataSource dataSource) {
    return new JdbcTemplateLockProvider(dataSource);
}

 

2. SchedulerLock 어노테이션이 ShedlockConfig의 내용을 참조하면서 미리 초기화 시도가 일어난다.

public class ExampleScheduler {

    private final ExampleRepository exampleRepository;

    @SchedulerLock(name = "changeStatus", lockAtLeastForString = "PT1S", lockAtMostForString = "PT10S")
    @Scheduled(cron = "0 0 0 * * *")
    @Transactional
    public void changeStatus() {...}
    
}

2-4. 해결

@Bean
public LockProvider lockProvider(@Lazy @Qualifier("dataSource") DataSource dataSource) {
    return new JdbcTemplateLockProvider(dataSource);
}

1. @Lazy를 lockProvider의 파라미터에 붙인다.

• Spring이 lockProvider 빈을 생성할 때 dataSource를 당장 초기화하지 않는다.
• JdbcTemplateLockProvider 생성 시점에 dataSource.getConnection() 을 호출하며 초기화한다.
• 따라서 dataSource 빈은 AnnotationAwareAspectJAutoProxyCreator(BPP 중 하나. @Transactional이 붙은 빈들의 프록시 빈을 만들어준다) 생성 이후 안정적인 시점 이후에 초기화된다.

 

2. SchedulerLock 문제 → 그대로 두기로 결정

• ShedlockConfig에게 필요한 BPP는 proxyScheduledLockAopBeanPostProcessor.
• 로그를 보면 필요한 BPP 이후 lockProvider, shedlockConfig가 생성되는 것을 볼 수 있다.

Creating shared instance of singleton bean ...
'org.springframework.context.annotation.internalScheduledAnnotationProcessor'
'org.springframework.scheduling.annotation.SchedulingConfiguration'
'proxyScheduledLockAopBeanPostProcessor'
'net.javacrumbs.shedlock.spring.annotation.SchedulerProxyLockConfiguration'
'lockProvider'
'shedlockConfig'​

• 그렇다면 왜 여전히 WARN 로그가 발생하는가?

출처 : https://velog.io/@dailylifecoding/Spring-BeanPostProcessor-Weird-Warning-Log

• Spring은 내부적으로 BPP의 전체 목표 개수를 기억해둔다.
• if 문을 보면 다음과 같은 일을 하는데…
  • if (현재까지 등록된 BPP의 개수 < 전체 BPP의 목표 개수)
• 따라서 이 조건은 ‘특정 bean이 필요한 BPP 이후 생성되는가'가 아니라 ‘전체 BPP 이후 생성되는가’를 본다.

 

• shedlock 테이블 확인 결과 락은 잘 걸리고 있음. WARN 로그는 빈의 조기 초기화를 경고하는 수준이며, 실제 BPP 이후에 초기화된 로그가 확인되었으므로 안전하다고 판단. 수정하려면 @SchedulerLock 을 사용하지 않고 수동으로 lock을 걸어야 하는데 이 방향이 맞는지 의문이 들어 어노테이션 유지.
• 앞의 datasource 빈도 @lazy 붙이지 않아도 트랜잭션 잘 걸리는 것을 로그로 확인(필요한 BPP 이후 생성되는 것도 확인)하였지만 문제 해결이 비교적 간단하여 간단한 수정을 진행.

 

3. 다짐

• 앞으로 각 빈들이 서로 초기화되는 시기를 신경쓰고 config를 작성할 것.