JobRepository Failure

[waaa768]

Hi all,

We are experiencing some problems with our Spring Batch JobRepository. Normally, our batch jobs run without any issue, the job gets finished and the steps are logged in the JobRepository.

The problem occurs when we have a long running job, i.e. a tasklet commits a large set of data into our production database, this can sometime take more than 5 hours. We got exceptions like the one below:

ERROR JobRepository failure forcing exit with unknown status
org.springframework.dao.RecoverableDataAccessExcep tion: PreparedStatementCallback; SQL [UPDATE BATCH_STEP_EXECUTION_CONTEXT SET SHORT_CONTEXT = ?, SERIALIZED_CONTEXT = ? WHERE STEP_EXECUTION_ID = ?]; The last packet successfully received from the server was51849 seconds ago.The last packet sent successfully to the server was 51849 seconds ago, which 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.; nested exception is com.mysql.jdbc.exceptions.jdbc4.CommunicationsExce ption: The last packet successfully received from the server was51849 seconds ago.The last packet sent successfully to the server was 51849 seconds ago, which is longer than the server configured value of 'wait_timeout'. You should consider either e!
xpiring 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 org.springframework.jdbc.support.SQLExceptionSubcl assTranslator.doTranslate(SQLExceptionSubclassTran slator.java:98) ~[spring-jdbc-3.1.0.RELEASE.jar:3.1.0.RELEASE]

We have tried four different connection pool implementations, and working with our DBA, we are pretty sure that the connection pools are working properly, all the connections in the pool get tested periodically. However, we have noticed that there is one connection to the JobRepository always open and doing nothing.

We are wondering whether anyone has come across this problem before? Any suggestions are welcome.

Many thanks,
Rui

[AnthonyRyan]

Hi Rui,

Did you get an answer for this problem?

We are also running a large amount of imformation through one of our steps which can take over an hour. When testing it we got the following exceptions, which look to be very similar to your own.

2012-11-05 17:38:45,735 [task-scheduler-2] ERROR tasklet.TaskletStep  - JobRepository failure forcing exit with unknown status
org.springframework.dao.RecoverableDataAccessException: PreparedStatementCallback; SQL [UPDATE BATCH_STEP_EXECUTION_CONTEXT SET SHORT_CONTEXT = ?, SERIALIZED_CONTEXT = ? WHERE STEP_EXECUTION_ID = ?]; Communications link failure

The last packet successfully received from the server was 4,023,267 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.; nested exception is com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 4,023,267 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:662)
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

Followed by:

Caused by: java.net.SocketException: Software caused connection abort: recv failed
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:114)
	at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:161)
	at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:189)
	at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3036)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3489)
	... 20 more
2012-11-05 17:38:45,969 [task-scheduler-2] ERROR tasklet.TaskletStep  - Rolling back with transaction in unknown state
2012-11-05 17:38:45,969 [task-scheduler-2] ERROR support.TransactionTemplate  - Application exception overridden by rollback exception
org.springframework.batch.core.step.FatalStepExecutionException: JobRepository failure forcing exit with unknown status
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)

And finally by:

2012-11-05 17:38:46,001 [task-scheduler-2] ERROR step.AbstractStep  - Encountered an error executing the step
org.springframework.transaction.TransactionSystemException: Could not roll back JDBC transaction; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
	at java.util.concurrent.FutureTask.run(FutureTask.java:138)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:662)
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
	at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
	at com.mysql.jdbc.Util.getInstance(Util.java:386)
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1013)
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987)
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:982)
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:927)
	at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1251)
	at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1243)
	at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4723)
	at org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:368)
	at org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:368)
	at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.rollback(PoolingDataSource.java:323)
	... 8 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 4,023,267 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.
	at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)

Any help would be greatly appreciated!

Thanks,
Tony

[mminella]

What connection pool are you using and how is it configured? It sounds like expired connections are not being tossed out.

[AnthonyRyan]

Hi mminella, thanks for replying,

I'm using the following Datasource configuration but I don't have a Connection Pool configured explicitly:

	<bean id="dataSource" 
         class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
		<property name="driverClassName" value="com.mysql.jdbc.Driver" />
		<property name="url" value="jdbc:mysql://localhost/Example" />
		<property name="username" value="root" />
		<property name="password" value="blahblah" />
		<property name="poolPreparedStatements"><value>true</value></property>
		<property name="maxActive"><value>10</value></property>
		<property name="maxIdle"><value>1</value></property>
	</bean>

Do I also need to set up a connection pool? As a bean in the same file? What type is recommended?

Cheers,
Tony

[mminella]

Try setting a validation query (the pool uses it to validate connections before returning them to the user).

[vijaymohanp]

I have same issue my process may take more than half an hour to finish the task in the writer, and in that scenario its throwing this exception. my config given below.

You can see the maxIdleTime and idleConnectionTestPeriod value there.

<bean id="jobsDataSource" name="jobsDataSource" class="com.mchange.v2.c3p0.ComboPooledDataSource"
		destroy-method="close">
		<property name="driverClass" value="${jdbc.driver}" />
		<property name="jdbcUrl" value="${job.jdbc.url}" />
		<property name="user" value="${jdbc.read.write.username}" />
		<property name="password" value="${jdbc.read.write.password}" />

		<property name="acquireIncrement" value="5" />
		<property name="initialPoolSize" value="10" />
		<property name="minPoolSize" value="5" />
		<property name="maxPoolSize" value="100" />
		<property name="maxIdleTime" value="280" />
		<property name="maxStatementsPerConnection" value="100" />
		<property name="numHelperThreads" value="8" />
		<property name="idleConnectionTestPeriod" value="260" />
		<property name="preferredTestQuery" value="SELECT 1" />
	</bean>

I did increased the timeout in the mysql to 1500sec and its started working fine i used the same datasource conf before.

I dont know what is wrong here.

If you can give me some insight that will be great, I really dont want to increase the timeout in mysql to 1500sec from 60sec.