Мы обновили наше приложение на основе Spring Batch до последней версии Spring Batch 4.x и Boot 2.0.x и столкнулись с некоторыми проблемами с пулом соединений HikariCP MySQL.
Если я использую по умолчанию maxPoolSize из 10 соединений, и я использую 5 потоков, каждый из которых запускает простую фиктивную работу, это работает нормально.(Используя SimpleJobLauncher).Все задания запускаются немедленно, и после этого в пул HikariCP возвращаются все использованные соединения.
Проблема начинается, когда я делаю то же самое, но затем с 11 потоками.Затем я вижу, что приложение зависает до истечения времени ожидания соединения, а затем запускаются задания.Я ожидал, что первые 10 заданий начнутся, и после того, как первое завершит одиннадцатое задание ...
Перед началом заданий я вижу это:
HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
Теперь я запускаю 11 заданий иприложение будет зависать в течение 30 секунд ...
2019-01-21 11:25:01.256 INFO 10194 --- [ver (CliServer)] c.n.r.i.batch.cli.CliClientHandler : Start 11 jobs
2019-01-21 11:25:30.928 DEBUG 10194 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Pool stats (total=10, active=10, idle=0, waiting=2)
2019-01-21 11:25:35.990 DEBUG 10194 --- [ Thread-10] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Timeout failure stats (total=10, active=10, idle=0, waiting=1)
2019-01-21 11:25:35.992 DEBUG 10194 --- [ Thread-6] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Timeout failure stats (total=10, active=10, idle=0, waiting=1)
org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.
at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:305)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:378)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:474)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:289)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:98)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at org.springframework.batch.core.repository.support.AbstractJobRepositoryFactoryBean$1.invoke(AbstractJobRepositoryFactoryBean.java:181)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
at com.sun.proxy.$Proxy74.createJobExecution(Unknown Source)
at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:131)
at com.xx.yy.zz.batch.cli.commands.DummyCliCommand$1.run(DummyCliCommand.java:54)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.
at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:697)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:196)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:161)
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128)
at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:262)
... 12 more
И после этого времени запускаются первые задания ...
2019-01-21 11:25:36.061 INFO 10194 --- [ Thread-11] c.n.r.i.b.u.c.BlockingThreadPoolExecutor : [sftp-executor] 3 running jobs, 0 queued jobs, 2000 jobs allowed
2019-01-21 11:25:36.062 INFO 10194 --- [ Thread-5] c.n.r.i.b.u.c.BlockingThreadPoolExecutor : [sftp-executor] 3 running jobs, 0 queued jobs, 2000 jobs allowed
2019-01-21 11:25:36.061 INFO 10194 --- [ Thread-3] c.n.r.i.b.u.c.BlockingThreadPoolExecutor : [sftp-executor] 3 running jobs, 0 queued jobs, 2000 jobs allowed
2019-01-21 11:25:36.063 INFO 10194 --- [pool-1-thread-2] o.s.b.c.l.support.SimpleJobLauncher : Job: [SimpleJob: [name=dummyJob]] launched with the following parameters: [{dummy=f5c864d9-8a74-4d51-9a53-e3fc5c0b731d}]
Версия: - HikariCP 2.7.9 - spring-batch-core 4.0.1 - Hibernate Core 5.2.17.Final - spring-boot 2.0.5
Не понимаю, почему пул зависает?(Пустышки спят только секунду)
HikariCP config
allowPoolSuspension.............false
autoCommit......................true
catalog.........................none
connectionInitSql...............none
connectionTestQuery.............none
connectionTimeout...............30000
dataSource......................none
dataSourceClassName.............none
dataSourceJNDI..................none
dataSourceProperties............{usePipelineAuth=false, password=<masked>, prepStmtCacheSqlLimit=2048, rewriteBatchedStatements=false, useSSL=false, cachePrepStmts=true, useServerPrepStmts=true, prepStmtCacheSize=250}
driverClassName................."com.mysql.jdbc.Driver"
healthCheckProperties...........{}
healthCheckRegistry.............none
idleTimeout.....................600000
initializationFailTimeout.......1
isolateInternalQueries..........false
jdbcUrl.........................jdbc:mysql://localhost:3306/development
leakDetectionThreshold..........60000
maxLifetime.....................1800000
maximumPoolSize.................10
metricRegistry..................none
metricsTrackerFactory...........none
minimumIdle.....................10
password........................<masked>
poolName........................"HikariPool-1"
readOnly........................false
registerMbeans..................true
scheduledExecutor...............none
schema..........................none
threadFactory...................internal
transactionIsolation............default
username........................"user"
validationTimeout...............5000