I'm upgrading from 2.4.5 to 2.5.1 but found the SQL init failed, without changing anything else other than the Spring Boot version.
The database is set to ddl-auto: create-drop as this is local testing
The SQL init only contains 1 line of INSERT
Seems to me that on 2.4.x, the table is created first then the SQL init triggered.
While on 2.5.x, the SQL init is triggered first, leading to table not found. I think it's a bug, but idk if it's a feature.
Tested: - 2.4.5 OK - 2.4.6 OK - 2.4.7 OK - 2.5.0 Fail - 2.5.1 Fail
application.yml
spring:
config:
activate:
on-profile: local
datasource:
url: jdbc:h2:mem:payment;MODE=MYSQL
driverClassName: org.h2.Driver
username: p2pl
password: 123456
initialization-mode: always
data:
- classpath:data_va_code.sql
jpa:
hibernate.ddlAuto: create-drop
databasePlatform: org.hibernate.dialect.H2Dialect
showSql: true
h2.console:
enabled: true
SQL initialization script data_va_code.sql
INSERT INTO va_code(id, start_number, end_number) VALUES ('1', '0', '99999999');
Successful start on 2.4.7, some parts are shortened with ( ... )
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.4.7)
2021-06-22 14:31:21.357 INFO 64483 --- [ restartedMain] c.l.id.p2pl.wallet.WalletApplicationKt : Starting WalletApplicationKt using Java 11.0.11 on ID-M.local with PID 64483 ( ... )
2021-06-22 14:31:21.359 INFO 64483 --- [ restartedMain] c.l.id.p2pl.wallet.WalletApplicationKt : The following profiles are active: local
2021-06-22 14:31:21.397 INFO 64483 --- [ restartedMain] o.s.b.devtools.restart.ChangeableUrls : The Class-Path manifest attribute in ( ... )
2021-06-22 14:31:21.398 INFO 64483 --- [ restartedMain] o.s.b.devtools.restart.ChangeableUrls : The Class-Path manifest attribute in ( ... )
2021-06-22 14:31:21.398 INFO 64483 --- [ restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : Devtools property defaults active! Set 'spring.devtools.add-properties' to 'false' to disable
2021-06-22 14:31:21.398 INFO 64483 --- [ restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : For additional web related logging consider setting the 'logging.level.web' property to 'DEBUG'
2021-06-22 14:31:22.338 INFO 64483 --- [ restartedMain] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!
2021-06-22 14:31:22.339 INFO 64483 --- [ restartedMain] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2021-06-22 14:31:22.422 INFO 64483 --- [ restartedMain] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 73 ms. Found 4 JPA repository interfaces.
2021-06-22 14:31:22.954 INFO 64483 --- [ restartedMain] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [name: default]
2021-06-22 14:31:23.029 INFO 64483 --- [ restartedMain] org.hibernate.Version : HHH000412: Hibernate ORM core version 5.4.32.Final
2021-06-22 14:31:23.200 INFO 64483 --- [ restartedMain] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2021-06-22 14:31:23.308 INFO 64483 --- [ restartedMain] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
2021-06-22 14:31:23.429 INFO 64483 --- [ restartedMain] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.
2021-06-22 14:31:23.446 INFO 64483 --- [ restartedMain] org.hibernate.dialect.Dialect : HHH000400: Using dialect: org.hibernate.dialect.H2Dialect
Hibernate: drop table if exists bank CASCADE
Hibernate: drop table if exists user_history CASCADE
Hibernate: drop table if exists va_code CASCADE
Hibernate: drop table if exists wallet CASCADE
Hibernate: create table bank ( ... )
Hibernate: create table user_history ( ... )
Hibernate: create table va_code ( ... )
Hibernate: create table wallet ( ... )
2021-06-22 14:31:23.930 INFO 64483 --- [ restartedMain] o.h.e.t.j.p.i.JtaPlatformInitiator : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2021-06-22 14:31:23.939 INFO 64483 --- [ restartedMain] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2021-06-22 14:31:23.987 INFO 64483 --- [ restartedMain] o.s.b.d.a.OptionalLiveReloadServer : LiveReload server is running on port 35729
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by retrofit2.Platform ( ... )
WARNING: Please consider reporting this to the maintainers of retrofit2.Platform
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
Failed start on 2.5.1, some parts are shortened with ( ... )
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.5.1)
2021-06-22 14:32:57.017 INFO 64574 --- [ restartedMain] c.l.id.p2pl.wallet.WalletApplicationKt : Starting WalletApplicationKt using Java 11.0.11 on ID-M.local with PID 64574 ( ... )
2021-06-22 14:32:57.020 INFO 64574 --- [ restartedMain] c.l.id.p2pl.wallet.WalletApplicationKt : The following profiles are active: local
2021-06-22 14:32:57.067 INFO 64574 --- [ restartedMain] o.s.b.devtools.restart.ChangeableUrls : The Class-Path manifest attribute in ( ... )
2021-06-22 14:32:57.067 INFO 64574 --- [ restartedMain] o.s.b.devtools.restart.ChangeableUrls : The Class-Path manifest attribute in ( ... )
2021-06-22 14:32:57.068 INFO 64574 --- [ restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : Devtools property defaults active! Set 'spring.devtools.add-properties' to 'false' to disable
2021-06-22 14:32:57.068 INFO 64574 --- [ restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : For additional web related logging consider setting the 'logging.level.web' property to 'DEBUG'
2021-06-22 14:32:57.963 INFO 64574 --- [ restartedMain] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!
2021-06-22 14:32:57.963 INFO 64574 --- [ restartedMain] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2021-06-22 14:32:58.052 INFO 64574 --- [ restartedMain] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 80 ms. Found 4 JPA repository interfaces.
2021-06-22 14:32:58.664 INFO 64574 --- [ restartedMain] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting...
2021-06-22 14:32:58.833 INFO 64574 --- [ restartedMain] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed.
2021-06-22 14:32:58.851 WARN 64574 --- [ restartedMain] onfigReactiveWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'scriptDataSourceInitializer' defined in class path resource [org/springframework/boot/autoconfigure/jdbc/DataSourceInitializationConfiguration$SharedCredentialsDataSourceInitializationConfiguration.class]: Invocation of init method failed; nested exception is org.springframework.jdbc.datasource.init.ScriptStatementFailedException: Failed to execute SQL script statement #1 of class path resource [data_va_code.sql]: INSERT INTO va_code(id, start_number, end_number) VALUES ('1', '0', '99999999'); nested exception is org.h2.jdbc.JdbcSQLSyntaxErrorException: Table "VA_CODE" not found; SQL statement:
INSERT INTO va_code(id, start_number, end_number) VALUES ('1', '0', '99999999') [42102-200]
2021-06-22 14:32:59.058 WARN 64574 --- [ restartedMain] o.s.b.f.support.DisposableBeanAdapter : Invocation of destroy method failed on bean with name 'inMemoryDatabaseShutdownExecutor': org.h2.jdbc.JdbcSQLNonTransientConnectionException: Database is already closed (to disable automatic closing at VM shutdown, add ";DB_CLOSE_ON_EXIT=FALSE" to the db URL) [90121-200]
2021-06-22 14:32:59.059 INFO 64574 --- [ restartedMain] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown initiated...
2021-06-22 14:32:59.191 INFO 64574 --- [ restartedMain] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown completed.
2021-06-22 14:32:59.224 INFO 64574 --- [ restartedMain] ConditionEvaluationReportLoggingListener :
Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
2021-06-22 14:32:59.258 ERROR 64574 --- [ restartedMain] o.s.boot.SpringApplication : Application run failed
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'scriptDataSourceInitializer' defined in class path resource [org/springframework/boot/autoconfigure/jdbc/DataSourceInitializationConfiguration$SharedCredentialsDataSourceInitializationConfiguration.class]: Invocation of init method failed; nested exception is org.springframework.jdbc.datasource.init.ScriptStatementFailedException: Failed to execute SQL script statement #1 of class path resource [data_va_code.sql]: INSERT INTO va_code(id, start_number, end_number) VALUES ('1', '0', '99999999'); nested exception is org.h2.jdbc.JdbcSQLSyntaxErrorException: Table "VA_CODE" not found; SQL statement:
INSERT INTO va_code(id, start_number, end_number) VALUES ('1', '0', '99999999') [42102-200]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1786) ~[spring-beans-5.3.8.jar:5.3.8]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:602) ~[spring-beans-5.3.8.jar:5.3.8]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:524) ~[spring-beans-5.3.8.jar:5.3.8]
at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335) ~[spring-beans-5.3.8.jar:5.3.8]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234) ~[spring-beans-5.3.8.jar:5.3.8]
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333) ~[spring-beans-5.3.8.jar:5.3.8]
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208) ~[spring-beans-5.3.8.jar:5.3.8]
at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:322) ~[spring-beans-5.3.8.jar:5.3.8]
at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208) ~[spring-beans-5.3.8.jar:5.3.8]
at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1154) ~[spring-context-5.3.8.jar:5.3.8]
at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:908) ~[spring-context-5.3.8.jar:5.3.8]
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:583) ~[spring-context-5.3.8.jar:5.3.8]
at org.springframework.boot.web.reactive.context.ReactiveWebServerApplicationContext.refresh(ReactiveWebServerApplicationContext.java:64) ~[spring-boot-2.5.1.jar:2.5.1]
at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:754) ~[spring-boot-2.5.1.jar:2.5.1]
at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:434) ~[spring-boot-2.5.1.jar:2.5.1]
at org.springframework.boot.SpringApplication.run(SpringApplication.java:338) ~[spring-boot-2.5.1.jar:2.5.1]
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1343) ~[spring-boot-2.5.1.jar:2.5.1]
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1332) ~[spring-boot-2.5.1.jar:2.5.1]
at ( ... ).WalletApplicationKt.main(WalletApplication.kt:18) ~[main/:na]
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na]
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
at java.base/java.lang.reflect.Method.invoke(Method.java:566) ~[na:na]
at org.springframework.boot.devtools.restart.RestartLauncher.run(RestartLauncher.java:49) ~[spring-boot-devtools-2.5.1.jar:2.5.1]
Caused by: org.springframework.jdbc.datasource.init.ScriptStatementFailedException: Failed to execute SQL script statement #1 of class path resource [data_va_code.sql]: INSERT INTO va_code(id, start_number, end_number) VALUES ('1', '0', '99999999'); nested exception is org.h2.jdbc.JdbcSQLSyntaxErrorException: Table "VA_CODE" not found; SQL statement:
INSERT INTO va_code(id, start_number, end_number) VALUES ('1', '0', '99999999') [42102-200]
at org.springframework.jdbc.datasource.init.ScriptUtils.executeSqlScript(ScriptUtils.java:282) ~[spring-jdbc-5.3.8.jar:5.3.8]
at org.springframework.jdbc.datasource.init.ResourceDatabasePopulator.populate(ResourceDatabasePopulator.java:254) ~[spring-jdbc-5.3.8.jar:5.3.8]
at org.springframework.jdbc.datasource.init.DatabasePopulatorUtils.execute(DatabasePopulatorUtils.java:49) ~[spring-jdbc-5.3.8.jar:5.3.8]
at org.springframework.boot.jdbc.init.DataSourceScriptDatabaseInitializer.runScripts(DataSourceScriptDatabaseInitializer.java:78) ~[spring-boot-2.5.1.jar:2.5.1]
at org.springframework.boot.sql.init.AbstractScriptDatabaseInitializer.runScripts(AbstractScriptDatabaseInitializer.java:151) ~[spring-boot-2.5.1.jar:2.5.1]
at org.springframework.boot.sql.init.AbstractScriptDatabaseInitializer.applyScripts(AbstractScriptDatabaseInitializer.java:111) ~[spring-boot-2.5.1.jar:2.5.1]
at org.springframework.boot.sql.init.AbstractScriptDatabaseInitializer.applyDataScripts(AbstractScriptDatabaseInitializer.java:105) ~[spring-boot-2.5.1.jar:2.5.1]
at org.springframework.boot.sql.init.AbstractScriptDatabaseInitializer.initializeDatabase(AbstractScriptDatabaseInitializer.java:77) ~[spring-boot-2.5.1.jar:2.5.1]
at org.springframework.boot.sql.init.AbstractScriptDatabaseInitializer.afterPropertiesSet(AbstractScriptDatabaseInitializer.java:65) ~[spring-boot-2.5.1.jar:2.5.1]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1845) ~[spring-beans-5.3.8.jar:5.3.8]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1782) ~[spring-beans-5.3.8.jar:5.3.8]
... 23 common frames omitted
Caused by: org.h2.jdbc.JdbcSQLSyntaxErrorException: Table "VA_CODE" not found; SQL statement:
INSERT INTO va_code(id, start_number, end_number) VALUES ('1', '0', '99999999') [42102-200]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:453) ~[h2-1.4.200.jar:1.4.200]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:429) ~[h2-1.4.200.jar:1.4.200]
at org.h2.message.DbException.get(DbException.java:205) ~[h2-1.4.200.jar:1.4.200]
at org.h2.message.DbException.get(DbException.java:181) ~[h2-1.4.200.jar:1.4.200]
at org.h2.command.Parser.readTableOrView(Parser.java:7628) ~[h2-1.4.200.jar:1.4.200]
at org.h2.command.Parser.readTableOrView(Parser.java:7599) ~[h2-1.4.200.jar:1.4.200]
at org.h2.command.Parser.parseInsert(Parser.java:1747) ~[h2-1.4.200.jar:1.4.200]
at org.h2.command.Parser.parsePrepared(Parser.java:954) ~[h2-1.4.200.jar:1.4.200]
at org.h2.command.Parser.parse(Parser.java:843) ~[h2-1.4.200.jar:1.4.200]
at org.h2.command.Parser.parse(Parser.java:815) ~[h2-1.4.200.jar:1.4.200]
at org.h2.command.Parser.prepareCommand(Parser.java:738) ~[h2-1.4.200.jar:1.4.200]
at org.h2.engine.Session.prepareLocal(Session.java:657) ~[h2-1.4.200.jar:1.4.200]
at org.h2.engine.Session.prepareCommand(Session.java:595) ~[h2-1.4.200.jar:1.4.200]
at org.h2.jdbc.JdbcConnection.prepareCommand(JdbcConnection.java:1235) ~[h2-1.4.200.jar:1.4.200]
at org.h2.jdbc.JdbcStatement.executeInternal(JdbcStatement.java:212) ~[h2-1.4.200.jar:1.4.200]
at org.h2.jdbc.JdbcStatement.execute(JdbcStatement.java:201) ~[h2-1.4.200.jar:1.4.200]
at com.zaxxer.hikari.pool.ProxyStatement.execute(ProxyStatement.java:94) ~[HikariCP-4.0.3.jar:na]
at com.zaxxer.hikari.pool.HikariProxyStatement.execute(HikariProxyStatement.java) ~[HikariCP-4.0.3.jar:na]
at org.springframework.jdbc.datasource.init.ScriptUtils.executeSqlScript(ScriptUtils.java:261) ~[spring-jdbc-5.3.8.jar:5.3.8]
... 33 common frames omitted
Process finished with exit code 0
Comment From: wilkinsona
This is covered in the 2.5 release notes. You now need to set spring.jpa.defer-datasource-initialization to true if you want script-based database initialization to be performed after Hibernate has created the schema.
Comment From: ihchristianto
Thanks for the prompt answer!