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

2017-02-16 17:33
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~