1 Reply Latest reply on Apr 13, 2016 3:59 AM by Pedro Ruivo

    InvocationContextInterceptor - ISPN000136: Execution error: java.lang.IllegalStateException

    Dave Rathnow Novice


      I'm using Embedded Infinispan: 8.0.2 with Wildfly 10.0.0.  I have a number of different caches that I'm using but one, the most important in the app, seems to always cause me trouble.  I decided to programmatic configuration:

       

      GlobalConfiguration glob = new GlobalConfigurationBuilder()
                  .transport()
                      .defaultTransport()
                      .clusterName(CLUSTER_NAME)
                  .globalJmxStatistics()
                      .allowDuplicateDomains(true)
                  .build();
          
          Configuration defaultConfig = new ConfigurationBuilder()
                          .transaction()
                              .transactionMode(TransactionMode.TRANSACTIONAL)
                              .autoCommit(true)
                              .lockingMode(LockingMode.OPTIMISTIC)
                              .transactionManagerLookup(new GenericTransactionManagerLookup())
                          .build();
          
          cacheManager = new DefaultCacheManager(glob, defaultConfig);
          cacheManager.start();
      
      
          String cacheStorePath = getCacheStorePath();
          Configuration requestCacheConfig = new ConfigurationBuilder()
                                                      .clustering()
                                                      .cacheMode(CacheMode.REPL_SYNC)
                                                      .persistence()
                                                          .addStore(SingleFileStoreConfigurationBuilder.class)
                                                          .location(cacheStorePath)
                                                      .indexing()
                                                          .index(Index.LOCAL)
                                                      .build();
          
          cacheManager.defineConfiguration(CACHE_NAME, requestCacheConfig);
          Cache<String, OutgoingRequest> cache = cacheManager.getCache(CACHE_NAME);
          ExpirationManager expirationManager = new ExpirationManager(cache, expirationMinutes.currentValue().longValue());
          OutgoingRequestCacheCreateEventListener createListener = new OutgoingRequestCacheCreateEventListener();
          cache.addListener(expirationManager);
          cache.addListener(createListener);
      

       

      The app communicates with remote embedded devices that collect sensor data and send that data to our server at regular and irregular intervals.  The remote devices connect and hold their connections open for a period of time before disconnecting and then reconnecting. All the work is done by a number of worker threads that manage these connections.  We use Infinspan caches to hold outgoing data for these device so whenever a device connects, the cache is checked to see if there is any pending data.  If a device is connected cache listeners detect additional devices and kick off a process to send that data to the device.

       

      Our application has been running fine for the past couple of weeks but last night it crashed.  Things seemed to start going awry when the following messages started to show up in the logfile:

       

      23:11:22,543 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4a3 in state  RUN

      23:13:25,608 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4af in state  RUN

      23:13:34,596 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4c3 in state  RUN

      23:13:49,630 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b506 in state  RUN

      23:13:55,174 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b50c in state  RUN

      23:14:43,126 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b5dc in state  RUN

      23:16:28,680 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4a3 in state  CANCEL

      23:14:03,563 WARN  [com.arjuna.ats.arjuna] () ARJUNA012095: Abort of action id 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4a3 invoked while multiple threads active within it.

      23:16:37,817 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4af in state  SCHEDULE_CANCEL

      23:21:05,952 WARN  [com.arjuna.ats.arjuna] () ARJUNA012108: CheckedAction::check - atomic action 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4a3 aborting with 1 threads active!

      23:20:22,541 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4c3 in state  SCHEDULE_CANCEL

      23:23:57,483 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b506 in state  SCHEDULE_CANCEL

      23:25:37,023 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b50c in state  SCHEDULE_CANCEL

      23:25:52,780 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b5dc in state  SCHEDULE_CANCEL

      23:28:23,198 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4af in state  CANCEL

      23:27:55,662 WARN  [com.arjuna.ats.arjuna] () ARJUNA012095: Abort of action id 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4af invoked while multiple threads active within it.

      23:29:46,175 WARN  [com.arjuna.ats.arjuna] () ARJUNA012108: CheckedAction::check - atomic action 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4af aborting with 1 threads active!

      23:29:23,172 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4c3 in state  SCHEDULE_CANCEL

      23:31:36,665 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b506 in state  SCHEDULE_CANCEL

      23:31:36,665 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b50c in state  SCHEDULE_CANCEL

      23:30:59,033 WARN  [com.arjuna.ats.arjuna] () ARJUNA012095: Abort of action id 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4c3 invoked while multiple threads active within it.

      23:31:40,315 WARN  [com.arjuna.ats.arjuna] () ARJUNA012108: CheckedAction::check - atomic action 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b4c3 aborting with 1 threads active!

      23:31:42,323 WARN  [com.arjuna.ats.arjuna] () ARJUNA012095: Abort of action id 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b506 invoked while multiple threads active within it.

      23:31:42,323 WARN  [com.arjuna.ats.arjuna] () ARJUNA012108: CheckedAction::check - atomic action 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b506 aborting with 1 threads active!

      23:31:38,578 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b5dc in state  SCHEDULE_CANCEL

      23:35:11,646 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b506 in state  CANCEL

      23:35:32,469 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b50c in state  SCHEDULE_CANCEL

      23:37:32,552 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b5dc in state  SCHEDULE_CANCEL

      23:38:21,425 WARN  [com.arjuna.ats.arjuna] () ARJUNA012117: TransactionReaper::check timeout for TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b506 in state  CANCEL_INTERRUPTED

      23:40:12,663 WARN  [com.arjuna.ats.arjuna] () ARJUNA012120: TransactionReaper::check worker Thread[Transaction Reaper Worker 0,5,main] not responding to interrupt when cancelling TX 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b506 -- worker marked as zombie and TX scheduled for mark-as-rollback

       

      At this point all my worker threads stopped processing data and appeared to all be blocked.  This went on for a couple hours of and then this exception started showing up:

       

      00:10:33,558 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (10.71.17.16/17) ISPN000136: Execution error: java.lang.IllegalStateException: Transaction TransactionImple < ac, BasicAction: 0:ffffc0a80b03:-7a2e229:56f77a1f:b6b639 status: ActionStatus.ABORTING > is not in a valid state to be invoking cache operations on.
        at org.infinispan.interceptors.TxInterceptor.enlist(TxInterceptor.java:362) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.TxInterceptor.enlistIfNeeded(TxInterceptor.java:327) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:321) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:300) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:77) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:233) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.statetransfer.StateTransferInterceptor.handleDefault(StateTransferInterceptor.java:217) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:77) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.CacheMgmtInterceptor.visitDataReadCommand(CacheMgmtInterceptor.java:103) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.CacheMgmtInterceptor.visitGetKeyValueCommand(CacheMgmtInterceptor.java:91) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:102) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:71) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:77) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:333) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:423) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:415) [infinispan-core.jar:7.1.1.Final]
        at org.infinispan.query.impl.EntityLoader.load(EntityLoader.java:28) [infinispan-query.jar:7.1.1.Final]
        at org.infinispan.query.impl.EntityLoader.load(EntityLoader.java:34) [infinispan-query.jar:7.1.1.Final]
        at org.infinispan.query.impl.CacheQueryImpl.list(CacheQueryImpl.java:162) [infinispan-query.jar:7.1.1.Final]
        at zedi.pacbridge.app.cache.InfinispanOutgoingRequestCache.outgoingRequestsForSiteAddress(InfinispanOutgoingRequestCache.java:86) [pacbridge-app-6.1.0.jar:]
        at sun.reflect.GeneratedMethodAccessor19.invoke(Unknown Source) [:1.7.0_79]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) [rt.jar:1.7.0_79]
        at java.lang.reflect.Method.invoke(Unknown Source) [rt.jar:1.7.0_79]
        at org.jboss.as.ee.component.ManagedReferenceMethodInterceptorFactory$ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptorFactory.java:72) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:58) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:374) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:129) [jboss-as-weld-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:137) [jboss-as-weld-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:58) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:58) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47) [jboss-as-jpa-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:94) [jboss-as-weld-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:51) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:272) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:339) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:238) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55) [jboss-as-ejb3-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
        at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72) [jboss-as-ee-7.3.0.Final-redhat-14.jar:7.3.0.Final-redhat-14]
        at zedi.pacbridge.app.controls.OutgoingRequestCache$$$view3.outgoingRequestsForSiteAddress(Unknown Source) [pacbridge-app-6.1.0.jar:]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_79]
        at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) [rt.jar:1.7.0_79]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) [rt.jar:1.7.0_79]
        at java.lang.reflect.Method.invoke(Unknown Source) [rt.jar:1.7.0_79]
        at org.jboss.weld.util.reflection.SecureReflections$13.work(SecureReflections.java:267) [weld-core-1.1.16.Final-redhat-1.jar:1.1.16.Final-redhat-1]
        at org.jboss.weld.util.reflection.SecureReflectionAccess.run(SecureReflectionAccess.java:52) [weld-core-1.1.16.Final-redhat-1.jar:1.1.16.Final-redhat-1]
        at org.jboss.weld.util.reflection.SecureReflectionAccess.runAsInvocation(SecureReflectionAccess.java:137) [weld-core-1.1.16.Final-redhat-1.jar:1.1.16.Final-redhat-1]
        at org.jboss.weld.util.reflection.SecureReflections.invoke(SecureReflections.java:263) [weld-core-1.1.16.Final-redhat-1.jar:1.1.16.Final-redhat-1]
        at org.jboss.weld.bean.proxy.EnterpriseBeanProxyMethodHandler.invoke(EnterpriseBeanProxyMethodHandler.java:115) [weld-core-1.1.16.Final-redhat-1.jar:1.1.16.Final-redhat-1]
        at org.jboss.weld.bean.proxy.EnterpriseTargetBeanInstance.invoke(EnterpriseTargetBeanInstance.java:56) [weld-core-1.1.16.Final-redhat-1.jar:1.1.16.Final-redhat-1]
        at org.jboss.weld.bean.proxy.ProxyMethodHandler.invoke(ProxyMethodHandler.java:105) [weld-core-1.1.16.Final-redhat-1.jar:1.1.16.Final-redhat-1]
        at zedi.pacbridge.app.cache.OutgoingRequestCache$OutgoingRequestCacheUpdateDelegate$1675550284$Proxy$_$$_Weld$Proxy$.outgoingRequestsForSiteAddress(OutgoingRequestCache$OutgoingRequestCacheUpdateDelegate$1675550284$Proxy$_$$_Weld$Proxy$.java) [pacbridge-app-6.1.0.jar:]
        at zedi.pacbridge.app.net.ConnectionManagerHelper$WorkerRunner.run(ConnectionManagerHelper.java:72) [pacbridge-app-6.1.0.jar:]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [rt.jar:1.7.0_79]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [rt.jar:1.7.0_79]
        at java.lang.Thread.run(Unknown Source) [rt.jar:1.7.0_79]
      

       

      At this point some blurry eyed support tech tried to stop JBoss but it wouldn't shutdown cleanly.  He ended up having to manually kill the process before being able to restart.  I had a similar situation happen a few months back and posted a query, but I never got a good explanation.  Since then, I upgraded to 8.0 and haven't seen that problem but now this problem has taken it's place.  This application needs to run 24X7 so we need this to be reliable. Can anyone suggest a reason why this might be happening?

       

      Thanks.

        • 1. Re: InvocationContextInterceptor - ISPN000136: Execution error: java.lang.IllegalStateException
          Pedro Ruivo Novice

          Hi Dave,

           

          The TransactionManager has a timeout and it kills the transaction if the timeout is reached. The log entry "TransactionReaper::check timeout" is doing just that.

           

          Your problem is the transactions is taking too much time to run. If it is expected the transaction to take long time to run, you should increase the timeout in TransactionManager. Check its configuration. If it supports the Transaction interface has a setTimeout().

           

          If the transaction is supposed to be short, then there is a problem somewhere. Since you are using listeners, are they synchronous? If they are, then are executed while the transaction is running and it could be the cause.

           

          Cheers,

          Pedro