-
Bug
-
Resolution: Done
-
Major
-
1.3.1.Final
-
None
Normally a batchlet-type job uses the JTA timeout (default value of 300s) defined in /subsystem=transactions:read-attribute(name=default-timeout). Chunk-type jobs ignores JTA timeout and use a value specified by the property javax.transaction.global.timeout (default of 180s).
It turns out that after a chunk-type job the transaction timeout is changed to the value of property javax.transaction.global.timeout for a thread and it's not cleaned up. If a bachlet-type job runs again in the same thread the transaction timeout is set to an unexpected value.
The property javax.transaction.global.timeout should affect only chunk-type steps and not batchlets.
I have attached a project to reproduce the issue and the log output is:
14:32:48,627 INFO [org.jberet.test.BenchmarkJobListener] (Batch Thread - 1) Initiating job "batchletJob" 14:32:48,684 INFO [org.jberet.test.Batchlet] (Batch Thread - 1) [batchletJob] Transaction key: 0:ffff7f000101:-57847db8:5c192123:10 14:32:58,693 INFO [org.jberet.test.BenchmarkJobListener] (Batch Thread - 1) Job batchletJob ended within 10 seconds
14:33:05,979 INFO [org.jberet.test.BenchmarkJobListener] (Batch Thread - 1) Initiating job "chunkJob" 14:33:05,985 INFO [org.jberet.test.Reader] (Batch Thread - 1) [reader] Transaction key: 0:ffff7f000101:-57847db8:5c192123:16 14:33:05,986 INFO [org.jberet.test.Writer] (Batch Thread - 1) [writer] Transaction key: 0:ffff7f000101:-57847db8:5c192123:16 14:33:05,988 INFO [org.jberet.test.BenchmarkJobListener] (Batch Thread - 1) Job chunkJob ended within 0 seconds
and calling batchlet again
14:33:18,835 INFO [org.jberet.test.BenchmarkJobListener] (Batch Thread - 1) Initiating job "batchletJob"
14:33:18,837 INFO [org.jberet.test.Batchlet] (Batch Thread - 1) [batchletJob] Transaction key: 0:ffff7f000101:-57847db8:5c192123:22
14:33:23,837 WARN [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff7f000101:-57847db8:5c192123:22 in state RUN
14:33:23,839 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffff7f000101:-57847db8:5c192123:22 invoked while multiple threads active within it.
14:33:23,841 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012381: Action id 0:ffff7f000101:-57847db8:5c192123:22 completed with multiple threads - thread Batch Thread - 1 was in progress with java.lang.Thread.sleep(Native Method)
org.jberet.test.Batchlet.process(Batchlet.java:29)
org.jberet.test.Batchlet$Proxy$_$$_WeldSubclass.process$$super(Unknown Source)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:498)
org.jboss.weld.interceptor.proxy.TerminalAroundInvokeInvocationContext.proceedInternal(TerminalAroundInvokeInvocationContext.java:51)
org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:78)
com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:174)
com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequired.doIntercept(TransactionalInterceptorRequired.java:53)
com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:88)
com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:47)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:498)
org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73)
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84)
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72)
org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56)
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
org.jberet.test.Batchlet$Proxy$_$$_WeldSubclass.process(Unknown Source)
org.jberet.runtime.runner.BatchletRunner.run(BatchletRunner.java:76)
org.jberet.runtime.runner.StepExecutionRunner.runBatchletOrChunk(StepExecutionRunner.java:228)
org.jberet.runtime.runner.StepExecutionRunner.run(StepExecutionRunner.java:144)
org.jberet.runtime.runner.CompositeExecutionRunner.runStep(CompositeExecutionRunner.java:164)
org.jberet.runtime.runner.CompositeExecutionRunner.runFromHeadOrRestartPoint(CompositeExecutionRunner.java:88)
org.jberet.runtime.runner.JobExecutionRunner.run(JobExecutionRunner.java:60)
org.wildfly.extension.batch.jberet.deployment.BatchEnvironmentService$WildFlyBatchEnvironment$1.run(BatchEnvironmentService.java:180)
org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:494)
org.jberet.spi.JobExecutor$2.run(JobExecutor.java:149)
org.jberet.spi.JobExecutor$1.run(JobExecutor.java:99)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
java.lang.Thread.run(Thread.java:748)
org.jboss.threads.JBossThread.run(JBossThread.java:485)
14:33:23,842 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action 0:ffff7f000101:-57847db8:5c192123:22 aborting with 1 threads active!
14:33:23,847 WARN [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffff7f000101:-57847db8:5c192123:22
14:33:28,837 WARN [com.arjuna.ats.arjuna] (Batch Thread - 1) ARJUNA012077: Abort called on already aborted atomic action 0:ffff7f000101:-57847db8:5c192123:22
14:33:28,846 WARN [org.jberet] (Batch Thread - 1) JBERET000001: Failed to run batchlet org.jberet.job.model.RefArtifact@25c1eb7e: javax.transaction.RollbackException: ARJUNA016102: The transaction is not active! Uid is 0:ffff7f000101:-57847db8:5c192123:22
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1278)
at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89)
at org.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:77)
at org.wildfly.transaction.client.ContextTransactionManager.commit(ContextTransactionManager.java:71)
at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:232)
at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:178)
at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequired.doIntercept(TransactionalInterceptorRequired.java:53)
at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:88)
at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:47)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73)
at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84)
at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72)
at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56)
at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79)
at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68)
at org.jberet.test.Batchlet$Proxy$_$$_WeldSubclass.process(Unknown Source)
at org.jberet.runtime.runner.BatchletRunner.run(BatchletRunner.java:76)
at org.jberet.runtime.runner.StepExecutionRunner.runBatchletOrChunk(StepExecutionRunner.java:228)
at org.jberet.runtime.runner.StepExecutionRunner.run(StepExecutionRunner.java:144)
at org.jberet.runtime.runner.CompositeExecutionRunner.runStep(CompositeExecutionRunner.java:164)
at org.jberet.runtime.runner.CompositeExecutionRunner.runFromHeadOrRestartPoint(CompositeExecutionRunner.java:88)
at org.jberet.runtime.runner.JobExecutionRunner.run(JobExecutionRunner.java:60)
at org.wildfly.extension.batch.jberet.deployment.BatchEnvironmentService$WildFlyBatchEnvironment$1.run(BatchEnvironmentService.java:180)
at org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:494)
at org.jberet.spi.JobExecutor$2.run(JobExecutor.java:149)
at org.jberet.spi.JobExecutor$1.run(JobExecutor.java:99)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
at org.jboss.threads.JBossThread.run(JBossThread.java:485)
14:33:28,849 INFO [org.jberet.test.BenchmarkJobListener] (Batch Thread - 1) Job batchletJob ended within 10 seconds
- is cloned by
-
-
- Closed
-
- is related to
-
-
- Closed
-
