search

apache / shardingsphere

Empowering Data Intelligence with Distributed SQL for Sharding, Scalability, and Security Across All Databases.
Apache License 2.0
19.97k stars 6.75k forks source link

hbm2ddl update "CREATE INDEX" exception in jpa #1711

Closed dalaocu closed 5 years ago

dalaocu commented 5 years ago

I have set the option "spring.jpa.properties.hibernate.hbm2ddl.auto=update".

My usage is compile('io.shardingsphere:sharding-jdbc-spring-boot-starter:3.1.0').

It's OK when I run the springboot application the first time. But it will warn when you restart the app again. The tables are OK, and only the indexes will be created again, which is not as expected. Here is the warn logs below.

2019-01-04 15:57:45.090 WARN 19228 --- [main] o.h.t.s.i.ExceptionHandlerLoggedImpl : GenerationTarget encountered exception accepting command : Error executing DDL "create index block_height on activity_activity (block_height)" via JDBC Statement

org.hibernate.tool.schema.spi.CommandAcceptanceException: Error executing DDL "create index block_height on activity_activity (block_height)" via JDBC Statement at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:67) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applySqlString(AbstractSchemaMigrator.java:559) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applySqlStrings(AbstractSchemaMigrator.java:504) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applyIndexes(AbstractSchemaMigrator.java:331) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.GroupedSchemaMigratorImpl.performTablesMigration(GroupedSchemaMigratorImpl.java:84) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.performMigration(AbstractSchemaMigrator.java:207) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.doMigration(AbstractSchemaMigrator.java:114) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.performDatabaseAction(SchemaManagementToolCoordinator.java:183) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.process(SchemaManagementToolCoordinator.java:72) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.internal.SessionFactoryImpl.(SessionFactoryImpl.java:310) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.boot.internal.SessionFactoryBuilderImpl.build(SessionFactoryBuilderImpl.java:467) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:939) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.springframework.orm.jpa.vendor.SpringHibernateJpaPersistenceProvider.createContainerEntityManagerFactory(SpringHibernateJpaPersistenceProvider.java:57) [spring-orm-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:365) [spring-orm-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.buildNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:390) [spring-orm-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.afterPropertiesSet(AbstractEntityManagerFactoryBean.java:377) [spring-orm-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.afterPropertiesSet(LocalContainerEntityManagerFactoryBean.java:341) [spring-orm-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1804) [spring-beans-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1741) [spring-beans-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:576) [spring-beans-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:498) [spring-beans-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:320) [spring-beans-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222) ~[spring-beans-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:318) [spring-beans-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:199) [spring-beans-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1083) ~[spring-context-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:853) ~[spring-context-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:546) ~[spring-context-5.1.2.RELEASE.jar:5.1.2.RELEASE] at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:140) ~[spring-boot-2.1.0.RELEASE.jar:2.1.0.RELEASE] at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:775) ~[spring-boot-2.1.0.RELEASE.jar:2.1.0.RELEASE] at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:397) ~[spring-boot-2.1.0.RELEASE.jar:2.1.0.RELEASE] at org.springframework.boot.SpringApplication.run(SpringApplication.java:316) ~[spring-boot-2.1.0.RELEASE.jar:2.1.0.RELEASE] at org.springframework.boot.SpringApplication.run(SpringApplication.java:1260) ~[spring-boot-2.1.0.RELEASE.jar:2.1.0.RELEASE] at org.springframework.boot.SpringApplication.run(SpringApplication.java:1248) ~[spring-boot-2.1.0.RELEASE.jar:2.1.0.RELEASE] at com.webank.bcosbee.BcosBeeApplication.main(BcosBeeApplication.java:23) ~[main/:na] Caused by: java.sql.SQLSyntaxErrorException: Duplicate key name 'block_height_activity_activity' at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:120) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.mysql.cj.jdbc.StatementImpl.executeInternal(StatementImpl.java:782) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.mysql.cj.jdbc.StatementImpl.execute(StatementImpl.java:666) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.zaxxer.hikari.pool.ProxyStatement.execute(ProxyStatement.java:95) ~[HikariCP-3.2.0.jar:na] at com.zaxxer.hikari.pool.HikariProxyStatement.execute(HikariProxyStatement.java) ~[HikariCP-3.2.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor$8.execute(StatementExecutor.java:205) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor$12.executeSQL(StatementExecutor.java:267) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor$12.executeSQL(StatementExecutor.java:263) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.core.executor.sql.execute.SQLExecuteCallback.execute0(SQLExecuteCallback.java:72) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.sql.execute.SQLExecuteCallback.execute(SQLExecuteCallback.java:61) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.ShardingExecuteEngine.syncGroupExecute(ShardingExecuteEngine.java:175) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.ShardingExecuteEngine.groupExecute(ShardingExecuteEngine.java:152) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.sql.execute.SQLExecuteTemplate.executeGroup(SQLExecuteTemplate.java:71) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.sql.execute.SQLExecuteTemplate.executeGroup(SQLExecuteTemplate.java:54) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.AbstractStatementExecutor.executeCallback(AbstractStatementExecutor.java:114) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor.execute(StatementExecutor.java:270) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor.execute(StatementExecutor.java:201) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.jdbc.core.statement.ShardingStatement.execute(ShardingStatement.java:161) ~[sharding-jdbc-core-3.1.0.jar:na] at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:54) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final] ... 34 common frames omitted

codefairy08 commented 5 years ago

this is hibernate issue, please refer this link https://www.cnblogs.com/zzsaf/p/6902559.html may give you some help

dalaocu commented 5 years ago

I've tried, but still not work.

spring.jpa.properties.hibernate.dialect=org.hibernate.dialect.MySQL5Dialect

codefairy08 commented 5 years ago

"create index block_height on activity_activity (block_height)" this sql call execute successed in mysql client? can you provide the minimal demo of reproduced this error ?

dalaocu commented 5 years ago

Sorry, my project is not open source. I have to write a demo to show you. I'm sure that it's not a hibernate issue because if I remove the ShardingSphere then it will work. This case is easy to check if you build a spring data jpa project with springboot. Actually I have rewrote the Dialect and It works fine when I just use hibernate.

` public class MysqlConfig extends MySQL57Dialect { @Override public String getTableTypeString() { return " ENGINE=InnoDB DEFAULT CHARSET=utf8"; }

}

`

dalaocu commented 5 years ago

I wrote the minimal demo of reproduced this error.

Please help me to check it. Thanks!

dalaocu commented 5 years ago

I add two branches in my demo project in order to simplify your work.

Switch to branch "using-sharding-jdbc-log", the warn log appeared:

2019-02-25 21:17:05.833 WARN 42973 --- [ main] o.h.t.s.i.ExceptionHandlerLoggedImpl : GenerationTarget encountered exception accepting command : Error executing DDL "create index block_height on activity_activity (block_height)" via JDBC Statement

org.hibernate.tool.schema.spi.CommandAcceptanceException: Error executing DDL "create index block_height on activity_activity (block_height)" via JDBC Statement at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:67) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applySqlString(AbstractSchemaMigrator.java:559) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applySqlStrings(AbstractSchemaMigrator.java:504) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applyIndexes(AbstractSchemaMigrator.java:331) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.GroupedSchemaMigratorImpl.performTablesMigration(GroupedSchemaMigratorImpl.java:84) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.performMigration(AbstractSchemaMigrator.java:207) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.doMigration(AbstractSchemaMigrator.java:114) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.performDatabaseAction(SchemaManagementToolCoordinator.java:183) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.process(SchemaManagementToolCoordinator.java:72) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.internal.SessionFactoryImpl.(SessionFactoryImpl.java:310) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.boot.internal.SessionFactoryBuilderImpl.build(SessionFactoryBuilderImpl.java:467) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:939) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.springframework.orm.jpa.vendor.SpringHibernateJpaPersistenceProvider.createContainerEntityManagerFactory(SpringHibernateJpaPersistenceProvider.java:57) [spring-orm-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:365) [spring-orm-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.buildNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:390) [spring-orm-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.afterPropertiesSet(AbstractEntityManagerFactoryBean.java:377) [spring-orm-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.afterPropertiesSet(LocalContainerEntityManagerFactoryBean.java:341) [spring-orm-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1804) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1741) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:576) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:498) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:320) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222) ~[spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:318) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:199) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1083) ~[spring-context-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:853) ~[spring-context-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:546) ~[spring-context-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:142) ~[spring-boot-2.1.2.RELEASE.jar:2.1.2.RELEASE] at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:775) ~[spring-boot-2.1.2.RELEASE.jar:2.1.2.RELEASE] at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:397) ~[spring-boot-2.1.2.RELEASE.jar:2.1.2.RELEASE] at org.springframework.boot.SpringApplication.run(SpringApplication.java:316) ~[spring-boot-2.1.2.RELEASE.jar:2.1.2.RELEASE] at org.springframework.boot.SpringApplication.run(SpringApplication.java:1260) ~[spring-boot-2.1.2.RELEASE.jar:2.1.2.RELEASE] at org.springframework.boot.SpringApplication.run(SpringApplication.java:1248) ~[spring-boot-2.1.2.RELEASE.jar:2.1.2.RELEASE] at com.dalaocu.sharding.demo.ShardingDemoApplication.main(ShardingDemoApplication.java:13) ~[main/:na] Caused by: java.sql.SQLSyntaxErrorException: Duplicate key name 'block_height_activity_activity' at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:120) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.mysql.cj.jdbc.StatementImpl.executeInternal(StatementImpl.java:782) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.mysql.cj.jdbc.StatementImpl.execute(StatementImpl.java:666) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.zaxxer.hikari.pool.ProxyStatement.execute(ProxyStatement.java:95) ~[HikariCP-3.2.0.jar:na] at com.zaxxer.hikari.pool.HikariProxyStatement.execute(HikariProxyStatement.java) ~[HikariCP-3.2.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor$8.execute(StatementExecutor.java:205) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor$12.executeSQL(StatementExecutor.java:267) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor$12.executeSQL(StatementExecutor.java:263) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.core.executor.sql.execute.SQLExecuteCallback.execute0(SQLExecuteCallback.java:72) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.sql.execute.SQLExecuteCallback.execute(SQLExecuteCallback.java:61) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.ShardingExecuteEngine.syncGroupExecute(ShardingExecuteEngine.java:175) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.ShardingExecuteEngine.groupExecute(ShardingExecuteEngine.java:152) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.sql.execute.SQLExecuteTemplate.executeGroup(SQLExecuteTemplate.java:71) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.sql.execute.SQLExecuteTemplate.executeGroup(SQLExecuteTemplate.java:54) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.AbstractStatementExecutor.executeCallback(AbstractStatementExecutor.java:114) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor.execute(StatementExecutor.java:270) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor.execute(StatementExecutor.java:201) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.jdbc.core.statement.ShardingStatement.execute(ShardingStatement.java:161) ~[sharding-jdbc-core-3.1.0.jar:na] at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:54) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final] ... 34 common frames omitted

Hibernate: create index status on activity_activity (status) 2019-02-25 21:17:05.874 WARN 42973 --- [ main] o.h.t.s.i.ExceptionHandlerLoggedImpl : GenerationTarget encountered exception accepting command : Error executing DDL "create index status on activity_activity (status)" via JDBC Statement

org.hibernate.tool.schema.spi.CommandAcceptanceException: Error executing DDL "create index status on activity_activity (status)" via JDBC Statement at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:67) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applySqlString(AbstractSchemaMigrator.java:559) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applySqlStrings(AbstractSchemaMigrator.java:504) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.applyIndexes(AbstractSchemaMigrator.java:331) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.GroupedSchemaMigratorImpl.performTablesMigration(GroupedSchemaMigratorImpl.java:84) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.performMigration(AbstractSchemaMigrator.java:207) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.internal.AbstractSchemaMigrator.doMigration(AbstractSchemaMigrator.java:114) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.performDatabaseAction(SchemaManagementToolCoordinator.java:183) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.tool.schema.spi.SchemaManagementToolCoordinator.process(SchemaManagementToolCoordinator.java:72) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.internal.SessionFactoryImpl.(SessionFactoryImpl.java:310) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.boot.internal.SessionFactoryBuilderImpl.build(SessionFactoryBuilderImpl.java:467) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.build(EntityManagerFactoryBuilderImpl.java:939) [hibernate-core-5.3.7.Final.jar:5.3.7.Final] at org.springframework.orm.jpa.vendor.SpringHibernateJpaPersistenceProvider.createContainerEntityManagerFactory(SpringHibernateJpaPersistenceProvider.java:57) [spring-orm-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:365) [spring-orm-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.buildNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:390) [spring-orm-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.afterPropertiesSet(AbstractEntityManagerFactoryBean.java:377) [spring-orm-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.afterPropertiesSet(LocalContainerEntityManagerFactoryBean.java:341) [spring-orm-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1804) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1741) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:576) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:498) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:320) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:222) ~[spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:318) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:199) [spring-beans-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1083) ~[spring-context-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:853) ~[spring-context-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:546) ~[spring-context-5.1.4.RELEASE.jar:5.1.4.RELEASE] at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:142) ~[spring-boot-2.1.2.RELEASE.jar:2.1.2.RELEASE] at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:775) ~[spring-boot-2.1.2.RELEASE.jar:2.1.2.RELEASE] at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:397) ~[spring-boot-2.1.2.RELEASE.jar:2.1.2.RELEASE] at org.springframework.boot.SpringApplication.run(SpringApplication.java:316) ~[spring-boot-2.1.2.RELEASE.jar:2.1.2.RELEASE] at org.springframework.boot.SpringApplication.run(SpringApplication.java:1260) ~[spring-boot-2.1.2.RELEASE.jar:2.1.2.RELEASE] at org.springframework.boot.SpringApplication.run(SpringApplication.java:1248) ~[spring-boot-2.1.2.RELEASE.jar:2.1.2.RELEASE] at com.dalaocu.sharding.demo.ShardingDemoApplication.main(ShardingDemoApplication.java:13) ~[main/:na] Caused by: java.sql.SQLSyntaxErrorException: Duplicate key name 'status_activity_activity' at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:120) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.mysql.cj.jdbc.StatementImpl.executeInternal(StatementImpl.java:782) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.mysql.cj.jdbc.StatementImpl.execute(StatementImpl.java:666) ~[mysql-connector-java-8.0.13.jar:8.0.13] at com.zaxxer.hikari.pool.ProxyStatement.execute(ProxyStatement.java:95) ~[HikariCP-3.2.0.jar:na] at com.zaxxer.hikari.pool.HikariProxyStatement.execute(HikariProxyStatement.java) ~[HikariCP-3.2.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor$8.execute(StatementExecutor.java:205) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor$12.executeSQL(StatementExecutor.java:267) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor$12.executeSQL(StatementExecutor.java:263) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.core.executor.sql.execute.SQLExecuteCallback.execute0(SQLExecuteCallback.java:72) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.sql.execute.SQLExecuteCallback.execute(SQLExecuteCallback.java:61) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.ShardingExecuteEngine.syncGroupExecute(ShardingExecuteEngine.java:175) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.ShardingExecuteEngine.groupExecute(ShardingExecuteEngine.java:152) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.sql.execute.SQLExecuteTemplate.executeGroup(SQLExecuteTemplate.java:71) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.core.executor.sql.execute.SQLExecuteTemplate.executeGroup(SQLExecuteTemplate.java:54) ~[sharding-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.AbstractStatementExecutor.executeCallback(AbstractStatementExecutor.java:114) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor.execute(StatementExecutor.java:270) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.executor.StatementExecutor.execute(StatementExecutor.java:201) ~[sharding-jdbc-core-3.1.0.jar:na] at io.shardingsphere.shardingjdbc.jdbc.core.statement.ShardingStatement.execute(ShardingStatement.java:161) ~[sharding-jdbc-core-3.1.0.jar:na] at org.hibernate.tool.schema.internal.exec.GenerationTargetToDatabase.accept(GenerationTargetToDatabase.java:54) ~[hibernate-core-5.3.7.Final.jar:5.3.7.Final] ... 34 common frames omitted

If you switch to branch "using-jdbc-log", the error disappeared.

2019-02-25 21:30:37.650 INFO 43945 --- [ main] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [ name: default ...] 2019-02-25 21:30:37.751 INFO 43945 --- [ main] org.hibernate.Version : HHH000412: Hibernate Core {5.3.7.Final} 2019-02-25 21:30:37.753 INFO 43945 --- [ main] org.hibernate.cfg.Environment : HHH000206: hibernate.properties not found 2019-02-25 21:30:37.962 INFO 43945 --- [ main] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.0.4.Final} 2019-02-25 21:30:38.125 INFO 43945 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting... 2019-02-25 21:30:38.536 INFO 43945 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed. 2019-02-25 21:30:38.551 INFO 43945 --- [ main] org.hibernate.dialect.Dialect : HHH000400: Using dialect: com.dalaocu.sharding.demo.config.MysqlConfig 2019-02-25 21:30:39.357 INFO 43945 --- [ main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default' 2019-02-25 21:30:40.289 INFO 43945 --- [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor' 2019-02-25 21:30:40.376 WARN 43945 --- [ main] aWebConfiguration$JpaWebMvcConfiguration : spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning 2019-02-25 21:30:40.714 INFO 43945 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8082 (http) with context path '' 2019-02-25 21:30:40.718 INFO 43945 --- [ main] c.d.s.demo.ShardingDemoApplication : Started ShardingDemoApplication in 6.864 seconds (JVM running for 7.306)

codefairy08 commented 5 years ago

@dalaocu it works well use your 'using-sharding-jdbc-log' branch, my code url is https://github.com/codefairy08/sharding-demo, mysql version is 8.0, i do not use zk. the log is 019-02-27 15:40:18.733 INFO 9220 --- [ main] c.d.s.demo.ShardingDemoApplication : Starting ShardingDemoApplication on DESKTOP-UJ1QVF3 with PID 9220 (E:\gitrepo\1711_demo\using-sharding-jdbc-log\sharding-demo\bin\main started by dhj in E:\gitrepo\1711_demo\using-sharding-jdbc-log\sharding-demo) 2019-02-27 15:40:18.735 INFO 9220 --- [ main] c.d.s.demo.ShardingDemoApplication : The following profiles are active: sharding-tables 2019-02-27 15:40:19.268 INFO 9220 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data repositories in DEFAULT mode. 2019-02-27 15:40:19.320 INFO 9220 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 45ms. Found 1 repository interfaces. 2019-02-27 15:40:19.562 INFO 9220 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration' of type [org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration$$EnhancerBySpringCGLIB$$ca11adb3] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2019-02-27 15:40:19.927 INFO 9220 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8082 (http) 2019-02-27 15:40:20.031 INFO 9220 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat] 2019-02-27 15:40:20.032 INFO 9220 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.14] 2019-02-27 15:40:20.041 INFO 9220 --- [ main] o.a.catalina.core.AprLifecycleListener : The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: 2019-02-27 15:40:20.124 INFO 9220 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext 2019-02-27 15:40:20.124 INFO 9220 --- [ main] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 1213 ms 2019-02-27 15:40:20.207 INFO 9220 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting... 2019-02-27 15:40:20.304 INFO 9220 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed. 2019-02-27 15:40:20.434 INFO 9220 --- [ main] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [ name: default ...] 2019-02-27 15:40:20.481 INFO 9220 --- [ main] org.hibernate.Version : HHH000412: Hibernate Core {5.3.7.Final} 2019-02-27 15:40:20.481 INFO 9220 --- [ main] org.hibernate.cfg.Environment : HHH000206: hibernate.properties not found 2019-02-27 15:40:20.591 INFO 9220 --- [ main] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.0.4.Final} 2019-02-27 15:40:20.707 INFO 9220 --- [ main] org.hibernate.dialect.Dialect : HHH000400: Using dialect: com.dalaocu.sharding.demo.config.MysqlConfig Hibernate: create table activity_activity (pk_id bigint not null auto_increment, block_height bigint, depot_updatetime datetime(6), status integer, primary key (pk_id)) ENGINE=InnoDB DEFAULT CHARSET=utf8 Hibernate: create index block_height on activity_activity (block_height) Hibernate: create index status on activity_activity (status) 2019-02-27 15:40:21.488 INFO 9220 --- [ main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default' 2019-02-27 15:40:21.920 INFO 9220 --- [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor' 2019-02-27 15:40:21.954 WARN 9220 --- [ main] aWebConfiguration$JpaWebMvcConfiguration : spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning 2019-02-27 15:40:22.106 INFO 9220 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8082 (http) with context path '' 2019-02-27 15:40:22.107 INFO 9220 --- [ main] c.d.s.demo.ShardingDemoApplication : Started ShardingDemoApplication in 3.639 seconds (JVM running for 3.949)

dalaocu commented 5 years ago

https://github.com/codefairy08/sharding-demo

@codefairy08 I hava tried your code with or without zk, and the warn logs repead. So does the specific db version work? My db version is Server version: 5.7.24 MySQL Community Server (GPL).

dalaocu commented 5 years ago

https://github.com/codefairy08/sharding-demo

@codefairy08 I hava tried your code with or without zk, and the warn logs repead. So does the specific db version work? My db version is Server version: 5.7.24 MySQL Community Server (GPL).

I have tried mysql8.0, but the problem still existed. This warn log appears only when you start the springboot app twice or more!

If you start the app the first time, it will not conflict to the older table indexes.

codefairy08 commented 5 years ago

@dalaocu i have tried more than 3 times, no warning log was found。 logs as follow： . _ _ /\ / '_ () \ \ \ \ ( ( )\ | ' | '| | ' \/ ` | \ \ \ \ \/ _)| |)| | | | | || (| | ) ) ) ) ' |__| .|| ||| |\, | / / / / =========|_|==============|__/=//// :: Spring Boot :: (v2.1.2.RELEASE)

2019-03-04 09:25:42.238 INFO 2160 --- [ main] c.d.s.demo.ShardingDemoApplication : Starting ShardingDemoApplication on DESKTOP-UJ1QVF3 with PID 2160 (E:\gitrepo\1711_demo\sharding-demo\bin\main started by dhj in E:\gitrepo\1711_demo\sharding-demo) 2019-03-04 09:25:42.240 INFO 2160 --- [ main] c.d.s.demo.ShardingDemoApplication : No active profile set, falling back to default profiles: default 2019-03-04 09:25:42.672 INFO 2160 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data repositories in DEFAULT mode. 2019-03-04 09:25:42.723 INFO 2160 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 46ms. Found 1 repository interfaces. 2019-03-04 09:25:42.971 INFO 2160 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration' of type [org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration$$EnhancerBySpringCGLIB$$ac6dc77d] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2019-03-04 09:25:43.321 INFO 2160 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8082 (http) 2019-03-04 09:25:43.341 INFO 2160 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat] 2019-03-04 09:25:43.341 INFO 2160 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.14] 2019-03-04 09:25:43.349 INFO 2160 --- [ main] o.a.catalina.core.AprLifecycleListener : The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [] 2019-03-04 09:25:43.422 INFO 2160 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext 2019-03-04 09:25:43.422 INFO 2160 --- [ main] o.s.web.context.ContextLoader : Root WebApplicationContext: initialization completed in 1153 ms 2019-03-04 09:25:43.621 INFO 2160 --- [ main] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [ name: default ...] 2019-03-04 09:25:43.668 INFO 2160 --- [ main] org.hibernate.Version : HHH000412: Hibernate Core {5.3.7.Final} 2019-03-04 09:25:43.669 INFO 2160 --- [ main] org.hibernate.cfg.Environment : HHH000206: hibernate.properties not found 2019-03-04 09:25:43.774 INFO 2160 --- [ main] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.0.4.Final} 2019-03-04 09:25:43.871 INFO 2160 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting... 2019-03-04 09:25:43.971 INFO 2160 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed. 2019-03-04 09:25:43.982 INFO 2160 --- [ main] org.hibernate.dialect.Dialect : HHH000400: Using dialect: com.dalaocu.sharding.demo.config.MysqlConfig 2019-03-04 09:25:44.429 INFO 2160 --- [ main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default' 2019-03-04 09:25:44.779 INFO 2160 --- [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor' 2019-03-04 09:25:44.816 WARN 2160 --- [ main] aWebConfiguration$JpaWebMvcConfiguration : spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning 2019-03-04 09:25:44.980 INFO 2160 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8082 (http) with context path '' 2019-03-04 09:25:44.981 INFO 2160 --- [ main] c.d.s.demo.ShardingDemoApplication : Started ShardingDemoApplication in 2.987 seconds (JVM running for 3.272)

dalaocu commented 5 years ago

Do you modify any code? I found you run it in windows. Mine is centos and mac. Is it related to the OS?

dalaocu commented 5 years ago

If you can't repeat the warn log, I have to set the log level manually... logging.level.org.hibernate=ERROR But I think it's not elegant.

codefairy08 commented 5 years ago

@dalaocu sharding-jdbc is not dependent with OS， i still cloud not reproduce after adding log

terrymanu commented 5 years ago

If no response more than 7 days and we cannot reproduce it on current information, we will close it.