Login/Register
Spring boot context load test hangs
Asked Answered
spring-bootspring-data-jpahikaricpspring-boot-test
P

0

10

We have a Spring Boot app written in Kotlin. The problem is it hangs during Maven clean test while running context load test below.

Java: 14.0.1 Kotlin: 1.4.20 Spring boot:2.3.6.RELEASE Spring cloud:Hoxton.SR9

@SpringBootTest
@ActiveProfiles("test")

class AppTest {

  @Test
  fun contextLoads() {
    assertTrue(true)
  }
}

I created a thread dump and was able to see DataSourceInitializedPublisher cannot publish event because it was blocked

"task-2" #24 prio=5 os_prio=0 cpu=15.63ms elapsed=1851.84s tid=0x0000019de7f8d800 nid=0x7dfc waiting for monitor entry  [0x00000030ceffe000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:217)
    - waiting to lock <0x0000000704600310> (a java.util.concurrent.ConcurrentHashMap)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:322)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:207)
    at org.springframework.context.event.AbstractApplicationEventMulticaster.retrieveApplicationListeners(AbstractApplicationEventMulticaster.java:247)
    at org.springframework.context.event.AbstractApplicationEventMulticaster.getApplicationListeners(AbstractApplicationEventMulticaster.java:204)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:134)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:404)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:361)
    at org.springframework.boot.autoconfigure.orm.jpa.DataSourceInitializedPublisher.publishEventIfRequired(DataSourceInitializedPublisher.java:110)
    at org.springframework.boot.autoconfigure.orm.jpa.DataSourceInitializedPublisher.access$300(DataSourceInitializedPublisher.java:55)
    at org.springframework.boot.autoconfigure.orm.jpa.DataSourceInitializedPublisher$DataSourceSchemaCreatedPublisher.lambda$postProcessEntityManagerFactory$0(DataSourceInitializedPublisher.java:253)
    at org.springframework.boot.autoconfigure.orm.jpa.DataSourceInitializedPublisher$DataSourceSchemaCreatedPublisher$$Lambda$1023/0x000000080152fc40.run(Unknown Source)
    at java.util.concurrent.Executors$RunnableAdapter.call([email protected]/Executors.java:515)
    at java.util.concurrent.FutureTask.run([email protected]/FutureTask.java:264)
    at java.util.concurrent.ThreadPoolExecutor.runWorker([email protected]/ThreadPoolExecutor.java:1130)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run([email protected]/ThreadPoolExecutor.java:630)
    at java.lang.Thread.run([email protected]/Thread.java:832)

   Locked ownable synchronizers:
    - <0x0000000706936bc0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

When I loocked for the lock 0x0000000704600310 I found

"main" #1 prio=5 os_prio=0 cpu=9937.50ms elapsed=1905.03s tid=0x0000019dc195e800 nid=0xa6c8 waiting on condition  [0x00000030cc0fa000]
   java.lang.Thread.State: WAITING (parking)
    at jdk.internal.misc.Unsafe.park([email protected]/Native Method)
    - parking to wait for  <0x00000007069372a0> (a java.util.concurrent.FutureTask)
    at java.util.concurrent.locks.LockSupport.park([email protected]/LockSupport.java:211)
    at java.util.concurrent.FutureTask.awaitDone([email protected]/FutureTask.java:447)
    at java.util.concurrent.FutureTask.get([email protected]/FutureTask.java:190)
    at org.springframework.boot.autoconfigure.orm.jpa.DataSourceInitializedPublisher$DataSourceInitializationCompletionListener.onApplicationEvent(DataSourceInitializedPublisher.java:148)
    at org.springframework.boot.autoconfigure.orm.jpa.DataSourceInitializedPublisher$DataSourceInitializationCompletionListener.onApplicationEvent(DataSourceInitializedPublisher.java:138)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:172)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:165)
    at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:139)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:404)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:410)
    at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:361)
    at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:898)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:554)
    - locked <0x0000000706a009b0> (a java.lang.Object)
    at org.springframework.cloud.context.named.NamedContextFactory.createContext(NamedContextFactory.java:137)
    at org.springframework.cloud.context.named.NamedContextFactory.getContext(NamedContextFactory.java:102)
    - locked <0x0000000706a3b728> (a java.util.concurrent.ConcurrentHashMap)
    at org.springframework.cloud.context.named.NamedContextFactory.getInstance(NamedContextFactory.java:146)
    at org.springframework.cloud.openfeign.FeignClientFactoryBean.get(FeignClientFactoryBean.java:281)
    at org.springframework.cloud.openfeign.FeignClientFactoryBean.feign(FeignClientFactoryBean.java:101)
    at org.springframework.cloud.openfeign.FeignClientFactoryBean.getTarget(FeignClientFactoryBean.java:337)
    at org.springframework.cloud.openfeign.FeignClientFactoryBean.getObject(FeignClientFactoryBean.java:327)
    at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.doGetObjectFromFactoryBean(FactoryBeanRegistrySupport.java:169)
    at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.getObjectFromFactoryBean(FactoryBeanRegistrySupport.java:101)
    - locked <0x0000000704600310> (a java.util.concurrent.ConcurrentHashMap)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getObjectForBeanInstance(AbstractBeanFactory.java:1828)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.getObjectForBeanInstance(AbstractAutowireCapableBeanFactory.java:1265)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:261)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:276)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.addCandidateEntry(DefaultListableBeanFactory.java:1532)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.findAutowireCandidates(DefaultListableBeanFactory.java:1489)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1270)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1227)
    at org.springframework.beans.factory.support.ConstructorResolver.resolveAutowiredArgument(ConstructorResolver.java:884)
    at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:788)
    at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:227)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireConstructor(AbstractAutowireCapableBeanFactory.java:1356)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1203)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:556)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:516)
    at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:324)
    at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$480/0x0000000800e2f840.getObject(Unknown Source)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
    - locked <0x0000000704600310> (a java.util.concurrent.ConcurrentHashMap)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:322)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:276)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1307)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1227)
    at org.springframework.beans.factory.support.ConstructorResolver.resolveAutowiredArgument(ConstructorResolver.java:884)
    at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:788)
    at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:227)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireConstructor(AbstractAutowireCapableBeanFactory.java:1356)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1203)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:556)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:516)
    at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:324)
    at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$480/0x0000000800e2f840.getObject(Unknown Source)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234)
    - locked <0x0000000704600310> (a java.util.concurrent.ConcurrentHashMap)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:322)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:897)
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:879)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:551)
    - locked <0x000000070471a538> (a java.lang.Object)
    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:758)
    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:750)
    at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:405)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:315)
    at org.springframework.boot.test.context.SpringBootContextLoader.loadContext(SpringBootContextLoader.java:120)
    at org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate.loadContextInternal(DefaultCacheAwareContextLoaderDelegate.java:99)
    at org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate.loadContext(DefaultCacheAwareContextLoaderDelegate.java:124)
    - locked <0x000000070396ad88> (a org.springframework.test.context.cache.DefaultContextCache)
    at org.springframework.test.context.support.DefaultTestContext.getApplicationContext(DefaultTestContext.java:123)
    at org.springframework.test.context.web.ServletTestExecutionListener.setUpRequestContextIfNecessary(ServletTestExecutionListener.java:190)
    at org.springframework.test.context.web.ServletTestExecutionListener.prepareTestInstance(ServletTestExecutionListener.java:132)
    at org.springframework.test.context.TestContextManager.prepareTestInstance(TestContextManager.java:244)
    at org.springframework.test.context.junit.jupiter.SpringExtension.postProcessTestInstance(SpringExtension.java:98)
    at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.lambda$invokeTestInstancePostProcessors$5(ClassBasedTestDescriptor.java:341)
    at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor$$Lambda$366/0x0000000800d38840.execute(Unknown Source)
    at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.executeAndMaskThrowable(ClassBasedTestDescriptor.java:346)
    at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.lambda$invokeTestInstancePostProcessors$6(ClassBasedTestDescriptor.java:341)
    at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor$$Lambda$365/0x0000000800d38440.accept(Unknown Source)
    at java.util.stream.StreamSpliterators$WrappingSpliterator$$Lambda$158/0x0000000800be6040.accept([email protected]/Unknown Source)
    at java.util.stream.ReferencePipeline$3$1.accept([email protected]/ReferencePipeline.java:195)
    at java.util.stream.ReferencePipeline$2$1.accept([email protected]/ReferencePipeline.java:177)
    at java.util.ArrayList$ArrayListSpliterator.forEachRemaining([email protected]/ArrayList.java:1624)
    at java.util.stream.AbstractPipeline.copyInto([email protected]/AbstractPipeline.java:484)
    at java.util.stream.AbstractPipeline.wrapAndCopyInto([email protected]/AbstractPipeline.java:474)
    at java.util.stream.StreamSpliterators$WrappingSpliterator.forEachRemaining([email protected]/StreamSpliterators.java:312)
    at java.util.stream.Streams$ConcatSpliterator.forEachRemaining([email protected]/Streams.java:735)
    at java.util.stream.Streams$ConcatSpliterator.forEachRemaining([email protected]/Streams.java:734)
    at java.util.stream.ReferencePipeline$Head.forEach([email protected]/ReferencePipeline.java:658)
    at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.invokeTestInstancePostProcessors(ClassBasedTestDescriptor.java:340)
    at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.instantiateAndPostProcessTestInstance(ClassBasedTestDescriptor.java:263)
    at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.lambda$testInstancesProvider$2(ClassBasedTestDescriptor.java:256)
    at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor$$Lambda$359/0x0000000800c79840.get(Unknown Source)
    at java.util.Optional.orElseGet([email protected]/Optional.java:362)
    at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.lambda$testInstancesProvider$3(ClassBasedTestDescriptor.java:255)
    at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor$$Lambda$262/0x0000000800c1b840.getTestInstances(Unknown Source)
    at org.junit.jupiter.engine.execution.TestInstancesProvider.getTestInstances(TestInstancesProvider.java:29)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$prepare$0(TestMethodTestDescriptor.java:108)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor$$Lambda$358/0x0000000800c7a440.execute(Unknown Source)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.prepare(TestMethodTestDescriptor.java:107)
    at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.prepare(TestMethodTestDescriptor.java:71)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$prepare$1(NodeTestTask.java:107)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$217/0x0000000800bf9c40.execute(Unknown Source)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.prepare(NodeTestTask.java:107)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:75)
    at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService$$Lambda$235/0x0000000800c14440.accept(Unknown Source)
    at java.util.ArrayList.forEach([email protected]/ArrayList.java:1510)
    at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$231/0x0000000800c13440.execute(Unknown Source)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$230/0x0000000800c13040.invoke(Unknown Source)
    at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$229/0x0000000800c12c40.execute(Unknown Source)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
    at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService$$Lambda$235/0x0000000800c14440.accept(Unknown Source)
    at java.util.ArrayList.forEach([email protected]/ArrayList.java:1510)
    at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$231/0x0000000800c13440.execute(Unknown Source)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:125)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$230/0x0000000800c13040.invoke(Unknown Source)
    at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:135)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:123)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$229/0x0000000800c12c40.execute(Unknown Source)
    at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:122)
    at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:80)
    at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:32)
    at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
    at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:51)
    at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:220)
    at org.junit.platform.launcher.core.DefaultLauncher.lambda$execute$6(DefaultLauncher.java:188)
    at org.junit.platform.launcher.core.DefaultLauncher$$Lambda$200/0x0000000800bfe840.accept(Unknown Source)
    at org.junit.platform.launcher.core.DefaultLauncher.withInterceptedStreams(DefaultLauncher.java:202)
    at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:181)
    at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:128)
    at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invokeAllTests(JUnitPlatformProvider.java:150)
    at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invoke(JUnitPlatformProvider.java:124)
    at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
    at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
    at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
    at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)

   Locked ownable synchronizers:
    - None

This thread is waiting for 0x00000007069372a0 which I could not find any reference in the dump. In the docs for DataSourceInitializationCompletionListener

{@link ApplicationListener} that, upon receiving {@link ContextRefreshedEvent}, * blocks until any asynchronous DataSource initialization has completed.

The publisher cannot publish because it is blocked and this listener is blocking until that event comes.It is some sort of deadlock I suppose. I could not find on whom the DataSourceInitializedPublisher is waitng. Can anyone help me on this ?

Potage answered 30/11, 2020 at 17:33 Comment(4)
It might be related to issue 24027 – Potage
Do you have any custom logic that gets executed on application startup? If so, can you please add it here – Weinstock
We have a lot of @Configuration classes which i cannot paste here. But I resolved the issue by setting spring.data.jpa.repositories.bootstrap-mode from deferred (which was defaultValue) to default in the test profile. – Potage
It might be related to issue github.com/spring-cloud/spring-cloud-openfeign/issues/443 – Conure

© 2022 - 2024 — McMap. All rights reserved.