Format conversion error in org.hibernate.cfg.Settings

Description

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

Environment

None

Status

Assignee

Unassigned

Reporter

Angelo Immediata

Fix versions

None

Labels

backPortable

None

Suitable for new contributors

None

Requires Release Note

None

Pull Request

None

backportDecision

None

Affects versions

5.4.5

Priority

Minor
Configure