search

spring-projects / spring-framework

Spring Framework
https://spring.io/projects/spring-framework
Apache License 2.0
56.62k stars 38.13k forks source link

Spring Boot 2.3.0 won't start with hibernate.search.FieldBridge annotation in use #25111

Closed knoobie closed 11 months ago

knoobie commented 4 years ago

Using the annotation org.hibernate.search.FieldBridge in a spring boot 2.3.0 project resulting in a "dead-lock". The application won't start. Removing the annotation fixes it.

Example (Java 8):

https://github.com/knoobie/spring-2-3-fieldbridge

1) The application is still on 2.2.6 -> mvn clean install -> tests are working 2) Update to 2.3.0 -> mvn clean install -> 

2020-05-20 10:13:39.710 DEBUG 18503 --- [         task-1] o.h.s.b.impl.lucene.WorkspaceFactory     : Starting workspace for index xxx.backend.entities.Question using an exclusive index strategy
2020-05-20 10:13:39.715 DEBUG 18503 --- [         task-1] o.h.s.b.impl.lucene.SyncWorkProcessor    : HSEARCH000230: Starting sync consumer thread for index 'de.dvzmv.service.help.service.backend.entities.Question'
2020-05-20 10:13:39.715 DEBUG 18503 --- [         task-1] o.h.s.b.impl.lucene.WorkspaceHolder      : HSEARCH000235: Backend for index 'xxx.backend.entities.Question' started: using a Synchronous batching backend.
2020-05-20 10:13:39.766 DEBUG 18503 --- [         task-1] o.h.s.i.i.LuceneEmbeddedIndexFamilyImpl  : Setting Lucene compatibility to Version 5.5.5
2020-05-20 10:13:39.777 DEBUG 18503 --- [         task-1] o.h.s.e.m.i.AnnotationMetadataProvider   : Found JPA id and using it as document id
2020-05-20 10:13:39.781 DEBUG 18503 --- [         task-1] o.h.s.e.m.i.AnnotationMetadataProvider   : Found JPA id and using it as document id
-- no more logs --

3) When @FieldBridge line is removed from Answer the application is running again, but the test fails (as expected).

Thread dump:

2020-05-20 10:46:25
Full thread dump OpenJDK 64-Bit Server VM (25.252-b09 mixed mode):

"Attach Listener" spring-projects/spring-boot#361 daemon prio=9 os_prio=0 tid=0x00007ff484001000 nid=0x7f21 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Hibernate Search sync consumer thread for index xxx.backend.entities.Question" spring-projects/spring-boot#360 daemon prio=5 os_prio=0 tid=0x00007ff44452d800 nid=0x7ec6 waiting on condition [0x00007ff45e1f8000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:338)
    at org.hibernate.search.backend.impl.lucene.SyncWorkProcessor.parkCurrentThread(SyncWorkProcessor.java:179)
    at org.hibernate.search.backend.impl.lucene.SyncWorkProcessor.access$300(SyncWorkProcessor.java:37)
    at org.hibernate.search.backend.impl.lucene.SyncWorkProcessor$Consumer.run(SyncWorkProcessor.java:149)
    at java.lang.Thread.run(Thread.java:748)

"task-1" spring-projects/spring-boot#359 prio=5 os_prio=0 tid=0x00007ff461434800 nid=0x7ec5 waiting for monitor entry [0x00007ff45eef7000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:183)
    - waiting to lock <0x00000006893d0330> (a java.util.concurrent.ConcurrentHashMap)
    at org.springframework.beans.factory.support.AbstractBeanFactory.isTypeMatch(AbstractBeanFactory.java:517)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doGetBeanNamesForType(DefaultListableBeanFactory.java:533)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeanNamesForType(DefaultListableBeanFactory.java:505)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeanNamesForType(DefaultListableBeanFactory.java:482)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeanNamesForType(DefaultListableBeanFactory.java:475)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveNamedBean(DefaultListableBeanFactory.java:1158)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveBean(DefaultListableBeanFactory.java:422)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBean(DefaultListableBeanFactory.java:352)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBean(DefaultListableBeanFactory.java:345)
    at org.springframework.orm.hibernate5.SpringBeanContainer.createBean(SpringBeanContainer.java:151)
    at org.springframework.orm.hibernate5.SpringBeanContainer.getBean(SpringBeanContainer.java:110)
    at org.hibernate.search.cfg.impl.HibernateOrmBeanContainerBeanResolver.resolve(HibernateOrmBeanContainerBeanResolver.java:63)
    at org.hibernate.search.engine.service.beanresolver.impl.ReflectionFallbackBeanResolver.resolve(ReflectionFallbackBeanResolver.java:40)
    at org.hibernate.search.bridge.impl.BridgeFactory.createFieldBridgeFromAnnotation(BridgeFactory.java:371)
    at org.hibernate.search.bridge.impl.BridgeFactory.findExplicitFieldBridge(BridgeFactory.java:350)
    at org.hibernate.search.bridge.impl.BridgeFactory.buildFieldBridge(BridgeFactory.java:203)
    at org.hibernate.search.engine.metadata.impl.AnnotationMetadataProvider.bindFieldAnnotation(AnnotationMetadataProvider.java:1335)
    at org.hibernate.search.engine.metadata.impl.AnnotationMetadataProvider.checkForField(AnnotationMetadataProvider.java:1258)
    at org.hibernate.search.engine.metadata.impl.AnnotationMetadataProvider.initializeMemberLevelAnnotations(AnnotationMetadataProvider.java:1065)
    at org.hibernate.search.engine.metadata.impl.AnnotationMetadataProvider.initializeClass(AnnotationMetadataProvider.java:615)
    at org.hibernate.search.engine.metadata.impl.AnnotationMetadataProvider.checkForIndexedEmbedded(AnnotationMetadataProvider.java:1924)
    at org.hibernate.search.engine.metadata.impl.AnnotationMetadataProvider.initializeMemberLevelAnnotations(AnnotationMetadataProvider.java:1074)
    at org.hibernate.search.engine.metadata.impl.AnnotationMetadataProvider.initializeClass(AnnotationMetadataProvider.java:615)
    at org.hibernate.search.engine.metadata.impl.AnnotationMetadataProvider.doGetTypeMetadataFor(AnnotationMetadataProvider.java:192)
    at org.hibernate.search.engine.metadata.impl.AnnotationMetadataProvider.getTypeMetadataFor(AnnotationMetadataProvider.java:181)
    at org.hibernate.search.engine.metadata.impl.AnnotationMetadataProvider.getTypeMetadataFor(AnnotationMetadataProvider.java:165)
    at org.hibernate.search.spi.SearchIntegratorBuilder.initDocumentBuilders(SearchIntegratorBuilder.java:445)
    at org.hibernate.search.spi.SearchIntegratorBuilder.createNewFactoryState(SearchIntegratorBuilder.java:244)
    at org.hibernate.search.spi.SearchIntegratorBuilder.buildNewSearchFactory(SearchIntegratorBuilder.java:200)
    at org.hibernate.search.spi.SearchIntegratorBuilder.buildSearchIntegrator(SearchIntegratorBuilder.java:128)
    at org.hibernate.search.hcore.impl.HibernateSearchSessionFactoryObserver.boot(HibernateSearchSessionFactoryObserver.java:127)
    - locked <0x000000068afdc268> (a org.hibernate.search.hcore.impl.HibernateSearchSessionFactoryObserver)
    at org.hibernate.search.hcore.impl.HibernateSearchSessionFactoryObserver.sessionFactoryCreated(HibernateSearchSessionFactoryObserver.java:94)
    at org.hibernate.internal.SessionFactoryObserverChain.sessionFactoryCreated(SessionFactoryObserverChain.java:35)
    at org.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:380)
    at org.hibernate.boot.internal.SessionFactoryBuilderImpl.build(SessionFactoryBuilderImpl.java:468)
    at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:1249)
    at org.springframework.orm.jpa.vendor.SpringHibernateJpaPersistenceProvider.createContainerEntityManagerFactory(SpringHibernateJpaPersistenceProvider.java:58)
    at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:365)
    at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.buildNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:391)
    at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean$$Lambda$806/120136606.call(Unknown Source)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

"container-0" spring-projects/spring-boot#358 prio=5 os_prio=0 tid=0x00007ff46011a000 nid=0x7ec4 waiting on condition [0x00007ff45effa000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at org.apache.catalina.core.StandardServer.await(StandardServer.java:570)
    at org.springframework.boot.web.embedded.tomcat.TomcatWebServer$1.run(TomcatWebServer.java:197)

"Catalina-utility-2" spring-projects/spring-boot#357 prio=1 os_prio=0 tid=0x00007ff458002800 nid=0x7ec3 waiting on condition [0x00007ff45f0fb000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x0000000689a6bf78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)

"Catalina-utility-1" spring-projects/spring-boot#356 prio=1 os_prio=0 tid=0x00007ff46121a800 nid=0x7ec2 waiting on condition [0x00007ff45f9fe000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x0000000689a6bf78> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)

"webpack" spring-projects/spring-boot#355 daemon prio=5 os_prio=0 tid=0x00007ff4612ed000 nid=0x7eb6 runnable [0x00007ff45f3fc000]
   java.lang.Thread.State: RUNNABLE
    at java.io.FileInputStream.readBytes(Native Method)
    at java.io.FileInputStream.read(FileInputStream.java:255)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:284)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
    - locked <0x000000068af7b7b0> (a java.lang.UNIXProcess$ProcessPipeInputStream)
    at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
    at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
    at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
    - locked <0x000000068b380150> (a java.io.InputStreamReader)
    at java.io.InputStreamReader.read(InputStreamReader.java:184)
    at java.io.BufferedReader.fill(BufferedReader.java:161)
    at java.io.BufferedReader.readLine(BufferedReader.java:324)
    - locked <0x000000068b380150> (a java.io.InputStreamReader)
    at java.io.BufferedReader.readLine(BufferedReader.java:389)
    at com.vaadin.flow.server.DevModeHandler.readLinesLoop(DevModeHandler.java:458)
    at com.vaadin.flow.server.DevModeHandler.lambda$logStream$1(DevModeHandler.java:436)
    at com.vaadin.flow.server.DevModeHandler$$Lambda$770/1410478418.run(Unknown Source)
    at java.lang.Thread.run(Thread.java:748)

"process reaper" spring-projects/spring-boot#353 daemon prio=10 os_prio=0 tid=0x00007ff4612e9800 nid=0x7ea1 runnable [0x00007ff49c0c3000]
   java.lang.Thread.State: RUNNABLE
    at java.lang.UNIXProcess.waitForProcessExit(Native Method)
    at java.lang.UNIXProcess.lambda$initStreams$3(UNIXProcess.java:289)
    at java.lang.UNIXProcess$$Lambda$760/842129709.run(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

"Thread-340" spring-projects/spring-boot#352 daemon prio=5 os_prio=0 tid=0x00007ff4612e2000 nid=0x7e9f runnable [0x00007ff45f4fd000]
   java.lang.Thread.State: RUNNABLE
    at java.net.PlainSocketImpl.socketAccept(Native Method)
    at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
    at java.net.ServerSocket.implAccept(ServerSocket.java:560)
    at java.net.ServerSocket.accept(ServerSocket.java:528)
    at com.vaadin.flow.server.DevServerWatchDog$WatchDogServer.run(DevServerWatchDog.java:58)
    at java.lang.Thread.run(Thread.java:748)

"HikariPool-1 housekeeper" spring-projects/spring-boot#350 daemon prio=5 os_prio=0 tid=0x00007ff460f65000 nid=0x7e9c waiting on condition [0x00007ff49dc21000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x0000000689acdf98> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

"restartedMain" spring-projects/spring-boot#11 prio=5 os_prio=0 tid=0x00007ff46c003000 nid=0x7d4b waiting on condition [0x00007ff49df1e000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x000000068acd0fd0> (a java.util.concurrent.FutureTask)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:429)
    at java.util.concurrent.FutureTask.get(FutureTask.java:191)
    at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.getNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:540)
    at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.invokeProxyMethod(AbstractEntityManagerFactoryBean.java:497)
    at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean$ManagedEntityManagerFactoryInvocationHandler.invoke(AbstractEntityManagerFactoryBean.java:680)
    at com.sun.proxy.$Proxy111.getMetamodel(Unknown Source)
    at org.springframework.data.jpa.repository.config.JpaMetamodelMappingContextFactoryBean$$Lambda$841/1869811997.apply(Unknown Source)
    at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:193)
    at java.util.Iterator.forEachRemaining(Iterator.java:116)
    at java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801)
    at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:482)
    at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:472)
    at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708)
    at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
    at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:566)
    at org.springframework.data.jpa.repository.config.JpaMetamodelMappingContextFactoryBean.getMetamodels(JpaMetamodelMappingContextFactoryBean.java:106)
    at org.springframework.data.jpa.repository.config.JpaMetamodelMappingContextFactoryBean.createInstance(JpaMetamodelMappingContextFactoryBean.java:80)
    at org.springframework.data.jpa.repository.config.JpaMetamodelMappingContextFactoryBean.createInstance(JpaMetamodelMappingContextFactoryBean.java:44)
    at org.springframework.beans.factory.config.AbstractFactoryBean.afterPropertiesSet(AbstractFactoryBean.java:142)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1855)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1792)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:595)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517)
    at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:323)
    at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$180/1416025551.getObject(Unknown Source)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:226)
    - locked <0x00000006893d0330> (a java.util.concurrent.ConcurrentHashMap)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:330)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:113)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1699)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1444)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:594)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517)
    at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:323)
    at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$180/1416025551.getObject(Unknown Source)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:226)
    - locked <0x00000006893d0330> (a java.util.concurrent.ConcurrentHashMap)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:207)
    at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1114)
    at org.springframework.data.repository.support.Repositories.cacheRepositoryFactory(Repositories.java:99)
    - locked <0x000000068b380f48> (a org.springframework.data.repository.support.Repositories)
    at org.springframework.data.repository.support.Repositories.populateRepositoryFactoryInformation(Repositories.java:92)
    at org.springframework.data.repository.support.Repositories.<init>(Repositories.java:85)
    at org.springframework.data.repository.support.DomainClassConverter.setApplicationContext(DomainClassConverter.java:109)
    at org.springframework.data.web.config.SpringDataWebConfiguration.addFormatters(SpringDataWebConfiguration.java:130)
    at org.springframework.web.servlet.config.annotation.WebMvcConfigurerComposite.addFormatters(WebMvcConfigurerComposite.java:81)
    at org.springframework.web.servlet.config.annotation.DelegatingWebMvcConfiguration.addFormatters(DelegatingWebMvcConfiguration.java:78)
    at org.springframework.boot.autoconfigure.web.servlet.WebMvcAutoConfiguration$EnableWebMvcConfiguration.mvcConversionService(WebMvcAutoConfiguration.java:435)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:154)
    at org.springframework.beans.factory.support.ConstructorResolver.instantiate(ConstructorResolver.java:651)
    at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:636)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1338)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1177)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:557)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517)
    at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:323)
    at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$180/1416025551.getObject(Unknown Source)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:226)
    - locked <0x00000006893d0330> (a java.util.concurrent.ConcurrentHashMap)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321)
    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:1306)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1226)
    at org.springframework.beans.factory.support.ConstructorResolver.resolveAutowiredArgument(ConstructorResolver.java:885)
    at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:789)
    at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:539)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1338)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1177)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:557)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517)
    at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:323)
    at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$180/1416025551.getObject(Unknown Source)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:226)
    - locked <0x00000006893d0330> (a java.util.concurrent.ConcurrentHashMap)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:895)
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:878)
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:550)
    - locked <0x00000006890192f0> (a java.lang.Object)
    at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:143)
    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:397)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:315)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1237)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226)
    at xxx.Application.main(Application.java:14)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:49)

"Thread-0" spring-projects/spring-boot#9 prio=5 os_prio=0 tid=0x00007ff4c0a81800 nid=0x7d4a in Object.wait() [0x00007ff49e023000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x0000000689018d28> (a org.springframework.boot.devtools.restart.RestartLauncher)
    at java.lang.Thread.join(Thread.java:1252)
    - locked <0x0000000689018d28> (a org.springframework.boot.devtools.restart.RestartLauncher)
    at java.lang.Thread.join(Thread.java:1326)
    at org.springframework.boot.devtools.restart.Restarter.relaunch(Restarter.java:296)
    at org.springframework.boot.devtools.restart.Restarter.doStart(Restarter.java:283)
    at org.springframework.boot.devtools.restart.Restarter.start(Restarter.java:264)
    at org.springframework.boot.devtools.restart.Restarter.lambda$immediateRestart$0(Restarter.java:172)
    at org.springframework.boot.devtools.restart.Restarter$$Lambda$16/1975546571.call(Unknown Source)
    at org.springframework.boot.devtools.restart.Restarter$LeakSafeThread.run(Restarter.java:629)

"Service Thread" spring-projects/spring-boot#8 daemon prio=9 os_prio=0 tid=0x00007ff4c00e2800 nid=0x7d48 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread2" spring-projects/spring-boot#7 daemon prio=9 os_prio=0 tid=0x00007ff4c00c5800 nid=0x7d47 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" spring-projects/spring-boot#6 daemon prio=9 os_prio=0 tid=0x00007ff4c00c3800 nid=0x7d46 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" spring-projects/spring-boot#5 daemon prio=9 os_prio=0 tid=0x00007ff4c00c0800 nid=0x7d45 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" spring-projects/spring-boot#4 daemon prio=9 os_prio=0 tid=0x00007ff4c00bc800 nid=0x7d44 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" spring-projects/spring-boot#3 daemon prio=8 os_prio=0 tid=0x00007ff4c008e800 nid=0x7d43 in Object.wait() [0x00007ff4ad5b5000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
    - locked <0x000000068901b960> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216)

"Reference Handler" spring-projects/spring-boot#2 daemon prio=10 os_prio=0 tid=0x00007ff4c008a000 nid=0x7d42 in Object.wait() [0x00007ff4ad6b6000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.lang.Object.wait(Object.java:502)
    at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
    - locked <0x000000068901bb90> (a java.lang.ref.Reference$Lock)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"main" spring-projects/spring-boot#1 prio=5 os_prio=0 tid=0x00007ff4c0012800 nid=0x7d3c in Object.wait() [0x00007ff4c7b77000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x000000068901aa18> (a org.springframework.boot.devtools.restart.Restarter$LeakSafeThread)
    at java.lang.Thread.join(Thread.java:1252)
    - locked <0x000000068901aa18> (a org.springframework.boot.devtools.restart.Restarter$LeakSafeThread)
    at java.lang.Thread.join(Thread.java:1326)
    at org.springframework.boot.devtools.restart.Restarter$LeakSafeThread.callAndWait(Restarter.java:613)
    at org.springframework.boot.devtools.restart.Restarter.immediateRestart(Restarter.java:171)
    at org.springframework.boot.devtools.restart.Restarter.initialize(Restarter.java:164)
    at org.springframework.boot.devtools.restart.Restarter.initialize(Restarter.java:554)
    at org.springframework.boot.devtools.restart.RestartApplicationListener.onApplicationStartingEvent(RestartApplicationListener.java:74)
    at org.springframework.boot.devtools.restart.RestartApplicationListener.onApplicationEvent(RestartApplicationListener.java:50)
    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.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:127)
    at org.springframework.boot.context.event.EventPublishingRunListener.starting(EventPublishingRunListener.java:74)
    at org.springframework.boot.SpringApplicationRunListeners.starting(SpringApplicationRunListeners.java:47)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:305)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1237)
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226)
    at xxx.Application.main(Application.java:14)

"VM Thread" os_prio=0 tid=0x00007ff4c0080800 nid=0x7d41 runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007ff4c0028000 nid=0x7d3d runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007ff4c002a000 nid=0x7d3e runnable 

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007ff4c002b800 nid=0x7d3f runnable 

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007ff4c002d800 nid=0x7d40 runnable 

"VM Periodic Task Thread" os_prio=0 tid=0x00007ff4c00e5000 nid=0x7d49 waiting on condition 

JNI global references: 1764
wilkinsona commented 4 years ago

Thanks for the sample. The problem is caused by Spring Boot 2.3 moving to bootstrapping Hibernate asynchronously by default. When Hibernate Search is involved, its bootstrapping results in a call back into the bean factory via SpringBeanContainer and a deadlock occurs. This will have to be investigated by the Spring Framework team. We'll transfer this issue to them shortly so that they can take a look. In the meantime, you can avoid the problem by disabling deferred bootstrapping:

spring:
  data:
    jpa:
      repositories:
        bootstrap_mode: default
knoobie commented 4 years ago

Thanks @wilkinsona!

yrodiere commented 4 years ago

Hi, Hibernate Search developer here. Maybe this can shed some light on the problem:

From what I understand (I might be wrong), Spring doesn't initialize Hibernate ORM lazily; it just instructs Hibernate ORM to resolve beans lazily, while performing the whole bootstrap process eagerly. That's possible for Hibernate ORM because the beans (converters, ...) are only used at runtime.

Hibernate Search, on the other hand, retrieves "bridges" through Spring. The "bridges" provide metadata that is needed at bootstrap, and thus they must be resolved eagerly at startup, so that the bootstrap process completes. Thus the "deferred" bootstrap mode in Spring cannot currently work out of the box in Hibernate Search.

There is a feature in Hibernate Search that defers the whole bootstrap process of Hibernate Search to a later time, but I'm not sure it would help, as a) Spring doesn't include any integration code specific to Hibernate Search right now (and I'm not sure you'll want that) and b) that feature only delays the bootstrap, it does not make it "lazy". See org.hibernate.search.hcore.impl.ExtendedBeanManagerSynchronizer for an example implementation (for CDI). That implementation is enabled thanks to org.hibernate.search.hcore.impl.ExtendedBeanManagerSynchronizerContributor, which is enabled through a service file: META-INF/services/org.hibernate.service.spi.ServiceContributor.

wilkinsona commented 4 years ago

The problem doesn't appear to be limited to apps that use Hibernate search. @ctmay4 shared a thread dump on the Spring Boot issue that switched the default to deferred which shows Hibernate ORM code calling back into the bean factory via SpringBeanContainer and deadlocking:

"main@1" prio=5 tid=0x1 nid=NA waiting
  java.lang.Thread.State: WAITING
     blocks task-1@7519
      at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
      at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:447)
      at java.util.concurrent.FutureTask.get(FutureTask.java:190)
      at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.getNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:540)
      at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.invokeProxyMethod(AbstractEntityManagerFactoryBean.java:497)
      at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean$ManagedEntityManagerFactoryInvocationHandler.invoke(AbstractEntityManagerFactoryBean.java:680)
      at com.sun.proxy.$Proxy93.getMetamodel(Unknown Source:-1)
      at org.springframework.data.jpa.repository.config.JpaMetamodelMappingContextFactoryBean$$Lambda$859.436399072.apply(Unknown Source:-1)
      at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
      at java.util.Iterator.forEachRemaining(Iterator.java:133)
      at java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801)
      at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
      at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
      at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913)
      at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
      at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:578)
      at org.springframework.data.jpa.repository.config.JpaMetamodelMappingContextFactoryBean.getMetamodels(JpaMetamodelMappingContextFactoryBean.java:106)
      at org.springframework.data.jpa.repository.config.JpaMetamodelMappingContextFactoryBean.createInstance(JpaMetamodelMappingContextFactoryBean.java:80)
      at org.springframework.data.jpa.repository.config.JpaMetamodelMappingContextFactoryBean.createInstance(JpaMetamodelMappingContextFactoryBean.java:44)
      at org.springframework.beans.factory.config.AbstractFactoryBean.afterPropertiesSet(AbstractFactoryBean.java:142)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1855)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1792)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:595)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517)
      at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:323)
      at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$318.1466413743.getObject(Unknown Source:-1)
      at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:226)
      - locked <0x273d> (a java.util.concurrent.ConcurrentHashMap)
      at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321)
      at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
      at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:330)
      at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:113)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1699)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1444)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:594)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517)
      at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:323)
      at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$318.1466413743.getObject(Unknown Source:-1)
      at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:226)
      at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321)
      at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:207)
      at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1114)
      at org.springframework.data.repository.support.Repositories.cacheRepositoryFactory(Repositories.java:99)
      - locked <0x273e> (a org.springframework.data.repository.support.Repositories)
      at org.springframework.data.repository.support.Repositories.populateRepositoryFactoryInformation(Repositories.java:92)
      at org.springframework.data.repository.support.Repositories.<init>(Repositories.java:85)
      at org.springframework.data.repository.support.DomainClassConverter.setApplicationContext(DomainClassConverter.java:109)
      at org.springframework.data.web.config.SpringDataWebConfiguration.addFormatters(SpringDataWebConfiguration.java:130)
      at org.springframework.web.servlet.config.annotation.WebMvcConfigurerComposite.addFormatters(WebMvcConfigurerComposite.java:81)
      at org.springframework.web.servlet.config.annotation.DelegatingWebMvcConfiguration.addFormatters(DelegatingWebMvcConfiguration.java:78)
      at org.springframework.boot.autoconfigure.web.servlet.WebMvcAutoConfiguration$EnableWebMvcConfiguration.mvcConversionService(WebMvcAutoConfiguration.java:435)
      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-1)
      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:566)
      at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:154)
      at org.springframework.beans.factory.support.ConstructorResolver.instantiate(ConstructorResolver.java:651)
      at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:636)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1338)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1177)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:557)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517)
      at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:323)
      at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$318.1466413743.getObject(Unknown Source:-1)
      at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:226)
      at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321)
      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:1306)
      at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1226)
      at org.springframework.beans.factory.support.ConstructorResolver.resolveAutowiredArgument(ConstructorResolver.java:885)
      at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:789)
      at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:539)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1338)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1177)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:557)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517)
      at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:323)
      at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$318.1466413743.getObject(Unknown Source:-1)
      at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:226)
      at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321)
      at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
      at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:895)
      at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:878)
      at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:550)
      - locked <0x273f> (a java.lang.Object)
      at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:143)
      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:397)
      at org.springframework.boot.SpringApplication.run(SpringApplication.java:315)
      at org.springframework.boot.SpringApplication.run(SpringApplication.java:1237)
      at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226)
      at com.imsweb.seerdms.admin.AdminApplication.main(AdminApplication.java:34)

"task-1@7519" prio=5 tid=0x181 nid=NA waiting for monitor entry
  java.lang.Thread.State: BLOCKED
     waiting for main@1 to release lock on <0x273d> (a java.util.concurrent.ConcurrentHashMap)
      at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:183)
      at org.springframework.beans.factory.support.AbstractBeanFactory.isTypeMatch(AbstractBeanFactory.java:517)
      at org.springframework.beans.factory.support.DefaultListableBeanFactory.doGetBeanNamesForType(DefaultListableBeanFactory.java:533)
      at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeanNamesForType(DefaultListableBeanFactory.java:505)
      at org.springframework.beans.factory.BeanFactoryUtils.beanNamesForTypeIncludingAncestors(BeanFactoryUtils.java:265)
      at org.springframework.beans.factory.support.DefaultListableBeanFactory.findAutowireCandidates(DefaultListableBeanFactory.java:1472)
      at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1269)
      at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1226)
      at org.springframework.beans.factory.support.ConstructorResolver.resolveAutowiredArgument(ConstructorResolver.java:885)
      at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:789)
      at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:228)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireConstructor(AbstractAutowireCapableBeanFactory.java:1358)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1204)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:557)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:353)
      at org.springframework.orm.hibernate5.SpringBeanContainer.createBean(SpringBeanContainer.java:147)
      at org.springframework.orm.hibernate5.SpringBeanContainer.getBean(SpringBeanContainer.java:105)
      at org.hibernate.resource.beans.internal.ManagedBeanRegistryImpl.getBean(ManagedBeanRegistryImpl.java:61)
      at org.hibernate.boot.model.convert.internal.ClassBasedConverterDescriptor.createManagedBean(ClassBasedConverterDescriptor.java:38)
      at org.hibernate.boot.model.convert.internal.AbstractConverterDescriptor.createJpaAttributeConverter(AbstractConverterDescriptor.java:107)
      at org.hibernate.mapping.SimpleValue.buildAttributeConverterTypeAdapter(SimpleValue.java:570)
      at org.hibernate.mapping.SimpleValue.setTypeUsingReflection(SimpleValue.java:531)
      at org.hibernate.cfg.annotations.SimpleValueBinder.fillSimpleValue(SimpleValueBinder.java:511)
      at org.hibernate.cfg.SetSimpleValueTypeSecondPass.doSecondPass(SetSimpleValueTypeSecondPass.java:25)
      at org.hibernate.boot.internal.InFlightMetadataCollectorImpl.processSecondPasses(InFlightMetadataCollectorImpl.java:1693)
      at org.hibernate.boot.internal.InFlightMetadataCollectorImpl.processSecondPasses(InFlightMetadataCollectorImpl.java:1651)
      at org.hibernate.boot.model.process.spi.MetadataBuildingProcess.complete(MetadataBuildingProcess.java:286)
      at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.metadata(EntityManagerFactoryBuilderImpl.java:1214)
      at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:1245)
      at org.springframework.orm.jpa.vendor.SpringHibernateJpaPersistenceProvider.createContainerEntityManagerFactory(SpringHibernateJpaPersistenceProvider.java:58)
      at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:365)
      at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.buildNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:391)
      at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean$$Lambda$769.882838692.call(Unknown Source:-1)
      at java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
      at java.util.concurrent.FutureTask.run(FutureTask.java:-1)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at java.lang.Thread.run(Thread.java:834)

"Catalina-utility-1@7279" prio=1 tid=0x17e nid=NA waiting
  java.lang.Thread.State: WAITING
      at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1182)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
      at java.lang.Thread.run(Thread.java:834)

"Catalina-utility-2@7283" prio=1 tid=0x17f nid=NA waiting
  java.lang.Thread.State: WAITING
      at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2081)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1177)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
      at java.lang.Thread.run(Thread.java:834)

"RMI Scheduler(0)@3836" daemon prio=5 tid=0x13 nid=NA waiting
  java.lang.Thread.State: WAITING
      at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1182)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at java.lang.Thread.run(Thread.java:834)

"HikariPool-1 housekeeper@8907" daemon prio=5 tid=0x184 nid=NA waiting
  java.lang.Thread.State: WAITING
      at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1182)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at java.lang.Thread.run(Thread.java:834)

"Common-Cleaner@1773" daemon prio=8 tid=0xa nid=NA waiting
  java.lang.Thread.State: WAITING
      at java.lang.Object.wait(Object.java:-1)
      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:155)
      at jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:148)
      at java.lang.Thread.run(Thread.java:834)
      at jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:134)

"RMI TCP Accept-0@1714" daemon prio=5 tid=0x10 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
      at java.net.PlainSocketImpl.accept0(PlainSocketImpl.java:-1)
      at java.net.PlainSocketImpl.socketAccept(PlainSocketImpl.java:159)
      at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:458)
      at java.net.ServerSocket.implAccept(ServerSocket.java:565)
      at java.net.ServerSocket.accept(ServerSocket.java:533)
      at sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRMIServerSocketFactory.java:52)
      at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:394)
      at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:366)
      at java.lang.Thread.run(Thread.java:834)

"RMI TCP Connection(1)-172.22.34.23@3482" daemon prio=5 tid=0x12 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
      at java.net.SocketInputStream.socketRead0(SocketInputStream.java:-1)
      at java.net.SocketInputStream.socketRead(SocketInputStream.java:115)
      at java.net.SocketInputStream.read(SocketInputStream.java:168)
      at java.net.SocketInputStream.read(SocketInputStream.java:140)
      at java.io.BufferedInputStream.fill(BufferedInputStream.java:252)
      at java.io.BufferedInputStream.read(BufferedInputStream.java:271)
      - locked <0x2742> (a java.io.BufferedInputStream)
      at java.io.FilterInputStream.read(FilterInputStream.java:83)
      at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:544)
      at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:796)
      at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:677)
      at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$$Lambda$222.498706880.run(Unknown Source:-1)
      at java.security.AccessController.doPrivileged(AccessController.java:-1)
      at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:676)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at java.lang.Thread.run(Thread.java:834)

"container-0@7293" prio=5 tid=0x180 nid=NA sleeping
  java.lang.Thread.State: TIMED_WAITING
      at java.lang.Thread.sleep(Thread.java:-1)
      at org.apache.catalina.core.StandardServer.await(StandardServer.java:570)
      at org.springframework.boot.web.embedded.tomcat.TomcatWebServer$1.run(TomcatWebServer.java:197)

"Reference Handler@10043" daemon prio=10 tid=0x2 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
      at java.lang.ref.Reference.waitForReferencePendingList(Reference.java:-1)
      at java.lang.ref.Reference.processPendingReferences(Reference.java:241)
      at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:213)

"Finalizer@9857" daemon prio=8 tid=0x3 nid=NA waiting
  java.lang.Thread.State: WAITING
      at java.lang.Object.wait(Object.java:-1)
      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:155)
      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:176)
      at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:170)

"Signal Dispatcher@10044" daemon prio=9 tid=0x4 nid=NA runnable
  java.lang.Thread.State: RUNNABLE

"Attach Listener@3193" daemon prio=5 tid=0x5 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
chengchen commented 4 years ago

Yes, it's the same for us. This is happening randomly.

main thread which waits for the Future to complete

main

task-1 thread executing the Future

task-1

The main thread waits for getNativeEntityManagerFactory() (done asynchronously on task-1 thread) to complete and at the same time it has already acquired the lock in DefaultSingletionBeanRegistry. And task-1 thread also requires a Hikari connection to be ready. However, at this moment, the Hikari connection pool is not yet initialized so it has to access this DefaultSingletionBeanRegistry as well trying to enter the synchronized block (but it's blocked by main thread).

If we switch to DEFAULT mode, it works fine as before.

snicoll commented 4 years ago

Once we have a fix for this issue, testing it against https://github.com/hgarus/entitylistener-deadlock is in order as it's yet another occurence of this issue.

pyn0t commented 4 years ago

Adding @EnableJpaRepositories to DemoApplication seems to fix the issue

dan1els commented 4 years ago

It seems you can't inject anything into entity listeners when using BoostrapMode.DEFAULT, but using deferred mode fixed both issues. @EnableJpaRepositories(bootstrapMode = BootstrapMode.DEFERRED)

hgarus commented 4 years ago

@pyn0t , @dan1els

Adding @EnableJpaRepositories to DemoApplication seems to fix the issue

Yes it does, as does setting spring.data.jpa.repositories.bootstrap-mode=default in application.properties.

Both cause the creation of the EntityManagerFactory in AbstractEntityManagerFactoryBean to be synchronous.

Spring-Boot changed the default for spring.data.jpa.repositories.bootstrap-mode to lazy with 2.3 which causes JpaRepositoriesAutoConfiguration to configure a bootstrapExecutor to create the EntityManagerFactory asynchronously.

Somewhat interestingly @EnableJpaRepositories(bootstrapMode = BootstrapMode.LAZY) doesn't set a bootstrapExecutor (and I don't see another way to set one using the annotation either), so @EnableJpaRepositories "fixes" the deadlock regardless of bootstrapMode.

matf commented 3 years ago

Encountered the same issue, hangs sometimes during startup while trying to inject EntityManagerFactory instances into HibernateMetricsAutoConfiguration. Here's the thread dump if it helps:

"main@1" prio=5 tid=0x1 nid=NA waiting
  java.lang.Thread.State: WAITING
     blocks task-1@8951
      at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
      at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:447)
      at java.util.concurrent.FutureTask.get(FutureTask.java:190)
      at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.getNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:540)
      at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.invokeProxyMethod(AbstractEntityManagerFactoryBean.java:497)
      at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean$ManagedEntityManagerFactoryInvocationHandler.invoke(AbstractEntityManagerFactoryBean.java:680)
      at com.sun.proxy.$Proxy157.unwrap(Unknown Source:-1)
      at org.springframework.boot.actuate.autoconfigure.metrics.orm.jpa.HibernateMetricsAutoConfiguration.bindEntityManagerFactoryToRegistry(HibernateMetricsAutoConfiguration.java:67)
      at org.springframework.boot.actuate.autoconfigure.metrics.orm.jpa.HibernateMetricsAutoConfiguration.lambda$bindEntityManagerFactoriesToRegistry$0(HibernateMetricsAutoConfiguration.java:60)
      at org.springframework.boot.actuate.autoconfigure.metrics.orm.jpa.HibernateMetricsAutoConfiguration$$Lambda$1179.1394343499.accept(Unknown Source:-1)
      at java.util.LinkedHashMap.forEach(LinkedHashMap.java:684)
      at org.springframework.boot.actuate.autoconfigure.metrics.orm.jpa.HibernateMetricsAutoConfiguration.bindEntityManagerFactoriesToRegistry(HibernateMetricsAutoConfiguration.java:60)
      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-1)
      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:566)
      at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredMethodElement.inject(AutowiredAnnotationBeanPostProcessor.java:755)
      at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:130)
      at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessProperties(AutowiredAnnotationBeanPostProcessor.java:399)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1420)
      at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:593)
      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$327.605705199.getObject(Unknown Source:-1)
      at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:226)
      - locked <0x2f53> (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 <0x2f54> (a java.lang.Object)
      at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:143)
      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:397)
      at org.springframework.boot.SpringApplication.run(SpringApplication.java:315)
      at org.springframework.boot.SpringApplication.run(SpringApplication.java:1237)
      at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226)
      at xyz.vehicledata.Application.main(Application.java:19)

"task-1@8951" prio=5 tid=0x28 nid=NA waiting for monitor entry
  java.lang.Thread.State: BLOCKED
     waiting for main@1 to release lock on <0x2f53> (a java.util.concurrent.ConcurrentHashMap)
      at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:183)
      at org.springframework.beans.factory.support.AbstractBeanFactory.isTypeMatch(AbstractBeanFactory.java:523)
      at org.springframework.beans.factory.support.DefaultListableBeanFactory.doGetBeanNamesForType(DefaultListableBeanFactory.java:530)
      at org.springframework.beans.factory.support.DefaultListableBeanFactory.getBeanNamesForType(DefaultListableBeanFactory.java:503)
      at org.springframework.beans.factory.BeanFactoryUtils.beanNamesForTypeIncludingAncestors(BeanFactoryUtils.java:265)
      at org.springframework.beans.factory.support.DefaultListableBeanFactory.findAutowireCandidates(DefaultListableBeanFactory.java:1473)
      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.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:353)
      at org.springframework.orm.hibernate5.SpringBeanContainer.createBean(SpringBeanContainer.java:147)
      at org.springframework.orm.hibernate5.SpringBeanContainer.getBean(SpringBeanContainer.java:105)
      at org.hibernate.resource.beans.internal.ManagedBeanRegistryImpl.getBean(ManagedBeanRegistryImpl.java:61)
      at org.hibernate.jpa.event.internal.CallbackBuilderLegacyImpl.resolveEntityCallbacks(CallbackBuilderLegacyImpl.java:200)
      at org.hibernate.jpa.event.internal.CallbackBuilderLegacyImpl.buildCallbacksForEntity(CallbackBuilderLegacyImpl.java:74)
      at org.hibernate.event.service.internal.EventListenerRegistryImpl.prepare(EventListenerRegistryImpl.java:146)
      at org.hibernate.boot.internal.MetadataImpl.initSessionFactory(MetadataImpl.java:379)
      at org.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:213)
      at org.hibernate.boot.internal.SessionFactoryBuilderImpl.build(SessionFactoryBuilderImpl.java:469)
      at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:1259)
      at org.springframework.orm.jpa.vendor.SpringHibernateJpaPersistenceProvider.createContainerEntityManagerFactory(SpringHibernateJpaPersistenceProvider.java:58)
      at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:365)
      at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.buildNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:391)
      at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean$$Lambda$931.256719132.call(Unknown Source:-1)
      at java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264)
      at java.util.concurrent.FutureTask.run(FutureTask.java:-1)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at java.lang.Thread.run(Thread.java:834)

"Catalina-utility-1@8461" prio=1 tid=0x22 nid=NA waiting
  java.lang.Thread.State: WAITING
      at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:194)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2081)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1177)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
      at java.lang.Thread.run(Thread.java:834)

"Catalina-utility-2@8467" prio=1 tid=0x23 nid=NA waiting
  java.lang.Thread.State: WAITING
      at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1182)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
      at java.lang.Thread.run(Thread.java:834)

"RMI Scheduler(0)@2870" daemon prio=5 tid=0x14 nid=NA waiting
  java.lang.Thread.State: WAITING
      at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1182)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at java.lang.Thread.run(Thread.java:834)

"hikari-cp-camiuns-vehicledata-scs housekeeper@8734" daemon prio=5 tid=0x26 nid=NA waiting
  java.lang.Thread.State: WAITING
      at jdk.internal.misc.Unsafe.park(Unsafe.java:-1)
      at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2123)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1182)
      at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
      at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1054)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1114)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at java.lang.Thread.run(Thread.java:834)

"Common-Cleaner@1631" daemon prio=8 tid=0xb nid=NA waiting
  java.lang.Thread.State: WAITING
      at java.lang.Object.wait(Object.java:-1)
      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:155)
      at jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:148)
      at java.lang.Thread.run(Thread.java:834)
      at jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:134)

"RMI TCP Accept-0@1723" daemon prio=5 tid=0x10 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
      at java.net.PlainSocketImpl.socketAccept(PlainSocketImpl.java:-1)
      at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:458)
      at java.net.ServerSocket.implAccept(ServerSocket.java:565)
      at java.net.ServerSocket.accept(ServerSocket.java:533)
      at sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRMIServerSocketFactory.java:52)
      at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:394)
      at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:366)
      at java.lang.Thread.run(Thread.java:834)

"RMI TCP Connection(1)-127.0.0.1@2625" daemon prio=5 tid=0x13 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
      at java.net.SocketInputStream.socketRead0(SocketInputStream.java:-1)
      at java.net.SocketInputStream.socketRead(SocketInputStream.java:115)
      at java.net.SocketInputStream.read(SocketInputStream.java:168)
      at java.net.SocketInputStream.read(SocketInputStream.java:140)
      at java.io.BufferedInputStream.fill(BufferedInputStream.java:252)
      at java.io.BufferedInputStream.read(BufferedInputStream.java:271)
      - locked <0x2f57> (a java.io.BufferedInputStream)
      at java.io.FilterInputStream.read(FilterInputStream.java:83)
      at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:544)
      at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:796)
      at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:677)
      at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$$Lambda$141.605553038.run(Unknown Source:-1)
      at java.security.AccessController.doPrivileged(AccessController.java:-1)
      at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:676)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
      at java.lang.Thread.run(Thread.java:834)

"container-0@8477" prio=5 tid=0x24 nid=NA sleeping
  java.lang.Thread.State: TIMED_WAITING
      at java.lang.Thread.sleep(Thread.java:-1)
      at org.apache.catalina.core.StandardServer.await(StandardServer.java:570)
      at org.springframework.boot.web.embedded.tomcat.TomcatWebServer$1.run(TomcatWebServer.java:197)

"Keep-Alive-Timer@11851" daemon prio=8 tid=0x83 nid=NA sleeping
  java.lang.Thread.State: TIMED_WAITING
      at java.lang.Thread.sleep(Thread.java:-1)
      at sun.net.www.http.KeepAliveCache.run(KeepAliveCache.java:168)
      at java.lang.Thread.run(Thread.java:834)
      at jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:134)

"Reference Handler@12111" daemon prio=10 tid=0x2 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
      at java.lang.ref.Reference.waitForReferencePendingList(Reference.java:-1)
      at java.lang.ref.Reference.processPendingReferences(Reference.java:241)
      at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:213)

"Finalizer@12112" daemon prio=8 tid=0x3 nid=NA waiting
  java.lang.Thread.State: WAITING
      at java.lang.Object.wait(Object.java:-1)
      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:155)
      at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:176)
      at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:170)

"PostgreSQL-JDBC-SharedTimer-1@8722" daemon prio=5 tid=0x25 nid=NA waiting
  java.lang.Thread.State: WAITING
      at java.lang.Object.wait(Object.java:-1)
      at java.lang.Object.wait(Object.java:328)
      at java.util.TimerThread.mainLoop(Timer.java:527)
      at java.util.TimerThread.run(Timer.java:506)

"Signal Dispatcher@12113" daemon prio=9 tid=0x4 nid=NA runnable
  java.lang.Thread.State: RUNNABLE

"Attach Listener@2293" daemon prio=9 tid=0x12 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
snicoll commented 3 years ago

@matf using deferred initialization for JPA means that you shouldn't be touching the JPA infrastructure on startup. It's not obvious why that is which is why we've decided to switch back to the default mode in Spring Boot, see https://github.com/spring-projects/spring-boot/issues/24249.

Encountered the same issue, hangs sometimes during startup while trying to inject EntityManagerFactory instances into HibernateMetricsAutoConfiguration

If that's the regular auto-configuration, it shouldn't do that per https://github.com/spring-projects/spring-boot/issues/23740.

jhoeller commented 11 months ago

If there is nothing that we can do about this from the core JPA support side, let's rather close this issue.