使用 Hibernate 在 JPA 中 调用 generateSchema 会出现执行两次 SQL 语句问题的解决方法

1 描述问题

使用的 Hibernate 版本：5.1.0.Final

今天发现在使用 Hibernate 实现的 JPA 中 调用 generateSchema 后，所有的 SQL 语句都会被执行两次：

public void generateSchema(String action){
//Take exiting EMF properties, override the schema generation setting on a copy
Map<String,String> createSchemaProperties=new HashMap<>(properties);
createSchemaProperties.put(
"javax.persistence.schema-generation.database.action",
action
);
Persistence.generateSchema(getPersistenceUnitName(),createSchemaProperties);
}

虽然可以通过单元测试，但总是觉得很奇怪，报错的原因是因为同一张表创建了两次：

...
Hibernate:
drop table if exists hibernate_sequence
Hibernate:
drop table if exists Item
Hibernate:
drop table if exists hibernate_sequence
Hibernate:
drop table if exists Item
二月 16, 2017 4:54:20 下午 org.hibernate.jpa.internal.util.LogHelper logPersistenceUnitInformation
INFO: HHH000204: Processing PersistenceUnitInfo [
name: SimpleXMLCompletePU
...]
二月 16, 2017 4:54:20 下午 org.hibernate.dialect.Dialect <init>
INFO: HHH000400: Using dialect: org.hibernate.dialect.MySQL57InnoDBDialect
二月 16, 2017 4:54:20 下午 org.hibernate.envers.boot.internal.EnversServiceImpl configure
INFO: Envers integration enabled? : true
二月 16, 2017 4:54:20 下午 org.hibernate.cfg.annotations.reflection.JPAOverriddenAnnotationReader checkForOrphanProperties
WARN: HHH000207: Property net.deniro.hibernate.model.simple.Item.id not found in class but described in <mapping-file/> (possible typo error)
二月 16, 2017 4:54:20 下午 org.hibernate.cfg.annotations.reflection.JPAOverriddenAnnotationReader checkForOrphanProperties
WARN: HHH000207: Property net.deniro.hibernate.model.simple.Item.category not found in class but described in <mapping-file/> (possible typo error)
Hibernate:
create table hibernate_sequence (
next_val bigint
) ENGINE=InnoDB
Hibernate:
insert into hibernate_sequence values ( 1 )
Hibernate:
create table Item (
id bigint not null,
auctionEnd datetime(6),
name varchar(255) not null,
primary key (id)
) ENGINE=InnoDB
二月 16, 2017 4:54:20 下午 org.hibernate.tool.schema.internal.SchemaCreatorImpl applyImportSources
INFO: HHH000476: Executing import script 'org.hibernate.tool.schema.internal.exec.ScriptSourceInputNonExistentImpl@6b04acb2'
二月 16, 2017 4:54:20 下午 org.hibernate.hql.internal.QueryTranslatorFactoryInitiator initiateService
INFO: HHH000397: Using ASTQueryTranslatorFactory
二月 16, 2017 4:54:20 下午 org.hibernate.tool.schema.internal.ExceptionHandlerLoggedImpl handleException
WARN: GenerationTarget encountered exception accepting command : Unable to execute command [
create table hibernate_sequence (
next_val bigint
) ENGINE=InnoDB]
org.hibernate.tool.schema.spi.CommandAcceptanceException: Unable to execute command [
create table hibernate_sequence (
next_val bigint
) ENGINE=InnoDB]
at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:63)
at org.hibernate.tool.schema.internal.SchemaCreatorImpl.applySqlString(SchemaCreatorImpl.java:423)
at org.hibernate.tool.schema.internal.SchemaCreatorImpl.applySqlStrings(SchemaCreatorImpl.java:408)
at org.hibernate.tool.schema.internal.SchemaCreatorImpl.createFromMetadata(SchemaCreatorImpl.java:310)
at org.hibernate.tool.schema.internal.SchemaCreatorImpl.performCreation(SchemaCreatorImpl.java:165)
at org.hibernate.tool.schema.internal.SchemaCreatorImpl.doCreation(SchemaCreatorImpl.java:134)
at org.hibernate.tool.schema.internal.SchemaCreatorImpl.doCreation(SchemaCreatorImpl.java:120)
at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.performDatabaseAction(SchemaManagementToolCoordinator.java:122)
at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.process(SchemaManagementToolCoordinator.java:64)
at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.generateSchema(EntityManagerFactoryBuilderImpl.java:862)
at org.hibernate.jpa.HibernatePersistenceProvider.generateSchema(HibernatePersistenceProvider.java:155)
at javax.persistence.Persistence.generateSchema(Persistence.java:87)
at net.deniro.hibernate.env.JPASetup.generateSchema(JPASetup.java:93)
at net.deniro.hibernate.env.JPASetup.createSchema(JPASetup.java:79)
at net.deniro.hibernate.env.JPATest.beforeMethod(JPATest.java:61)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
at org.testng.internal.Invoker.invokeConfigurationMethod(Invoker.java:564)
at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:213)
at org.testng.internal.Invoker.invokeMethod(Invoker.java:653)
at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
at org.testng.TestRunner.privateRun(TestRunner.java:767)
at org.testng.TestRunner.run(TestRunner.java:617)
at org.testng.SuiteRunner.runTest(SuiteRunner.java:334)
at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:329)
at org.testng.SuiteRunner.privateRun(SuiteRunner.java:291)
at org.testng.SuiteRunner.run(SuiteRunner.java:240)
at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
at org.testng.TestNG.runSuitesSequentially(TestNG.java:1224)
at org.testng.TestNG.runSuitesLocally(TestNG.java:1149)
at org.testng.TestNG.run(TestNG.java:1057)
at org.testng.remote.RemoteTestNG.run(RemoteTestNG.java:111)
at org.testng.remote.RemoteTestNG.initAndRun(RemoteTestNG.java:204)
at org.testng.remote.RemoteTestNG.main(RemoteTestNG.java:175)
at org.testng.RemoteTestNGStarter.main(RemoteTestNGStarter.java:125)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:140)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table 'hibernate_sequence' already exists
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:377)
at com.mysql.jdbc.Util.getInstance(Util.java:360)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:978)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3887)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3823)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2435)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2582)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2526)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2484)
at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:848)
at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:742)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at bitronix.tm.resource.jdbc.BaseProxyHandlerClass.invoke(BaseProxyHandlerClass.java:64)
at com.sun.proxy.$Proxy28.execute(Unknown Source)
at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:51)
... 46 more

Hibernate:
create table hibernate_sequence (
next_val bigint
) ENGINE=InnoDB
Hibernate:
insert into hibernate_sequence values ( 1 )
Hibernate:
create table Item (
id bigint not null,
auctionEnd datetime(6),
name varchar(255) not null,
primary key (id)
) ENGINE=InnoDB
二月 16, 2017 4:54:20 下午 org.hibernate.tool.schema.internal.ExceptionHandlerLoggedImpl handleException
WARN: GenerationTarget encountered exception accepting command : Unable to execute command [
create table Item (
id bigint not null,
auctionEnd datetime(6),
name varchar(255) not null,
primary key (id)
) ENGINE=InnoDB]
org.hibernate.tool.schema.spi.CommandAcceptanceException: Unable to execute command [
create table Item (
id bigint not null,
auctionEnd datetime(6),
name varchar(255) not null,
primary key (id)
) ENGINE=InnoDB]
at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:63)
at org.hibernate.tool.schema.internal.SchemaCreatorImpl.applySqlString(SchemaCreatorImpl.java:423)
at org.hibernate.tool.schema.internal.SchemaCreatorImpl.applySqlStrings(SchemaCreatorImpl.java:408)
at org.hibernate.tool.schema.internal.SchemaCreatorImpl.createFromMetadata(SchemaCreatorImpl.java:310)
at org.hibernate.tool.schema.internal.SchemaCreatorImpl.performCreation(SchemaCreatorImpl.java:165)
at org.hibernate.tool.schema.internal.SchemaCreatorImpl.doCreation(SchemaCreatorImpl.java:134)
at org.hibernate.tool.schema.internal.SchemaCreatorImpl.doCreation(SchemaCreatorImpl.java:120)
at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.performDatabaseAction(SchemaManagementToolCoordinator.java:122)
at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.process(SchemaManagementToolCoordinator.java:64)
at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.generateSchema(EntityManagerFactoryBuilderImpl.java:862)
at org.hibernate.jpa.HibernatePersistenceProvider.generateSchema(HibernatePersistenceProvider.java:155)
at javax.persistence.Persistence.generateSchema(Persistence.java:87)
at net.deniro.hibernate.env.JPASetup.generateSchema(JPASetup.java:93)
at net.deniro.hibernate.env.JPASetup.createSchema(JPASetup.java:79)
at net.deniro.hibernate.env.JPATest.beforeMethod(JPATest.java:61)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
at org.testng.internal.Invoker.invokeConfigurationMethod(Invoker.java:564)
at org.testng.internal.Invoker.invokeConfigurations(Invoker.java:213)
at org.testng.internal.Invoker.invokeMethod(Invoker.java:653)
at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
at org.testng.TestRunner.privateRun(TestRunner.java:767)
at org.testng.TestRunner.run(TestRunner.java:617)
at org.testng.SuiteRunner.runTest(SuiteRunner.java:334)
at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:329)
at org.testng.SuiteRunner.privateRun(SuiteRunner.java:291)
at org.testng.SuiteRunner.run(SuiteRunner.java:240)
at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
at org.testng.TestNG.runSuitesSequentially(TestNG.java:1224)
at org.testng.TestNG.runSuitesLocally(TestNG.java:1149)
at org.testng.TestNG.run(TestNG.java:1057)
at org.testng.remote.RemoteTestNG.run(RemoteTestNG.java:111)
at org.testng.remote.RemoteTestNG.initAndRun(RemoteTestNG.java:204)
at org.testng.remote.RemoteTestNG.main(RemoteTestNG.java:175)
at org.testng.RemoteTestNGStarter.main(RemoteTestNGStarter.java:125)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.intellij.rt.execution.application.AppMain.main(AppMain.java:140)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table 'item' already exists
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:377)
at com.mysql.jdbc.Util.getInstance(Util.java:360)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:978)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3887)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3823)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2435)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2582)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2526)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2484)
at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:848)
at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:742)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at bitronix.tm.resource.jdbc.BaseProxyHandlerClass.invoke(BaseProxyHandlerClass.java:64)
at com.sun.proxy.$Proxy28.execute(Unknown Source)
at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:51)
... 46 more

...

===============================================
Custom suite
Total tests run: 1, Failures: 0, Skips: 0
===============================================

Process finished with exit code 0

2 分析问题

打开源代码看看，一路跟踪到

org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl：

@Override
public void generateSchema() {
// This seems overkill, but building the SF is necessary to get the Integrators to kick in.
// Metamodel will clean this up...
try {
SessionFactoryBuilder sfBuilder = metadata().getSessionFactoryBuilder();
populate( sfBuilder, standardServiceRegistry );
sfBuilder.build();

SchemaManagementToolCoordinator.process(
metadata, standardServiceRegistry, configurationValues, DelayedDropRegistryNotAvailableImpl.INSTANCE
);
}
catch (Exception e) {
throw persistenceException( "Error performing schema management", e );
}

// release this builder
cancel();
}

这里面的

sfBuilder.build()

与

SchemaManagementToolCoordinator.process（...）

都会执行一次定义的 SQL 语句。

3 解决问题

sfBuilder.build()

与

SchemaManagementToolCoordinator.process（...）

任意注释掉一个就解决问题啦 O(∩_∩)O~