Why is Spring Data JPA Creating new EntityManager for shared EntityManager invocation?

Question

I have a sample project using spring boot + spring data JPA. In the log I observed that EntityManagers are getting created few times before I make the first rest call. Please clarify why this happen. Thanks much.

Initialized JPA EntityManagerFactory for persistence unit 'ENTITY_MGR'
SpringBoot --> 10:05:40 8766 DEBUG org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler [main] - Creating new EntityManager for shared EntityManager invocation
SpringBoot --> 10:05:41 8963 DEBUG org.hibernate.stat.internal.StatisticsInitiator [main] - Statistics initialized [enabled=true]
SpringBoot --> 10:05:41 8977 TRACE org.hibernate.internal.SessionImpl [main] - Opened Session [f35fe4ac-8ce1-46b8-90dc-e456c07015c9] at timestamp: 15339099411
SpringBoot --> 10:05:41 8980 DEBUG org.springframework.orm.jpa.EntityManagerFactoryUtils [main] - Closing JPA EntityManager
SpringBoot --> 10:05:41 8982 TRACE org.hibernate.internal.SessionImpl [main] - Closing session [f35fe4ac-8ce1-46b8-90dc-e456c07015c9]
SpringBoot --> 10:05:41 8982 INFO  org.hibernate.engine.internal.StatisticalLoggingSessionEventListener [main] - 
SpringBoot --> 10:05:41 8983 TRACE org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl [main] - Releasing JDBC resources
SpringBoot --> 10:05:41 8983 TRACE org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl [main] - Closing logical connection
SpringBoot --> 10:05:41 8983 TRACE org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl [main] - Logical connection closed
SpringBoot --> 10:05:41 8985 DEBUG org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler [main] - Creating new EntityManager for shared EntityManager invocation
SpringBoot --> 10:05:41 8986 TRACE org.hibernate.internal.SessionImpl [main] - Opened Session [26018255-8491-4014-98ad-fbce0d3b5109] at timestamp: 15339099412
SpringBoot --> 10:05:41 8986 DEBUG org.springframework.orm.jpa.EntityManagerFactoryUtils [main] - Closing JPA EntityManager
SpringBoot --> 10:05:41 8986 TRACE org.hibernate.internal.SessionImpl [main] - Closing session [26018255-8491-4014-98ad-fbce0d3b5109]
SpringBoot --> 10:05:41 8986 INFO  org.hibernate.engine.internal.StatisticalLoggingSessionEventListener [main] - 
SpringBoot --> 10:05:41 8986 TRACE org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl [main] - Releasing JDBC resources
SpringBoot --> 10:05:41 8986 TRACE org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl [main] - Closing logical connection
SpringBoot --> 10:05:41 8986 TRACE org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl [main] - Logical connection closed
SpringBoot --> 10:05:41 9069 DEBUG org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler [main] - Creating new EntityManager for shared EntityManager invocation
SpringBoot --> 10:05:41 9069 TRACE org.hibernate.internal.SessionImpl [main] - Opened Session [4d3e7b5f-46fe-436f-9526-7ba62e332846] at timestamp: 15339099412
SpringBoot --> 10:05:41 9069 DEBUG org.springframework.orm.jpa.EntityManagerFactoryUtils [main] - Closing JPA EntityManager
SpringBoot --> 10:05:41 9069 TRACE org.hibernate.internal.SessionImpl [main] - Closing session [4d3e7b5f-46fe-436f-9526-7ba62e332846]
SpringBoot --> 10:05:41 9069 INFO  org.hibernate.engine.internal.StatisticalLoggingSessionEventListener [main] - 
SpringBoot --> 10:05:41 9070 TRACE org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl [main] - Releasing JDBC resources
SpringBoot --> 10:05:41 9070 TRACE org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl [main] - Closing logical connection
SpringBoot --> 10:05:41 9070 TRACE org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl [main] - Logical connection closed
SpringBoot --> 10:05:41 9248 DEBUG org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler [main] - Creating new EntityManager for shared EntityManager invocation
SpringBoot --> 10:05:41 9248 TRACE org.hibernate.internal.SessionImpl [main] - Opened Session [1b5f5936-fa7f-42cd-831c-78570ace0f58] at timestamp: 15339099414
SpringBoot --> 10:05:41 9248 DEBUG org.springframework.orm.jpa.EntityManagerFactoryUtils [main] - Closing JPA EntityManager
SpringBoot --> 10:05:41 9248 TRACE org.hibernate.internal.SessionImpl [main] - Closing session [1b5f5936-fa7f-42cd-831c-78570ace0f58]
SpringBoot --> 10:05:41 9249 INFO  org.hibernate.engine.internal.StatisticalLoggingSessionEventListener [main] - 
SpringBoot --> 10:05:41 9249 TRACE org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl [main] - Releasing JDBC resources
SpringBoot --> 10:05:41 9249 TRACE org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl [main] - Closing logical connection
SpringBoot --> 10:05:41 9249 TRACE org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl [main] - Logical connection closed

Answer 1

I wondered about the same thing and here is what I have found.

In many cases in Spring it is used a proxy for the EntityManager fields. I suppose the reason for this is that the proxy is said to be thread-safe compared to the real implementations of EntityManager interface which are not thread-safe.

For example the default implementation of CrudRepository interface -> SimpleJpaRepository has field of type EntityManager. And in most cases we just want to extend the CrudRepository interface and to inject it somewhere as a singleton bean. Since it is a singleton the EntityManager has to be thread-safe because the repository may be invoked from multiple threads.

In the documentation of the SharedEntityManagerCreator class we can see how this proxy really works.

A shared EntityManager will behave just like an EntityManager fetched from an application server's JNDI environment, as defined by the JPA specification. It will delegate all calls to the current transactional EntityManager, if any; otherwise it will fall back to a newly created EntityManager per operation.

This means that if there is created EntityManager (Session) the proxy will use it and if there is not it will create a new EntityManager (Session) on demand for you.

When we start our Spring Boot application Spring makes calls to some EntityManagers but these EntityManagers are proxies and because we don't have real EntityManager (Session) created it creates one for us and logs these messages that you are asking for.

So in your case these shared EntityManagers are created probably because you have defined Repository interfaces in your project and during initialization there are calls to the EntityManager (proxy) in these Repositories.