Uploaded image for project: 'JBoss BPMS Platform'
  1. JBoss BPMS Platform
  2. RHBPMS-4762

[GSS](6.4.z) Transaction timeout when running EJB Timers on WAS

    XMLWordPrintable

Details

    • Bug
    • Resolution: Done
    • Major
    • 6.4.5
    • 6.4.2
    • jBPM Core
    • BPMS 6.4.2
      Spring
      WAS 8.5.x

    • 2017 Week 28-29

    Description

      EJB timer service is correctly invoking EJBTimerScheduler.executeTimerJob, however the transaction is timing out. At the time of Transaction failure, the engine is initializing the KieSession and checking that timers configured in that session are not duplicated in the EJB timer service. This appears to be taking longer than the timeout of 120s.

      This is partly due to the engine needing to loop over all timers to check for duplicates, and partly due to WebSphere's implementation, which requires a separate database call for each timer to pull back the job data

      To address, please implement some version of local caching (to be made optional?) as:
      https://github.com/kiegroup/jbpm/pull/850

      STACK TRACE
      [5/17/17 18:31:19:347 EDT] 00000096 TimeoutManage I WTRN0006W: Transaction 0000015C18879B3600000001602628C8C04E7819F8696551C9E85E6545D4C2E75099FB6B0000015C18879B3600000001602628C8C04E7819F8696551C9E85E6545D4C2E75099FB6B00000001 has timed out after 120 seconds.
      [5/17/17 18:31:19:349 EDT] 00000096 TimeoutManage I WTRN0124I: When the timeout occurred the thread with which the transaction is, or was most recently, associated was Thread[DefaultWorkManager.Alarm Pool : 6,5,DefaultWorkManager: WAS Scheduler: jdbc/ejtimers]. The stack trace of this thread when the timeout occurred was:
      java.net.SocketInputStream.socketRead0(Native Method)
      java.net.SocketInputStream.read(SocketInputStream.java:164)
      java.net.SocketInputStream.read(SocketInputStream.java:134)
      oracle.net.ns.Packet.receive(Packet.java:300)
      oracle.net.ns.DataPacket.receive(DataPacket.java:106)
      oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:315)
      oracle.net.ns.NetInputStream.read(NetInputStream.java:260)
      oracle.net.ns.NetInputStream.read(NetInputStream.java:185)
      oracle.net.ns.NetInputStream.read(NetInputStream.java:102)
      oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:124)
      oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:80)
      oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1137)
      oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:290)
      oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:192)
      oracle.jdbc.driver.T4CTTIOtxen.doOTXEN(T4CTTIOtxen.java:168)
      oracle.jdbc.driver.T4CXAResource.doTransaction(T4CXAResource.java:746)
      oracle.jdbc.driver.T4CXAResource.doCommit(T4CXAResource.java:422)
      oracle.jdbc.xa.client.OracleXAResource.commit(OracleXAResource.java:560)
      com.ibm.ws.rsadapter.spi.WSRdbXaResourceImpl.commit(WSRdbXaResourceImpl.java:361)
      com.ibm.ejs.j2c.XATransactionWrapper.commit(XATransactionWrapper.java:496)
      com.ibm.tx.jta.impl.JTAXAResourceImpl.commit_one_phase(JTAXAResourceImpl.java:343)
      com.ibm.tx.jta.impl.RegisteredResources.flowCommitOnePhase(RegisteredResources.java:2397)
      com.ibm.tx.jta.impl.TransactionImpl.commitXAResources(TransactionImpl.java:1819)
      com.ibm.ws.tx.jta.TransactionImpl.stage1CommitProcessing(TransactionImpl.java:600)
      com.ibm.tx.jta.impl.TransactionImpl.processCommit(TransactionImpl.java:1029)
      com.ibm.tx.jta.impl.TransactionImpl.commit(TransactionImpl.java:963)
      com.ibm.ws.tx.jta.TranManagerImpl.commit(TranManagerImpl.java:439)
      com.ibm.tx.jta.impl.TranManagerSet.commit(TranManagerSet.java:191)
      com.ibm.ws.extensionhelper.tran.impl.TransactionControlImpl.postinvoke(TransactionControlImpl.java:344)
      com.ibm.ws.scheduler.SchedulerImpl$7.run(SchedulerImpl.java:2196)
      java.security.AccessController.doPrivileged(AccessController.java:456)
      com.ibm.ws.scheduler.SchedulerImpl.getTask(SchedulerImpl.java:2159)
      com.ibm.ejs.container.TimerImpl.getInfo(TimerImpl.java:686)
      org.jbpm.services.ejb.timer.EJBTimerScheduler.getTimerByName(EJBTimerScheduler.java:129)
      sun.reflect.GeneratedMethodAccessor169.invoke(Unknown Source)
      sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:56)
      java.lang.reflect.Method.invoke(Method.java:620)
      com.ibm.ejs.container.EJSContainer.invokeProceed(EJSContainer.java:5798)
      com.ibm.ejs.container.interceptors.InvocationContextImpl.proceed(InvocationContextImpl.java:569)
      org.apache.webbeans.ejb.common.interceptor.OpenWebBeansEjbInterceptor.callToOwbInterceptors(OpenWebBeansEjbInterceptor.java:197)
      sun.reflect.GeneratedMethodAccessor131.invoke(Unknown Source)
      sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:56)
      java.lang.reflect.Method.invoke(Method.java:620)
      com.ibm.ejs.container.interceptors.InterceptorProxy.invokeInterceptor(InterceptorProxy.java:227)
      com.ibm.ejs.container.interceptors.InvocationContextImpl.proceed(InvocationContextImpl.java:549)
      org.apache.webbeans.ejb.WSEJBInterceptor.callToOwbInterceptors(WSEJBInterceptor.java:152)
      sun.reflect.GeneratedMethodAccessor132.invoke(Unknown Source)
      sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:56)
      java.lang.reflect.Method.invoke(Method.java:620)
      com.ibm.ejs.container.interceptors.InterceptorProxy.invokeInterceptor(InterceptorProxy.java:227)
      com.ibm.ejs.container.interceptors.InvocationContextImpl.proceed(InvocationContextImpl.java:549)
      com.ibm.ejs.container.interceptors.InvocationContextImpl.doAroundInvoke(InvocationContextImpl.java:230)
      com.ibm.ejs.container.EJSContainer.invoke(EJSContainer.java:5689)
      org.jbpm.services.ejb.timer.EJSLocalNSGEJBTimerScheduler_2ce4371c.getTimerByName(EJSLocalNSGEJBTimerScheduler_2ce4371c.java)
      org.jbpm.services.ejb.timer.EjbSchedulerService.scheduleJob(EjbSchedulerService.java:56)
      org.jbpm.process.core.timer.impl.GlobalTimerService.scheduleJob(GlobalTimerService.java:93)
      org.jbpm.process.core.timer.impl.RegisteredTimerServiceDelegate.scheduleJob(RegisteredTimerServiceDelegate.java:63)
      org.jbpm.process.instance.timer.TimerManager$ProcessTimerInputMarshaller.deserialize(TimerManager.java:268)
      org.drools.core.marshalling.impl.ProtobufInputMarshaller.readTimer(ProtobufInputMarshaller.java:709)
      org.drools.core.marshalling.impl.ProtobufInputMarshaller.readSession(ProtobufInputMarshaller.java:291)
      org.drools.core.marshalling.impl.ProtobufInputMarshaller.readSession(ProtobufInputMarshaller.java:162)
      org.drools.core.marshalling.impl.ProtobufMarshaller.unmarshall(ProtobufMarshaller.java:116)
      org.drools.core.marshalling.impl.ProtobufMarshaller.unmarshall(ProtobufMarshaller.java:52)
      org.drools.persistence.SessionMarshallingHelper.loadSnapshot(SessionMarshallingHelper.java:99)
      org.drools.persistence.SingleSessionCommandService.initExistingKnowledgeSession(SingleSessionCommandService.java:253)
      org.drools.persistence.SingleSessionCommandService.<init>(SingleSessionCommandService.java:191)
      sun.reflect.GeneratedConstructorAccessor204.newInstance(Unknown Source)
      sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:58)
      java.lang.reflect.Constructor.newInstance(Constructor.java:542)
      org.drools.persistence.jpa.KnowledgeStoreServiceImpl.buildCommandService(KnowledgeStoreServiceImpl.java:143)
      org.drools.persistence.jpa.KnowledgeStoreServiceImpl.loadKieSession(KnowledgeStoreServiceImpl.java:111)
      org.drools.persistence.jpa.KnowledgeStoreServiceImpl.loadKieSession(KnowledgeStoreServiceImpl.java:39)
      org.kie.internal.persistence.jpa.JPAKnowledgeService.loadStatefulKnowledgeSession(JPAKnowledgeService.java:144)
      org.jbpm.runtime.manager.impl.factory.JPASessionFactory.findKieSessionById(JPASessionFactory.java:53)
      org.jbpm.runtime.manager.impl.PerProcessInstanceRuntimeManager$PerProcessInstanceInitializer.initKieSession(PerProcessInstanceRuntimeManager.java:553)
      org.jbpm.runtime.manager.impl.RuntimeEngineImpl.getKieSession(RuntimeEngineImpl.java:70)
      org.jbpm.process.core.timer.impl.GlobalTimerService.getCommandService(GlobalTimerService.java:233)
      org.jbpm.process.core.timer.impl.GlobalTimerService.getCommandService(GlobalTimerService.java:208)
      org.jbpm.persistence.timer.GlobalJpaTimerJobInstance.call(GlobalJpaTimerJobInstance.java:75)
      org.jbpm.persistence.timer.GlobalJpaTimerJobInstance.call(GlobalJpaTimerJobInstance.java:47)
      org.jbpm.services.ejb.timer.EJBTimerScheduler.executeTimerJob(EJBTimerScheduler.java:79)
      sun.reflect.GeneratedMethodAccessor444.invoke(Unknown Source)
      sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:56)
      java.lang.reflect.Method.invoke(Method.java:620)
      com.ibm.ejs.container.EJSContainer.invokeProceed(EJSContainer.java:5798)
      com.ibm.ejs.container.interceptors.InvocationContextImpl.proceed(InvocationContextImpl.java:569)
      org.apache.webbeans.ejb.common.interceptor.OpenWebBeansEjbInterceptor.callAroundTimeouts(OpenWebBeansEjbInterceptor.java:606)
      sun.reflect.GeneratedMethodAccessor443.invoke(Unknown Source)
      sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:56)
      java.lang.reflect.Method.invoke(Method.java:620)
      com.ibm.ejs.container.interceptors.InterceptorProxy.invokeInterceptor(InterceptorProxy.java:227)
      com.ibm.ejs.container.interceptors.InvocationContextImpl.proceed(InvocationContextImpl.java:549)
      org.apache.webbeans.ejb.WSEJBInterceptor.callToOwbInterceptors(WSEJBInterceptor.java:152)
      sun.reflect.GeneratedMethodAccessor132.invoke(Unknown Source)
      sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:56)
      java.lang.reflect.Method.invoke(Method.java:620)
      com.ibm.ejs.container.interceptors.InterceptorProxy.invokeInterceptor(InterceptorProxy.java:227)
      com.ibm.ejs.container.interceptors.InvocationContextImpl.proceed(InvocationContextImpl.java:549)
      com.ibm.ejs.container.interceptors.InvocationContextImpl.doAroundInvoke(InvocationContextImpl.java:230)
      com.ibm.ejs.container.EJSContainer.invoke(EJSContainer.java:5689)
      com.ibm.ejs.container.TimedObjectWrapper.invokeCallback(TimedObjectWrapper.java:114)
      com.ibm.ejs.container.TimerTaskHandler.doWork(TimerTaskHandler.java:364)
      com.ibm.ws.scheduler.AlarmListener.executeTaskWithNotification(AlarmListener.java:807)
      com.ibm.ws.scheduler.AlarmListener.access$700(AlarmListener.java:124)
      com.ibm.ws.scheduler.AlarmListener$TaskWork.doWork(AlarmListener.java:436)
      com.ibm.ws.scheduler.AlarmListener$TaskWork.run(AlarmListener.java:222)
      com.ibm.ws.asynchbeans.J2EEContext$RunProxy.run(J2EEContext.java:271)
      java.security.AccessController.doPrivileged(AccessController.java:400)
      com.ibm.ws.asynchbeans.J2EEContext.run(J2EEContext.java:797)
      com.ibm.ws.asynchbeans.ExecutionContextImpl.go(ExecutionContextImpl.java:86)
      com.ibm.ws.scheduler.AlarmListener.fireTask(AlarmListener.java:1416)
      com.ibm.ws.scheduler.AlarmListener.fired(AlarmListener.java:1334)
      com.ibm.ws.asynchbeans.AlarmImpl.callListenerMethod(AlarmImpl.java:427)
      com.ibm.ws.asynchbeans.timer.GenericTimer.run(GenericTimer.java:228)
      com.ibm.ws.asynchbeans.J2EEContext$RunProxy.run(J2EEContext.java:267)
      java.security.AccessController.doPrivileged(AccessController.java:400)
      com.ibm.ws.asynchbeans.J2EEContext.run(J2EEContext.java:1165)
      com.ibm.ws.asynchbeans.AlarmImpl.runListenerAsCJWork(AlarmImpl.java:249)
      com.ibm.ws.asynchbeans.am._Alarm.fireAlarm(_Alarm.java:340)
      com.ibm.ws.asynchbeans.am._Alarm.run(_Alarm.java:237)
      com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1881)

      Attachments

        Issue Links

          Activity

            People

              swiderski.maciej Maciej Swiderski (Inactive)
              djeremiah David Murphy (Inactive)
              David Murphy (Inactive)
              Marian Macik Marian Macik
              Marian Macik Marian Macik
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: