I’m trying to execute a spring batch made by one job and n step. The Job starts and execute correctly first steps, when it arrives on the ‘X’ step, it should execute a query on the source database (last 1 minute) and then write the result on the target one.
Unfortunatelly i am getting this stack trace:
HikariPool-2 - Connection com.mysql.cj.jdbc.ConnectionImpl@1cb37ee4 marked as broken because of SQLSTATE(08S01), ErrorCode(0)
com.mysql.cj.jdbc.exceptions.CommunicationsException: The last packet successfully received from the server was 7,877,590 milliseconds ago. The last packet sent successfully to the server was 7,877,590 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:174) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:953) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.jdbc.ClientPreparedStatement.executeQuery(ClientPreparedStatement.java:1003) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52) ~[HikariCP-3.4.5.jar!/:na]
at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java) ~[HikariCP-3.4.5.jar!/:na]
at org.springframework.batch.item.database.JdbcCursorItemReader.openCursor(JdbcCursorItemReader.java:127) ~[spring-batch-infrastructure-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
at org.springframework.batch.item.database.AbstractCursorItemReader.doOpen(AbstractCursorItemReader.java:428) ~[spring-batch-infrastructure-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
at org.springframework.batch.item.support.AbstractItemCountingItemStreamItemReader.open(AbstractItemCountingItemStreamItemReader.java:150) ~[spring-batch-infrastructure-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
at org.springframework.batch.item.support.CompositeItemStream.open(CompositeItemStream.java:103) ~[spring-batch-infrastructure-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
at org.springframework.batch.core.step.tasklet.TaskletStep.open(TaskletStep.java:311) ~[spring-batch-core-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
at org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:205) ~[spring-batch-core-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:148) ~[spring-batch-core-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
at org.springframework.batch.core.job.AbstractJob.handleStep(AbstractJob.java:410) ~[spring-batch-core-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
at org.springframework.batch.core.job.SimpleJob.doExecute(SimpleJob.java:136) ~[spring-batch-core-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:319) ~[spring-batch-core-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:147) ~[spring-batch-core-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:50) ~[spring-core-5.2.10.RELEASE.jar!/:5.2.10.RELEASE]
at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:140) ~[spring-batch-core-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
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.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.2.10.RELEASE.jar!/:5.2.10.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.2.10.RELEASE.jar!/:5.2.10.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.2.10.RELEASE.jar!/:5.2.10.RELEASE]
at org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$PassthruAdvice.invoke(SimpleBatchConfiguration.java:127) ~[spring-batch-core-4.2.4.RELEASE.jar!/:4.2.4.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.10.RELEASE.jar!/:5.2.10.RELEASE]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.2.10.RELEASE.jar!/:5.2.10.RELEASE]
at com.sun.proxy.$Proxy38.run(Unknown Source) ~[na:na]
at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.execute(JobLauncherApplicationRunner.java:199) ~[spring-boot-autoconfigure-2.3.5.RELEASE.jar!/:2.3.5.RELEASE]
at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.executeLocalJobs(JobLauncherApplicationRunner.java:173) ~[spring-boot-autoconfigure-2.3.5.RELEASE.jar!/:2.3.5.RELEASE]
at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.launchJobFromProperties(JobLauncherApplicationRunner.java:160) ~[spring-boot-autoconfigure-2.3.5.RELEASE.jar!/:2.3.5.RELEASE]
at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.run(JobLauncherApplicationRunner.java:155) ~[spring-boot-autoconfigure-2.3.5.RELEASE.jar!/:2.3.5.RELEASE]
at org.springframework.boot.autoconfigure.batch.JobLauncherApplicationRunner.run(JobLauncherApplicationRunner.java:150) ~[spring-boot-autoconfigure-2.3.5.RELEASE.jar!/:2.3.5.RELEASE]
at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:786) ~[spring-boot-2.3.5.RELEASE.jar!/:2.3.5.RELEASE]
at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:776) ~[spring-boot-2.3.5.RELEASE.jar!/:2.3.5.RELEASE]
at org.springframework.boot.SpringApplication.run(SpringApplication.java:322) ~[spring-boot-2.3.5.RELEASE.jar!/:2.3.5.RELEASE]
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1237) ~[spring-boot-2.3.5.RELEASE.jar!/:2.3.5.RELEASE]
at org.springframework.boot.SpringApplication.run(SpringApplication.java:1226) ~[spring-boot-2.3.5.RELEASE.jar!/:2.3.5.RELEASE]
at EtlPerCruscottoDataMartApplication.main(EtlPerCruscottoDataMartApplication.java:12) ~[classes!/:2.4.0]
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.loader.MainMethodRunner.run(MainMethodRunner.java:49) ~[background.jar:2.4.0]
at org.springframework.boot.loader.Launcher.launch(Launcher.java:107) ~[background.jar:2.4.0]
at org.springframework.boot.loader.Launcher.launch(Launcher.java:58) ~[background.jar:2.4.0]
at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88) ~[background.jar:2.4.0]
Caused by: com.mysql.cj.exceptions.CJCommunicationsException: The last packet successfully received from the server was 7,877,590 milliseconds ago. The last packet sent successfully to the server was 7,877,590 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:na]
at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:na]
at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:na]
at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490) ~[na:na]
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:61) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:151) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.exceptions.ExceptionFactory.createCommunicationsException(ExceptionFactory.java:167) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:544) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.a.NativeProtocol.checkErrorMessage(NativeProtocol.java:708) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.a.NativeProtocol.sendCommand(NativeProtocol.java:647) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.a.NativeProtocol.sendQueryPacket(NativeProtocol.java:946) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.NativeSession.execSQL(NativeSession.java:1075) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:930) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
... 46 common frames omitted
Caused by: java.net.SocketException: Connection timed out (Read failed)
at java.base/java.net.SocketInputStream.socketRead0(Native Method) ~[na:na]
at java.base/java.net.SocketInputStream.socketRead(SocketInputStream.java:115) ~[na:na]
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:168) ~[na:na]
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:140) ~[na:na]
at com.mysql.cj.protocol.ReadAheadInputStream.fill(ReadAheadInputStream.java:107) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:150) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.ReadAheadInputStream.read(ReadAheadInputStream.java:180) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at java.base/java.io.FilterInputStream.read(FilterInputStream.java:133) ~[na:na]
at com.mysql.cj.protocol.FullReadInputStream.readFully(FullReadInputStream.java:64) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:63) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:45) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:52) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:41) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:54) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:44) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:538) ~[mysql-connector-java-8.0.22.jar!/:8.0.22]
The step before shares the same design and have a longer query to execute on source database.
This is my pom.xml:
<parent>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-parent</artifactId>
<version>2.3.5.RELEASE</version>
<relativePath/> <!-- lookup parent from repository -->
</parent>
<properties>
<java.version>11</java.version>
</properties>
<dependencies>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-batch</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-devtools</artifactId>
<scope>runtime</scope>
<optional>true</optional>
</dependency>
<dependency>
<groupId>mysql</groupId>
<artifactId>mysql-connector-java</artifactId>
<scope>runtime</scope>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-configuration-processor</artifactId>
<optional>true</optional>
</dependency>
<dependency>
<groupId>org.projectlombok</groupId>
<artifactId>lombok</artifactId>
<optional>true</optional>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-test</artifactId>
<scope>test</scope>
<exclusions>
<exclusion>
<groupId>org.junit.vintage</groupId>
<artifactId>junit-vintage-engine</artifactId>
</exclusion>
</exclusions>
</dependency>
<dependency>
<groupId>org.springframework.batch</groupId>
<artifactId>spring-batch-test</artifactId>
<scope>test</scope>
</dependency>
</dependencies>
This is my application.yml:
spring:
application:
name: cruscotto-data-mart
datasource:
driverClassName: com.mysql.cj.jdbc.Driver
jdbcUrl: jdbc:mysql://${urlDB1:localhost}:3306/source?useSSL=false&serverTimezone=UTC&useLegacyDatetimeCode=false
username: ${userDB:user}
password: ${passDB:}
target:
driverClassName: com.mysql.cj.jdbc.Driver
jdbcUrl: jdbc:mysql://${urlDB2:localhost}:3306/target?useSSL=false&serverTimezone=UTC&useLegacyDatetimeCode=false
username: ${userDB2:user}
password: ${passDB2:}
batch:
initialize-schema: always
On database i have my.cnf:
[mysqld]
sql_mode = "STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_ENGINE_SUBSTITUTION"
innodb_flush_method=O_DIRECT
innodb_buffer_pool_size=16384M
max_connections=450
wait_timeout=600
max_allowed_packet=128M
long_query_time=650
query_cache_size=1024M
query_cache_limit=2048M
max_heap_table_size=512M
tmp_table_size=128M
query_cache_type=0
slow_query_log = 1
slow-query_log_file = /var/log/mysql-slow.log
long_query_time = 2
I have optimized the query and i have tried to increase timeouts.
2
Answers
Spring Batch cannot help with connection timeouts. The step will just fail.
You should try to optimize the query if possible and increase the connection timeout accordingly.
From the stacktrace we can see that the
Hikari
connection pool is in use. This can be an explanation of the mysterious error. The connections are being kept in pool and they are eventually idle for a long time. This cause the MySQL driver to report an error after some time.Solution
Let
Hikari
validate the connection periodically every 5 minutes with the following property:To learn more how the pool is actually working you can set its logging level to DEBUG with this property: