Spring Framework 6.2.6: deadlock when starting application after migration Spring Boot 3.3.11 to 3.4.5

[stefan-schilling]

Hello,
we're trying to migrate our applications from Spring Boot 3.3.11 (actually: 3.2.12, but everything seems to be working w/ 3.3.x). We've done that successfully for 9 of them, but 1 is showing failure below:
One of the modules define Quartz-based schedulers (total of 14), of which 3 have an issue, which kind of looks like a deadlock when launching the application.

It always gets to the message

51532 [main] INFO  org.quartz.core.QuartzScheduler - Scheduler quartzScheduler_$_linex0141746794695894 started. 
52675 [main] INFO  o.s.d.j.r.q.QueryEnhancerFactory - Hibernate is in classpath; If applicable, HQL parser will be used. 

Then we get log messages such as

51532 [main] INFO  org.quartz.core.QuartzScheduler - Scheduler quartzScheduler_$_linex0141746794695894 started. 
52675 [main] INFO  o.s.d.j.r.q.QueryEnhancerFactory - Hibernate is in classpath; If applicable, HQL parser will be used. 
52817 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'manualReactivationActivationService' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, dealerService] 
52818 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'manualReactivationActivationWorker' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, dealerService, manualReactivationActivationService] 
52821 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'vehicleActivationService' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, manualReactivationActivationWorker, dealerService, manualReactivationActivationService] 
52825 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'VSActivationFacadeFactory' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, manualReactivationActivationWorker, dealerService, manualReactivationActivationService, vehicleActivationService] 
52828 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'liveActivationFacade' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, manualReactivationActivationWorker, dealerService, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
52830 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'VSRestTemplateFactory' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, manualReactivationActivationWorker, dealerService, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
52833 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'vehicleServiceMileageTemplate' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
52838 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'vsRestTemplate' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
52838 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'VSRestTemplateConfig' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, vsRestTemplate, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
52912 [quartzScheduler_QuartzSchedulerThread] INFO  c.e.d.g.c.vs.VSRestTemplateConfig - Trying to set proxy for rest template. Host:  Port:  
52937 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'vehicleservice-com.exxeta.dfstp.geofence.core.vs.VehicleServiceConfig' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
52976 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'vehicleServiceExceptionHandler' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
52992 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'vehicleServiceGeneralSubscriptionTemplate' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
53092 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'circuitBreakerAspect' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
53092 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'io.github.resilience4j.springboot3.circuitbreaker.autoconfigure.CircuitBreakerConfigurationOnMissingBean' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
53094 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'resilience4j.circuitbreaker-io.github.resilience4j.springboot3.circuitbreaker.autoconfigure.CircuitBreakerProperties' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, io.github.resilience4j.springboot3.circuitbreaker.autoconfigure.CircuitBreakerConfigurationOnMissingBean, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
53396 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'circuitBreakerRegistry' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
53397 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'eventConsumerRegistry' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, circuitBreakerRegistry, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
53443 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'circuitBreakerRegistryEventConsumer' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, circuitBreakerRegistry, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
53447 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'taggedCircuitBreakerMetricsPublisher' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, circuitBreakerRegistryEventConsumer, liveActivationFacade, VSRestTemplateFactory, circuitBreakerRegistry, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
53449 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'io.github.resilience4j.springboot3.circuitbreaker.autoconfigure.CircuitBreakerMetricsAutoConfiguration' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, circuitBreakerRegistryEventConsumer, liveActivationFacade, taggedCircuitBreakerMetricsPublisher, VSRestTemplateFactory, circuitBreakerRegistry, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
53545 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'compositeCircuitBreakerCustomizer' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, circuitBreakerRegistry, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
53718 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'fallbackExecutor' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
53725 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'io.github.resilience4j.springboot3.fallback.autoconfigure.FallbackConfigurationOnMissingBean' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, fallbackExecutor, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
53746 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'spelResolver' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, fallbackExecutor, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
53747 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'io.github.resilience4j.springboot3.spelresolver.autoconfigure.SpelResolverConfigurationOnMissingBean' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, fallbackExecutor, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, spelResolver, circuitBreakerAspect, vehicleActivationService] 
53762 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'spelExpressionParser' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, fallbackExecutor, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, spelResolver, circuitBreakerAspect, vehicleActivationService] 
53769 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'parameterNameDiscoverer' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, fallbackExecutor, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, spelResolver, circuitBreakerAspect, vehicleActivationService] 
53797 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'fallbackDecorators' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, fallbackExecutor, manualReactivationActivationWorker, dealerService, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
53801 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'completionStageFallbackDecorator' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, fallbackExecutor, manualReactivationActivationWorker, dealerService, fallbackDecorators, vehicleServiceMileageTemplate, VSActivationFacadeFactory, manualReactivationActivationService, circuitBreakerAspect, vehicleActivationService] 
54117 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'vehicleServicePositionOffTemplate' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
54121 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'stockService' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, vehicleServicePositionOffTemplate, addDealerConcurrentWfsImportProcessService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
54128 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'vehicleRepositoryImpl' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, vehicleServicePositionOffTemplate, addDealerConcurrentWfsImportProcessService, stockService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
54150 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'vehicleRepository' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, vehicleServicePositionOffTemplate, addDealerConcurrentWfsImportProcessService, stockService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, dealerService, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
54153 [quartzScheduler_QuartzSchedulerThread] INFO  o.s.b.f.s.DefaultListableBeanFactory - Obtaining singleton bean 'jpa.named-queries#1' in thread "quartzScheduler_QuartzSchedulerThread" while other thread holds singleton lock for other beans [dealerRepository, vehicleServicePositionOffTemplate, addDealerConcurrentWfsImportProcessService, stockService, liveActivationFacade, VSRestTemplateFactory, manualReactivationActivationWorker, vehicleRepository, dealerService, VSActivationFacadeFactory, manualReactivationActivationService, vehicleActivationService] 
170041 [QuartzScheduler_quartzScheduler-linex0141746794695894_MisfireHandler] INFO  o.s.s.q.LocalDataSourceJobStore - Handling 4 trigger(s) that missed their scheduled fire-time. 

The last message gets repeated after some time, I guess, Quartz notices, that a job wasn't finished.

But the application does not continue to be fully started (e.g. Tomcat won't finish its boot and therefore does not request any ports for it).
Sadly, I cannot debug this, since logging class o.s.b.f.s.DefaultListableBeanFactory doesn't print message "Obtaining singleton bean ..." anywhere. So I don't know where to look.

On the other hand, if I disable the 3 (out of 14) schedulers, the application will boot successfully.

I never get any error message, so there seems to be no timeout involved.

Since we're using Spring Framework 6.2.6, we're not getting
org.springframework.beans.factory.BeanCurrentlyInCreationException as #34373 reported.

I cannot give you a reduced sample application, since our code seems to be ok (all services injected here are used by other services, too - but their presence does not prevent the application from starting). It fails for this specific combination only. And: though it currently quite persistently fails on my machine, my colleague currently cannot reproduce the issue using Intellij - but when he runs the jar file on his Mac, it fails there, too.

Sorry for being so unspecific, but this looks like a time/order related thing.

[jhoeller]

This seems to be similar to the previously reported Pekko scenarios where your scheduler gets activated before all the common beans are created. This could be solved through ordering: making sure that the common beans come first in the order of definition, possibly with the scheduled declaring @DependsOn on those common beans. That said, as of 6.2.6 we also have a Spring property that can be set for strict locking: see #34303 (comment) - I recommend to give that a try, it should restore the pre-6.2 locking behavior for your scenario as well.

For Quartz specifically, it could also help to specify a startupDelay on SchedulerFactoryBean so that the main bootstrap thread could finish the initialization of all common beans before any of the Quartz triggers fire. This should work as long as those common beans are not marked as lazy-init.

[stefan-schilling]

Hello @jhoeller ,
thanks for your quick response.

I've added config setting spring.locking.strict=true, but that didn't change anything.

I also replaced org.quartz.Scheduler.start() (what we used to employ) by org.quartz.Scheduler.startDelayed(5) - that doesn't change anything either - except, that it now takes +5 seconds.

If I disable org.quartz.Scheduler.start()/startDelayed(x) completely, the application starts w/o any issues - but the schedulers are missing, of course.

Thanks.
Stefan

[jhoeller]

Just double-checking: Where have you been setting spring.locking.strict=true? This only works in a spring.properties file in the root of the classpath or as a JVM system property. If declared and picked up correctly, the log message "Obtaining singleton bean ... while other thread holds singleton lock for other beans" cannot appear anymore.

If a delayed start of the scheduler does not change anything, I wonder what your main bootstrap thread does in the meantime - since it should continue initializing the non-lazy singleton beans in the order of definition. Are those affected common beans declared as lazy-init by any chance?

Also, if you perform the Quartz Scheduler start manually rather than through Spring's Quartz integration, you should make sure to do so in a Lifecycle.start implementation (ideally paired with a Scheduler.standby call in Lifecycle.stop like Spring's SchedulerFactoryBean) or in a SmartInitializingSingleton.afterSingletonsInstantiated() implementation. Either way, this defers Scheduler initialization after common singleton bean initialization.

[stefan-schilling]

Hello @jhoeller ,

I'm sorry, I just added that config option to the application.yml - not as VM parameter. Changing that, it worked :)

Thanks a lot.
Stefan

[sbrannen]

Thanks for the feedback, @stefan-schilling.

I'll close this issue now.