Message Title

22 giu 2015 16:09:39,785  INFO LogHelper:31 - HHH000204: Processing PersistenceUnitInfo [
	name: TestPU
	...]
22 giu 2015 16:09:39,898  INFO Version:37 - HHH000412: Hibernate Core {5.0.0.CR1}
22 giu 2015 16:09:39,905  INFO Environment:207 - HHH000205: Loaded properties from resource hibernate.properties: {hibernate.connection.password=****, hibernate.c3p0.acquire_increment=10, hibernate.connection.autocommit=false, hibernate.c3p0.idle_test_period=3000, hibernate.c3p0.checkoutTimeout=5000, hibernate.default_catalog=Test, hibernate.show_sql=true, hibernate.c3p0.max_statements=0, hibernate.bytecode.use_reflection_optimizer=false, hibernate.c3p0.timeout=300, hibernate.archive.autodetection=, hibernate.hbm2ddl.auto=validate, hibernate.c3p0.min_size=5, hibernate.default_schema=dbo, hibernate.connection.username=sa, hibernate.connection.driver_class=net.sourceforge.jtds.jdbc.Driver, hibernate.current_session_context_class=thread, hibernate.c3p0.max_size=30, hibernate.connection.provider_class=org.hibernate.c3p0.internal.C3P0ConnectionProvider, hibernate.dialect=org.hibernate.dialect.SQLServerDialect, hibernate.connection.url=jdbc:jtds:sqlserver://localhost/Test;instance=SQL2012, hibernate.c3p0.max_statements_per_connection=0}
22 giu 2015 16:09:39,906  INFO Environment:329 - HHH000021: Bytecode provider name : javassist
22 giu 2015 16:09:39,965  INFO Version:66 - HCANN000001: Hibernate Commons Annotations {4.0.5.Final}
22 giu 2015 16:09:40,140  INFO ConnectionProviderInitiator:173 - HHH000130: Instantiating explicit connection provider: org.hibernate.c3p0.internal.C3P0ConnectionProvider
22 giu 2015 16:09:40,158  INFO C3P0ConnectionProvider:117 - HHH010002: C3P0 using driver: net.sourceforge.jtds.jdbc.Driver at URL: jdbc:jtds:sqlserver://localhost/Test;instance=SQL2012
22 giu 2015 16:09:40,158  INFO C3P0ConnectionProvider:118 - HHH000046: Connection properties: {user=sa, password=****, autocommit=false}
22 giu 2015 16:09:40,158  INFO C3P0ConnectionProvider:121 - HHH000006: Autocommit mode: false
22 giu 2015 16:09:40,179  INFO MLog:92 - MLog clients using log4j logging.
22 giu 2015 16:09:40,593  INFO C3P0Registry:216 - Initializing c3p0-0.9.2.1 [built 20-March-2013 11:16:28 +0000; debug? true; trace: 10]
22 giu 2015 16:09:40,678  INFO AbstractPoolBackedDataSource:522 - Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@59f79a33 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@3ec0ff4 [ acquireIncrement -> 10, acquireRetryAttempts -> 0, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 5000, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 1hge4v99a7npwtz8t3l4l|fd736f, idleConnectionTestPeriod -> 3000, initialPoolSize -> 5, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 300, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 30, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 5, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@c5ec4e65 [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> 1hge4v99a7npwtz8t3l4l|10875ae, jdbcUrl -> jdbc:jtds:sqlserver://localhost/Test;instance=SQL2012, properties -> {user=******, password=******, autocommit=false} ], preferredTestQuery -> null, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, factoryClassLocation -> null, identityToken -> 1hge4v99a7npwtz8t3l4l|581b90, numHelperThreads -> 3 ]
22 giu 2015 16:09:41,114  INFO Dialect:154 - HHH000400: Using dialect: org.hibernate.dialect.SQLServerDialect
22 giu 2015 16:09:41,206  INFO LobCreatorBuilderImpl:98 - HHH000423: Disabling contextual LOB creation as JDBC driver reported JDBC version [3] less than 4
22 giu 2015 16:09:41,693  INFO SchemaValidator:69 - HHH000229: Running schema validator
javax.persistence.PersistenceException: [PersistenceUnit: TestPU] Unable to build Hibernate SessionFactory
	at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.persistenceException(EntityManagerFactoryBuilderImpl.java:854)
	at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:782)
	at org.hibernate.jpa.HibernatePersistenceProvider.createEntityManagerFactory(HibernatePersistenceProvider.java:58)
	at javax.persistence.Persistence.createEntityManagerFactory(Persistence.java:55)
	at javax.persistence.Persistence.createEntityManagerFactory(Persistence.java:39)
	at testH5.TestH5.main(TestH5.java:20)
Caused by: org.hibernate.tool.schema.spi.SchemaManagementException: Schema-validation: missing column [aCamelCaseField] in table [Table1]
	at org.hibernate.tool.schema.internal.SchemaValidatorImpl.validateTable(SchemaValidatorImpl.java:85)
	at org.hibernate.tool.schema.internal.SchemaValidatorImpl.doValidation(SchemaValidatorImpl.java:50)
	at org.hibernate.tool.hbm2ddl.SchemaValidator.validate(SchemaValidator.java:91)
	at org.hibernate.internal.SessionFactoryImpl.<init>(SessionFactoryImpl.java:476)
	at org.hibernate.boot.internal.SessionFactoryBuilderImpl.build(SessionFactoryBuilderImpl.java:445)
	at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:779)
	... 4 more

Investigating for the cause, brought me to
org.hibernate.engine.jdbc.env.internal.NormalizingIdentifierHelperImpl#toIdentifierFromMetaData() at line 222:

		// lovely decipher of whether the incoming value represents a quoted identifier...
		final boolean isUpperCase = text.toUpperCase( Locale.ROOT ).equals( text );
		final boolean isLowerCase = text.toLowerCase( Locale.ROOT ).equals( text );
		final boolean isMixedCase = ! isLowerCase && ! isUpperCase;

		if ( quotedCaseStrategy == IdentifierCaseStrategy.MIXED && isMixedCase ) { // THIS IS LINE 222
			log.trace( "Interpreting return value as quoted due to case strategy" );
			return Identifier.toIdentifier( text, true );
		}

This way a quoted column name is generated and expected later at org.hibernate.tool.schema.internal.SchemaValidatorImpl#validateTable() line 83-84.

			final ColumnInformation existingColumn = tableInformation.getColumn( Identifier.toIdentifier( column.getQuotedName() ) );
			if ( existingColumn == null ) {
				throw new SchemaManagementException(
						String.format(
								"Schema-validation: missing column [%s] in table [%s]",
								column.getName(),
								table.getName()
						)
				);
			}

	@Column(name = "`aCamelCaseField`", nullable = false, length = 50)
	public String getaCamelCaseField() {
		return aCamelCaseField;
	}

This strange behaviour is not present in version 4.3.10, and the entity is correctly validated even without the backticks.

I think the validator should be robust enough to manage the presence or the absence of backticks in the column definition, so it should escape the eventually present backticks in order to check for column existence.. or maybe, it should add backticks in every column definition so that comparing just works..