Spring 3.1 + Hibernate 4.1 JPA, Entity manager factory is registered twice

Question

I'm using Spring Framework 3.1 with Hibernate 4.1 as a JPA provider, and I have a fully functional setup, but every time the web app is started I see this warning message:

14:28:12,725  WARN pool-2-thread-12 internal.EntityManagerFactoryRegistry:80 - HHH000436: Entity manager factory name (something) is already registered.  If entity manager will be clustered or passivated, specify a unique value for property 'hibernate.ejb.entitymanager_factory_name'

The application functions just fine, but warning messages like that bother me, and hours of searching and tweaking and experimenting have lead me nowhere. I've tried changing the factory name and adding and omitting chunks of configuration, all to no avail. It appears that something in Spring or Hibernate is just initializing the entity manager factory twice.

FYI, I'm using the packagesToScan functionality of the LocalContainerEntityManagerFactoryBean to configure the entity manager without a persistence.xml file.

I've pared down my spring context XML to the following and the problem persists:

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xmlns:context="http://www.springframework.org/schema/context"
       xsi:schemaLocation="
           http://www.springframework.org/schema/context http://www.springframework.org/schema/context/spring-context.xsd
           http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans.xsd">

  <context:property-placeholder location="classpath:jdbc.properties"/>
  <bean id="dataSource" class="org.apache.tomcat.jdbc.pool.DataSource" destroy-method="close">
    <property name="driverClassName" value="${jdbc.nightsword.driverClassName}"/>
    <property name="url" value="${jdbc.nightsword.url}"/>
    <property name="username" value="${jdbc.nightsword.username}"/>
    <property name="password" value="${jdbc.nightsword.password}"/>
  </bean>

  <bean id="entityManagerFactory" class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">
    <property name="jpaVendorAdapter">
      <bean class="org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter"/>
    </property>
    <property name="dataSource" ref="dataSource"/>
    <property name="packagesToScan" value="x.y"/>
  </bean>
</beans>

For completeness, here's hibernate.properties:

hibernate.dialect=org.hibernate.dialect.MySQL5Dialect
hibernate.ejb.entitymanager_factory_name=something

And here's excerpted debug-level log output from both org.springframework.orm and org.hibernate. You can see how at 14:40:06,911 the EntityManagerFactory is registered from the first time, and immediately thereafter the LocalContainerEntityManagerFactoryBean appears to start all over from the beginning. Huh.

INFO: Deploying web application archive /opt/local/share/java/tomcat7/webapps/nightsword.war
14:40:06,149  INFO pool-2-thread-13 jpa.LocalContainerEntityManagerFactoryBean:264 - Building JPA container EntityManagerFactory for persistence unit 'default'
14:40:06,219 DEBUG pool-2-thread-13 type.BasicTypeRegistry:143 - Adding type registration boolean -> org.hibernate.type.BooleanType@4cb91eff

...

14:40:06,882 DEBUG pool-2-thread-13 internal.SessionFactoryRegistry:62 - Initializing SessionFactoryRegistry : org.hibernate.internal.SessionFactoryRegistry@161bb7fe
14:40:06,882 DEBUG pool-2-thread-13 internal.SessionFactoryRegistry:75 - Registering SessionFactory: a3219dd8-7d59-45ac-9a5a-0d13e38dbb04 (<unnamed>)
14:40:06,882 DEBUG pool-2-thread-13 internal.SessionFactoryRegistry:82 - Not binding SessionFactory to JNDI, no JNDI name configured
14:40:06,882 DEBUG pool-2-thread-13 internal.SessionFactoryImpl:487 - Instantiated session factory
14:40:06,882 DEBUG pool-2-thread-13 internal.SessionFactoryImpl:1119 - Checking 0 named HQL queries
14:40:06,883 DEBUG pool-2-thread-13 internal.SessionFactoryImpl:1142 - Checking 0 named SQL queries
14:40:06,887 DEBUG pool-2-thread-13 internal.StatisticsInitiator:110 - Statistics initialized [enabled=false]
14:40:06,910 DEBUG pool-2-thread-13 internal.EntityManagerFactoryRegistry:56 - Initializing EntityManagerFactoryRegistry : org.hibernate.ejb.internal.EntityManagerFactoryRegistry@75cc9008
14:40:06,911 DEBUG pool-2-thread-13 internal.EntityManagerFactoryRegistry:66 - Registering EntityManagerFactory: something 
14:40:06,967  INFO pool-2-thread-13 jpa.LocalContainerEntityManagerFactoryBean:264 - Building JPA container EntityManagerFactory for persistence unit 'default'
14:40:06,967 DEBUG pool-2-thread-13 type.BasicTypeRegistry:143 - Adding type registration boolean -> org.hibernate.type.BooleanType@4cb91eff

...

14:40:07,128 DEBUG pool-2-thread-13 internal.SessionFactoryRegistry:75 - Registering SessionFactory: 81a9b5a6-83aa-46ee-be68-d642e6fda584 (<unnamed>)
14:40:07,128 DEBUG pool-2-thread-13 internal.SessionFactoryRegistry:82 - Not binding SessionFactory to JNDI, no JNDI name configured
14:40:07,129 DEBUG pool-2-thread-13 internal.SessionFactoryImpl:487 - Instantiated session factory
14:40:07,129 DEBUG pool-2-thread-13 internal.SessionFactoryImpl:1119 - Checking 0 named HQL queries
14:40:07,129 DEBUG pool-2-thread-13 internal.SessionFactoryImpl:1142 - Checking 0 named SQL queries
14:40:07,129 DEBUG pool-2-thread-13 internal.StatisticsInitiator:110 - Statistics initialized [enabled=false]
14:40:07,130 DEBUG pool-2-thread-13 internal.EntityManagerFactoryRegistry:66 - Registering EntityManagerFactory: something 
14:40:07,130  WARN pool-2-thread-13 internal.EntityManagerFactoryRegistry:80 - HHH000436: Entity manager factory name (something) is already registered.  If entity manager will be clustered or passivated, specify a unique value for property 'hibernate.ejb.entitymanager_factory_name'

Answer 1

I came across the same issue but in a different scenario. The EntityManagerFactoryRegistry produces the same HHH000436 warning, when executing multiple tests in the same run (i.e. the same JVM) started from my IDE.

The problem can surface in case there are at least two test classes using the SpringJUnit4ClassRunner to load different Spring test application contexts each containing an EntityManagerFactory.

The root cause is that Hibernate maintains a static registry of EntityManagerFactory instances, where the creation of the second instance may cause the collision the log message is about. So why isn't the first instance deregistered after the first test finished executing? It normally would when the app context containing that EntityManagerFactory instance gets destroyed. The reason it doesn't happen during test execution is that the Spring test context framework caches all loaded contexts in order to avoid re-loading the exact same context potentially needed by multiple tests. As a result, beans in these contexts doesn't get destroyed until after the last test finished executing, and Hibernate will just collect all the EntityManagerFactory instances ever created.

It's really a non-issue, but if someone is really annoyed by the warning message, there are a few possible ways to avoid seeing it:

1. Make sure the EntityManagerFactory instances get a different name (they are keyed by name in the registry). Chek the constructor of EntityManagerFactoryImpl on how the name is derived.
2. Use @DirtiesContext on the test class to cause the SpringJUnit4ClassRunner to close the context and remove it from its context cache immediately after executing the test class.
3. Simply set the logging level of EntityManagerFactoryRegistry to error...

Hope this helps someone.