| Hi.
This is my environment:
- Spring version 5.2.0
- Spring JPA data version 2.2.0
- Hibernate-core: 5.4.5
- logback: 1.1.3
- jcloverslf4j: 1.7.28
- slf4j-api: 1.7.28
When I put my hibernate log level to TRACE I got the following exception (in bold the main part):
2019-10-02 17:41:44,670 1720 [main] DEBUG o.h.internal.SessionFactoryImpl - Building session factory
2019-10-02 17:41:44,671 1721 [main] DEBUG org.hibernate.cfg.Settings - SessionFactory name : null
2019-10-02 17:41:44,671 1721 [main] DEBUG org.hibernate.cfg.Settings - Automatic flush during beforeCompletion(): enabled
2019-10-02 17:41:44,671 1721 [main] DEBUG org.hibernate.cfg.Settings - Automatic session close at end of transaction: disabled
2019-10-02 17:41:44,671 1721 [main] DEBUG org.hibernate.cfg.Settings - Statistics: enabled
2019-10-02 17:41:44,671 1721 [main] DEBUG org.hibernate.cfg.Settings - Deleted entity synthetic identifier rollback: disabled
2019-10-02 17:41:44,671 1721 [main] DEBUG org.hibernate.cfg.Settings - Default entity-mode: pojo
2019-10-02 17:41:44,671 1721 [main] DEBUG org.hibernate.cfg.Settings - Check Nullability in Core (should be disabled when Bean Validation is on): enabled
2019-10-02 17:41:44,671 1721 [main] DEBUG org.hibernate.cfg.Settings - Allow initialization of lazy state outside session : disabled
2019-10-02 17:41:44,672 1722 [main] WARN o.s.w.c.s.GenericWebApplicationContext - Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in it.eng.tz.rubrica.config.DbConfig: Invocation of init method failed; nested exception is javax.persistence.PersistenceException: [PersistenceUnit: rubrica.jpa.unit] Unable to build Hibernate SessionFactory; nested exception is java.util.UnknownFormatConversionException: Conversion = '%'
2019-10-02 17:41:44,672 1722 [main] INFO com.zaxxer.hikari.HikariDataSource - springHikariCP - Shutdown initiated...
2019-10-02 17:41:44,675 1725 [main] INFO com.zaxxer.hikari.HikariDataSource - springHikariCP - Shutdown completed.
2019-10-02 17:41:44,681 1731 [main] ERROR o.s.test.context.TestContextManager - Caught exception while allowing TestExecutionListener [org.springframework.test.context.web.ServletTestExecutionListener@5c671d7f] to prepare test instance [it.eng.tz.rubrica.core.tests.DbTest@4ecd00b5]
java.lang.IllegalStateException: Failed to load ApplicationContext
at org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate.loadContext(DefaultCacheAwareContextLoaderDelegate.java:132) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.support.DefaultTestContext.getApplicationContext(DefaultTestContext.java:123) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.web.ServletTestExecutionListener.setUpRequestContextIfNecessary(ServletTestExecutionListener.java:190) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.web.ServletTestExecutionListener.prepareTestInstance(ServletTestExecutionListener.java:132) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.TestContextManager.prepareTestInstance(TestContextManager.java:244) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.createTest(SpringJUnit4ClassRunner.java:227) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.junit4.SpringJUnit4ClassRunner$1.runReflectiveCall(SpringJUnit4ClassRunner.java:289) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) ~[junit-4.12.jar:4.12]
at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.methodBlock(SpringJUnit4ClassRunner.java:291) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:246) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:97) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) ~[junit-4.12.jar:4.12]
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) ~[junit-4.12.jar:4.12]
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) ~[junit-4.12.jar:4.12]
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) ~[junit-4.12.jar:4.12]
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) ~[junit-4.12.jar:4.12]
at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.junit.runners.ParentRunner.run(ParentRunner.java:363) ~[junit-4.12.jar:4.12]
at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:190) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:89) ~[.cp/:na]
at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:41) ~[.cp/:na]
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:541) ~[.cp/:na]
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:763) ~[.cp/:na]
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:463) ~[.cp/:na]
at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:209) ~[.cp/:na]
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in it.eng.tz.rubrica.config.DbConfig: Invocation of init method failed; nested exception is javax.persistence.PersistenceException: [PersistenceUnit: rubrica.jpa.unit] Unable to build Hibernate SessionFactory; nested exception is java.util.UnknownFormatConversionException: Conversion = '%'
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1803) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:595) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:323) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1108) ~[spring-context-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:868) ~[spring-context-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:550) ~[spring-context-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.web.AbstractGenericWebContextLoader.loadContext(AbstractGenericWebContextLoader.java:129) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.web.AbstractGenericWebContextLoader.loadContext(AbstractGenericWebContextLoader.java:61) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.support.AbstractDelegatingSmartContextLoader.delegateLoading(AbstractDelegatingSmartContextLoader.java:275) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.support.AbstractDelegatingSmartContextLoader.loadContext(AbstractDelegatingSmartContextLoader.java:243) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate.loadContextInternal(DefaultCacheAwareContextLoaderDelegate.java:99) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate.loadContext(DefaultCacheAwareContextLoaderDelegate.java:124) ~[spring-test-5.2.0.RELEASE.jar:5.2.0.RELEASE]
... 25 common frames omitted
Caused by: javax.persistence.PersistenceException: [PersistenceUnit: rubrica.jpa.unit] Unable to build Hibernate SessionFactory; nested exception is java.util.UnknownFormatConversionException: Conversion = '%'
at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.buildNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:403) ~[spring-orm-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.afterPropertiesSet(AbstractEntityManagerFactoryBean.java:378) ~[spring-orm-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.afterPropertiesSet(LocalContainerEntityManagerFactoryBean.java:341) ~[spring-orm-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1862) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1799) ~[spring-beans-5.2.0.RELEASE.jar:5.2.0.RELEASE]
... 40 common frames omitted
Caused by: java.util.UnknownFormatConversionException: Conversion = '%'
at java.base/java.util.Formatter.checkText(Formatter.java:2732) ~[na:na]
at java.base/java.util.Formatter.parse(Formatter.java:2718) ~[na:na]
at java.base/java.util.Formatter.format(Formatter.java:2655) ~[na:na]
at java.base/java.util.Formatter.format(Formatter.java:2609) ~[na:na]
at java.base/java.lang.String.format(String.java:2988) ~[na:na]
at org.jboss.logging.Slf4jLocationAwareLogger.doLogf(Slf4jLocationAwareLogger.java:81) ~[jboss-logging-3.3.0.Final.jar:3.3.0.Final]
at org.jboss.logging.Logger.debugf(Logger.java:712) ~[jboss-logging-3.3.0.Final.jar:3.3.0.Final]
at org.hibernate.cfg.Settings.<init>(Settings.java:79) ~[classes/:5.4.5.Final]
at org.hibernate.cfg.Settings.<init>(Settings.java:54) ~[classes/:5.4.5.Final]
at org.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:210) ~[hibernate-core-5.4.5.Final.jar:5.4.5.Final]
at org.hibernate.boot.internal.SessionFactoryBuilderImpl.build(SessionFactoryBuilderImpl.java:462) ~[hibernate-core-5.4.5.Final.jar:5.4.5.Final]
at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:935) ~[hibernate-core-5.4.5.Final.jar:5.4.5.Final]
at org.springframework.orm.jpa.vendor.SpringHibernateJpaPersistenceProvider.createContainerEntityManagerFactory(SpringHibernateJpaPersistenceProvider.java:58) ~[spring-orm-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:365) ~[spring-orm-5.2.0.RELEASE.jar:5.2.0.RELEASE]
at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.buildNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:391) ~[spring-orm-5.2.0.RELEASE.jar:5.2.0.RELEASE]
... 44 common frames omitted
By debugging I notied that when Hibernate tries to build the SessionFactory by the class org.hibernate.internal.SessionFactoryImpl, the deprecated class org.hibernate.cfg.Settings is used.
When logs are set to TRACE (or DEBUG) it enters inside the if if ( LOG.isDebugEnabled() ) { and more specifically it tries to execute the following line LOG.debugf( "Using BatchFetchStyle : %", sessionFactoryOptions.getBatchFetchStyle().name() ); and % is not a valid format. I modified the line in this way: LOG.debugf( "Using BatchFetchStyle : %s", sessionFactoryOptions.getBatchFetchStyle().name() ); and all worked pretty good I attache the modified class |
