Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

App fails to start when using Spring Batch with JDBC and lazy initialization is enabled #27193

Closed
wilkinsona opened this issue Jul 8, 2021 · 2 comments
Assignees
Labels
type: bug A general bug
Milestone

Comments

@wilkinsona
Copy link
Member

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                        

2021-07-08 18:27:56.391  INFO 73510 --- [           main] smoketest.batch.SampleBatchApplication   : Starting SampleBatchApplication using Java 1.8.0_252 on wilkinsona-a01.vmware.com with PID 73510 (/Users/awilkinson/dev/spring-projects/spring-boot/2.4.x/spring-boot-tests/spring-boot-smoke-tests/spring-boot-smoke-test-batch/bin/main started by awilkinson in /Users/awilkinson/dev/spring-projects/spring-boot/2.4.x/spring-boot-tests/spring-boot-smoke-tests/spring-boot-smoke-test-batch)
2021-07-08 18:27:56.393  INFO 73510 --- [           main] smoketest.batch.SampleBatchApplication   : No active profile set, falling back to default profiles: default
2021-07-08 18:27:57.124  INFO 73510 --- [           main] smoketest.batch.SampleBatchApplication   : Started SampleBatchApplication in 1.145 seconds (JVM running for 1.521)
2021-07-08 18:27:57.247  INFO 73510 --- [           main] o.s.b.a.b.JobLauncherApplicationRunner   : Running default command line with: []
2021-07-08 18:27:57.302  INFO 73510 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2021-07-08 18:27:57.560  INFO 73510 --- [           main] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Driver does not support get/set network timeout for connections. (feature not supported)
2021-07-08 18:27:57.563  INFO 73510 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2021-07-08 18:27:57.571  INFO 73510 --- [           main] o.s.b.c.r.s.JobRepositoryFactoryBean     : No database type set, using meta data indicating: HSQL
2021-07-08 18:27:57.686  INFO 73510 --- [           main] o.s.b.c.l.support.SimpleJobLauncher      : No TaskExecutor has been set, defaulting to synchronous executor.
2021-07-08 18:27:57.779  INFO 73510 --- [           main] ConditionEvaluationReportLoggingListener : 

Error starting ApplicationContext. To display the conditions report re-run your application with 'debug' enabled.
2021-07-08 18:27:57.809 ERROR 73510 --- [           main] o.s.boot.SpringApplication               : Application run failed

java.lang.IllegalStateException: Failed to execute ApplicationRunner
	at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:802) [main/:na]
	at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:789) [main/:na]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:346) [main/:na]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1329) [main/:na]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1318) [main/:na]
	at smoketest.batch.SampleBatchApplication.main(SampleBatchApplication.java:69) [main/:na]
Caused by: org.springframework.jdbc.BadSqlGrammarException: PreparedStatementCallback; bad SQL grammar [SELECT JOB_INSTANCE_ID, JOB_NAME from BATCH_JOB_INSTANCE where JOB_NAME = ? and JOB_KEY = ?]; nested exception is java.sql.SQLSyntaxErrorException: user lacks privilege or object not found: BATCH_JOB_INSTANCE in statement [SELECT JOB_INSTANCE_ID, JOB_NAME from BATCH_JOB_INSTANCE where JOB_NAME = ? and JOB_KEY = ?]
	at org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:93) ~[spring-jdbc-5.3.8.jar:5.3.8]
	at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:70) ~[spring-jdbc-5.3.8.jar:5.3.8]
	at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:79) ~[spring-jdbc-5.3.8.jar:5.3.8]
	at org.springframework.jdbc.core.JdbcTemplate.translateException(JdbcTemplate.java:1541) ~[spring-jdbc-5.3.8.jar:5.3.8]
	at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:667) ~[spring-jdbc-5.3.8.jar:5.3.8]
	at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:713) ~[spring-jdbc-5.3.8.jar:5.3.8]
	at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:744) ~[spring-jdbc-5.3.8.jar:5.3.8]
	at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:757) ~[spring-jdbc-5.3.8.jar:5.3.8]
	at org.springframework.jdbc.core.JdbcTemplate.query(JdbcTemplate.java:815) ~[spring-jdbc-5.3.8.jar:5.3.8]
	at org.springframework.batch.core.repository.dao.JdbcJobInstanceDao.getJobInstance(JdbcJobInstanceDao.java:151) ~[spring-batch-core-4.3.3.jar:4.3.3]
	at org.springframework.batch.core.repository.support.SimpleJobRepository.isJobInstanceExists(SimpleJobRepository.java:93) ~[spring-batch-core-4.3.3.jar:4.3.3]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_252]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_252]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_252]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_252]
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.3.8.jar:5.3.8]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.3.8.jar:5.3.8]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.8.jar:5.3.8]
	at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123) ~[spring-tx-5.3.8.jar:5.3.8]
	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388) ~[spring-tx-5.3.8.jar:5.3.8]
	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.8.jar:5.3.8]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.8.jar:5.3.8]
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215) ~[spring-aop-5.3.8.jar:5.3.8]
	at com.sun.proxy.$Proxy43.isJobInstanceExists(Unknown Source) ~[na:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_252]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_252]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_252]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_252]
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.3.8.jar:5.3.8]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.3.8.jar:5.3.8]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.8.jar:5.3.8]
	at org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$PassthruAdvice.invoke(SimpleBatchConfiguration.java:128) ~[spring-batch-core-4.3.3.jar:4.3.3]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.8.jar:5.3.8]
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:215) ~[spring-aop-5.3.8.jar:5.3.8]
	at com.sun.proxy.$Proxy43.isJobInstanceExists(Unknown Source) ~[na:na]
	at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.getNextJobParameters(JobLauncherApplicationRunner.java:206) ~[main/:na]
	at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.execute(JobLauncherApplicationRunner.java:198) ~[main/:na]
	at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.executeLocalJobs(JobLauncherApplicationRunner.java:173) ~[main/:na]
	at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.launchJobFromProperties(JobLauncherApplicationRunner.java:160) ~[main/:na]
	at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.run(JobLauncherApplicationRunner.java:155) ~[main/:na]
	at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.run(JobLauncherApplicationRunner.java:150) ~[main/:na]
	at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:799) [main/:na]
	... 5 common frames omitted
Caused by: java.sql.SQLSyntaxErrorException: user lacks privilege or object not found: BATCH_JOB_INSTANCE in statement [SELECT JOB_INSTANCE_ID, JOB_NAME from BATCH_JOB_INSTANCE where JOB_NAME = ? and JOB_KEY = ?]
	at org.hsqldb.jdbc.JDBCUtil.sqlException(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.jdbc.JDBCUtil.sqlException(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.jdbc.JDBCPreparedStatement.<init>(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.jdbc.JDBCConnection.prepareStatement(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at com.zaxxer.hikari.pool.ProxyConnection.prepareStatement(ProxyConnection.java:337) ~[HikariCP-3.4.5.jar:na]
	at com.zaxxer.hikari.pool.HikariProxyConnection.prepareStatement(HikariProxyConnection.java) ~[HikariCP-3.4.5.jar:na]
	at org.springframework.jdbc.core.JdbcTemplate$SimplePreparedStatementCreator.createPreparedStatement(JdbcTemplate.java:1645) ~[spring-jdbc-5.3.8.jar:5.3.8]
	at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:649) ~[spring-jdbc-5.3.8.jar:5.3.8]
	... 42 common frames omitted
Caused by: org.hsqldb.HsqlException: user lacks privilege or object not found: BATCH_JOB_INSTANCE
	at org.hsqldb.error.Error.error(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.error.Error.error(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserDQL.readTableName(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserDQL.readTableOrSubquery(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserDQL.XreadTableReference(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserDQL.XreadFromClause(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserDQL.XreadTableExpression(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserDQL.XreadQuerySpecification(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserDQL.XreadSimpleTable(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserDQL.XreadQueryPrimary(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserDQL.XreadQueryTerm(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserDQL.XreadQueryExpressionBody(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserDQL.XreadQueryExpression(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserDQL.compileCursorSpecification(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserCommand.compilePart(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.ParserCommand.compileStatement(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.Session.compileStatement(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.StatementManager.compile(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	at org.hsqldb.Session.execute(Unknown Source) ~[hsqldb-2.5.2.jar:2.5.2]
	... 48 common frames omitted

2021-07-08 18:27:57.811  INFO 73510 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2021-07-08 18:27:57.813  INFO 73510 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.

As long as the Batch database tables are not accessed until refresh has completed, a workaround is to exclude the initializer from lazy initialization:

@Bean
static LazyInitializationExcludeFilter eagerBatchDataSourceInitialization() {
	return LazyInitializationExcludeFilter.forBeanTypes(BatchDataSourceInitializer.class);
}

To allow Batch's database tables to be accessed during refresh, even when lazy initialization is enabled, we need to ensure that the job repository bean depends on the batch data source initializer bean.

@wilkinsona
Copy link
Member Author

The fix for this in 2.5 is quite different due to the reworking of database initialization. It's being tracked by #27207.

@wilkinsona
Copy link
Member Author

Re-opening as we need to do the same for Flyway- or Liquibase-based initialization.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type: bug A general bug
Projects
None yet
Development

No branches or pull requests

1 participant