2 Replies Latest reply on Jan 29, 2016 6:11 PM by James Perkins

    Getting exceptions when batch job takes too long

    Martin Furek Newbie

      I run a batch job that reads a csv file and stores the objects in a database. If I set a large chunk size (greater than 10000), the objects get stored in the database correctly by the writer, but the job itself does not complete (does not go to the next batchlet) and throws the following exceptions. If I lower the chunksize (smaller than 5000), I don't get an error.

       

      I think this might have something to do with it, because I think it shuts down the transaction for the job:

      19:53:01,690 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff0a701314:-170dc5a0:56a12384:10cbe in state  RUN

      19:53:01,690 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffff0a701314:-170dc5a0:56a12384:10cbe invoked while multiple threads active within it.

      19:53:01,690 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action 0:ffff0a701314:-170dc5a0:56a12384:10cbe aborting with 1 threads active!

      19:53:01,690 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffff0a701314:-170dc5a0:56a12384:10cbe

       

      Several minutes later, the objects get inserted into the database and I get this after the writer ends:

      19:55:11,006 ERROR [org.jberet] (Batch Thread - 2) ProcessingInfo{count=19296, timerExpired=false, itemState=RUNNING, chunkState=DEPLETED, checkpointPosition=-1, readPosition=19296, failurePoint=null}

      19:55:11,006 ERROR [org.jberet] (Batch Thread - 2) item-count=50000, time-limit=0, skip-limit=-1, skipCount=0, retry-limit=-1, retryCount=0

      19:55:11,006 ERROR [org.jberet] (Batch Thread - 2) JBERET000007: Failed to run job ..., org.jberet.job.model.Chunk@1d606166: javax.batch.operations.BatchRuntimeException: JBERET000622: Failed to obtain connection from org.jboss.jca.adapters.jdbc.WrapperDataSource@154bde45, java:jboss/datasources/ea.base.batch.model.ds

        at org.jberet.repository.JdbcRepository.getConnection(JdbcRepository.java:911) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.repository.JdbcRepository.updateStepExecution(JdbcRepository.java:587) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.repository.JdbcRepository.savePersistentData(JdbcRepository.java:624) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.context.StepContextImpl.savePersistentData(StepContextImpl.java:178) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.ChunkRunner.doCheckpoint(ChunkRunner.java:528) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.ChunkRunner.readProcessWriteItems(ChunkRunner.java:307) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.ChunkRunner.run(ChunkRunner.java:192) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.StepExecutionRunner.runBatchletOrChunk(StepExecutionRunner.java:212) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.StepExecutionRunner.run(StepExecutionRunner.java:139) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.CompositeExecutionRunner.runStep(CompositeExecutionRunner.java:164) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.CompositeExecutionRunner.runJobElement(CompositeExecutionRunner.java:128) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.StepExecutionRunner.run(StepExecutionRunner.java:191) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.CompositeExecutionRunner.runStep(CompositeExecutionRunner.java:164) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.CompositeExecutionRunner.runJobElement(CompositeExecutionRunner.java:128) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.StepExecutionRunner.run(StepExecutionRunner.java:191) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.CompositeExecutionRunner.runStep(CompositeExecutionRunner.java:164) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.CompositeExecutionRunner.runFromHeadOrRestartPoint(CompositeExecutionRunner.java:88) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.jberet.runtime.runner.JobExecutionRunner.run(JobExecutionRunner.java:54) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        at org.wildfly.jberet.services.BatchEnvironmentService$WildFlyBatchEnvironment$1.run(BatchEnvironmentService.java:140) [jboss-batch-jberet-1.0.3.jar:1.0.3]

        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_67]

        at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_67]

        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_67]

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_67]

        at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_67]

        at org.jboss.threads.JBossThread.run(JBossThread.java:122)

      Caused by: java.sql.SQLException: javax.resource.ResourceException: IJ000460: Error checking for a transaction

        at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:151)

        at org.jberet.repository.JdbcRepository.getConnection(JdbcRepository.java:909) [jberet-core-1.1.0.Final.jar:1.1.0.Final]

        ... 24 more

      Caused by: javax.resource.ResourceException: IJ000460: Error checking for a transaction

        at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:362)

        at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:510)

        at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:143)

        ... 25 more

      Caused by: javax.resource.ResourceException: IJ000459: Transaction is not active: tx=TransactionImple < ac, BasicAction: 0:ffff0a701314:-170dc5a0:56a12384:10cbe status: ActionStatus.ABORTED >

        at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:352)

        ... 27 more

       

       

      Can someone tell me what the problem is? I suppose there is a timeout for the job. Where could I set this? I might still use a lower chunksize, but I want to know the reason for this and how it could be fixed.

       

      Thanks in advance.