1 Reply Latest reply on Sep 21, 2017 12:02 PM by Zefa Guan

    Infinispan 8.2.4.Final - TimeoutException: ISPN000299: Unable to acquire lock after 2 seconds for key & ISPN000136: Error executing command PutKeyValueCommand, writing keys

    Zefa Guan Newbie

      I have 3 tomcat under 3 different VMs, the web app under each tomcat is using Infinispan 8.2.4.Final as embedded mode, distributed cache, owners = 3, by putAsync

      I got 3 kinds of exception when put item volume grew

      1)  org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 2 seconds for key

      I can see the key had been locked by another requestor, as the key had been put by putAsync, it should be handled by thread pool instead of current thread

      from exception trace, ‘ThreadPoolExecutor.execute’ , I guess the capacity of theadpool has been reached, so it got rejected, then current thread continue handling the put command, waiting for other requestor releasing the lock but timeout (2s),

      is my understanding correct?

      2)  ISPN000136: Error executing command PutKeyValueCommand, writing keys

      putAsync by thread: http-nio-8081-exec-19368

      scheduled by thread: http-nio-8081-exec-19373

      timeout and output by thread: http-nio-8081-exec-19373

      I may collect the incorrect putAsync thread, but I am confused by 'scheduled thread and current thead are sync instead of aysnc '

      3)  ISPN000136: Error executing command PutKeyValueCommand, writing keys

      putAsync by thread: http-nio-8081-exec-19245

      scheduled by thread: http-nio-8081-exec-19245

      timeout and output by thread: http-nio-8081-exec-19245

      almost same with 2), but putAsync thread is same with schedule and timeout output thread

       

      regarding 2) and 3), what is the scenario that scheduling pool used request(current) thread but thread pool?

       

      regarding  those TimeoutException for growing volume, which conf item I can change to avoid it?

       

      exception type 1)

      ----------------------------------------------------------------------------------------------------------------------------------------

      [2017-09-16_19:16:25:781] - [00016171] [DEBUG] - com.test.it.common.framework.service.cache.CacheManagerService.put(CacheManagerService.java:82)http-nio-8081-exec-19369 - |cacheName|idatasaas|key|app_000000000414&_&pro&_&app_0000000000011111&_&-945774822

      [2017-09-16_19:16:25:781] - [00016171] [DEBUG] - com.test.engine.distributedcache.impl.AppDistributedCache.put(AppDistributedCache.java:390)http-nio-8081-exec-19369 - [put] cacheName = idatasaas, key = app_000000000414&_&pro&_&app_0000000000011111&_&-945774822

       

       

      [2017-09-16_19:16:27:783] - [00016171] [ERROR] - org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:140)http-nio-8081-exec-19369 - ISPN000136: Error executing command PutKeyValueCommand, writing keys [app_000000000414&_&pro&_&app_0000000000011111&_&-945774822]

      org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 2 seconds for key app_000000000414&_&pro&_&app_0000000000011111&_&-945774822 and requestor CommandUUID{address=localhost-20832, id=1281042}. Lock is held by CommandUUID{address=localhost-20832, id=1279322}

      at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:238) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockAndRecord(AbstractLockingInterceptor.java:193) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitNonTxDataWriteCommand(AbstractLockingInterceptor.java:98) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.locking.NonTransactionalLockingInterceptor.visitDataWriteCommand(NonTransactionalLockingInterceptor.java:41) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:65) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:78) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.statetransfer.StateTransferInterceptor.handleNonTxWriteCommand(StateTransferInterceptor.java:349) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:281) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:107) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:78) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.CacheMgmtInterceptor.updateStoreStatistics(CacheMgmtInterceptor.java:191) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:177) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:78) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:114) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:83) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:43) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:78) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:99) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:113) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:43) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:78) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:335) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.cache.impl.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1672) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.cache.impl.CacheImpl.putInternal(CacheImpl.java:1121) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.cache.impl.CacheImpl.access$100(CacheImpl.java:128) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.cache.impl.CacheImpl$2.call(CacheImpl.java:1280) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_91]

      at java.util.concurrent.ThreadPoolExecutor$CallerRunsPolicy.rejectedExecution(ThreadPoolExecutor.java:2022) [?:1.8.0_91]

      at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823) [?:1.8.0_91]

      at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369) [?:1.8.0_91]

      at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:134) [?:1.8.0_91]

      at org.infinispan.executors.LazyInitializingExecutorService.submit(LazyInitializingExecutorService.java:79) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.cache.impl.CacheImpl.putAsync(CacheImpl.java:1275) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.cache.impl.CacheImpl.putAsync(CacheImpl.java:1775) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.cache.impl.CacheImpl.putAsync(CacheImpl.java:293) [infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at com.test.engine.distributedcache.impl.AppDistributedCache.put(AppDistributedCache.java:452) [DistributeCache-Core-1.5.0.05.RELEASE.jar:?]

      at com.test.engine.distributedcache.impl.AppDistributedCache.put(AppDistributedCache.java:395) [DistributeCache-Core-1.5.0.05.RELEASE.jar:?]

      at com.test.engine.distributedcache.impl.AppDistributedCacheImpl.put(AppDistributedCacheImpl.java:55) [DistributeCache-Core-1.5.0.05.RELEASE.jar:?]

      at com.test.it.common.framework.service.cache.impl.DistributedLocalCacheProvider.put(DistributedLocalCacheProvider.java:123) [FrameworkService-Release_1.1.68.5.jar:Release_1.1.68.5]

      at com.test.it.common.framework.service.cache.impl.DistributedCacheProvider.put(DistributedCacheProvider.java:53) [FrameworkService-Release_1.1.68.5.jar:Release_1.1.68.5]

      at com.test.it.common.framework.service.cache.CacheManagerService.put(CacheManagerService.java:83) [FrameworkService-Release_1.1.68.5.jar:Release_1.1.68.5]

      at com.test.it.common.saas.idata.util.CacheManger.put(CacheManger.java:49) [iDataSaasBase-1.1.2.jar:?]

      at com.test.it.common.saas.idata.biz.W3AccountService.getW3Account(W3AccountService.java:130) [iDataSaasMHRR002Core-1.0.00.jar:?]

      at com.test.it.common.saas.idata.biz.PersonBatchService.getBatchPersonInfo(PersonBatchService.java:103) [iDataSaasMHRR002Core-1.0.00.jar:?]

      at sun.reflect.GeneratedMethodAccessor477.invoke(Unknown Source) ~[?:?]

      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_91]

      at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_91]

      at com.test.it.common.saas.idata.util.BizCommonUtil.callServiceByMethodName(BizCommonUtil.java:217) [iDataSaasBase-1.1.2.jar:?]

      at com.test.it.common.saas.idata.util.BizCommonUtil.defaultServiceInvoke(BizCommonUtil.java:182) [iDataSaasBase-1.1.2.jar:?]

      at com.test.it.common.saas.idatasaasmhrr002.service.iDataSaasMHRR002Service.execute(iDataSaasMHRR002Service.java:73) [iDataSaasMHRR002Core-1.0.00.jar:?]

      at com.test.it.common.framework.service.impl.CommonWSImpl.invoke(CommonWSImpl.java:411) [FrameworkService-Release_1.1.68.5.jar:Release_1.1.68.5]

      at com.test.it.common.framework.service.impl.CommonWSImpl.execute(CommonWSImpl.java:178) [FrameworkService-Release_1.1.68.5.jar:Release_1.1.68.5]

      at com.test.it.common.saas.idatasaasmhrr002.impl.iDataSaasMHRR002.executeTokenNoTransNoEncrypt(iDataSaasMHRR002.java:64) [classes/:?]

      at sun.reflect.GeneratedMethodAccessor134.invoke(Unknown Source) ~[?:?]

      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_91]

      at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_91]

      at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:180) [cxf-core-3.1.4.jar:3.1.4]

      at org.apache.cxf.jaxws.JAXWSMethodInvoker.performInvocation(JAXWSMethodInvoker.java:66) [cxf-rt-frontend-jaxws-3.1.4.jar:3.1.4]

      at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:96) [cxf-core-3.1.4.jar:3.1.4]

      at org.apache.cxf.jaxws.AbstractJAXWSMethodInvoker.invoke(AbstractJAXWSMethodInvoker.java:232) [cxf-rt-frontend-jaxws-3.1.4.jar:3.1.4]

      at org.apache.cxf.jaxws.JAXWSMethodInvoker.invoke(JAXWSMethodInvoker.java:85) [cxf-rt-frontend-jaxws-3.1.4.jar:3.1.4]

      at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:74) [cxf-core-3.1.4.jar:3.1.4]

      at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59) [cxf-core-3.1.4.jar:3.1.4]

      at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_91]

      at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_91]

      at org.apache.cxf.interceptor.ServiceInvokerInterceptor$2.run(ServiceInvokerInterceptor.java:126) [cxf-core-3.1.4.jar:3.1.4]

      at org.apache.cxf.workqueue.SynchronousExecutor.execute(SynchronousExecutor.java:37) [cxf-core-3.1.4.jar:3.1.4]

      at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:131) [cxf-core-3.1.4.jar:3.1.4]

      at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) [cxf-core-3.1.4.jar:3.1.4]

      at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) [cxf-core-3.1.4.jar:3.1.4]

      at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:251) [cxf-rt-transports-http-3.1.4.jar:3.1.4]

      at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:234) [cxf-rt-transports-http-3.1.4.jar:3.1.4]

      at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:208) [cxf-rt-transports-http-3.1.4.jar:3.1.4]

      at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:160) [cxf-rt-transports-http-3.1.4.jar:3.1.4]

      at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:180) [cxf-rt-transports-http-3.1.4.jar:3.1.4]

      at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:293) [cxf-rt-transports-http-3.1.4.jar:3.1.4]

      at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:212) [cxf-rt-transports-http-3.1.4.jar:3.1.4]

      at javax.servlet.http.HttpServlet.service(HttpServlet.java:648) [servlet-api.jar:?]

      at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:268) [cxf-rt-transports-http-3.1.4.jar:3.1.4]

      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292) [catalina.jar:8.0.35]

      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207) [catalina.jar:8.0.35]

      at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) [tomcat-websocket.jar:8.0.35]

      at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240) [catalina.jar:8.0.35]

      at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207) [catalina.jar:8.0.35]

      at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:212) [catalina.jar:8.0.35]

      at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106) [catalina.jar:8.0.35]

      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502) [catalina.jar:8.0.35]

      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141) [catalina.jar:8.0.35]

      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) [catalina.jar:8.0.35]

      at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:616) [catalina.jar:8.0.35]

      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88) [catalina.jar:8.0.35]

      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:528) [catalina.jar:8.0.35]

      at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1099) [tomcat-coyote.jar:8.0.35]

      at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:672) [tomcat-coyote.jar:8.0.35]

      at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1520) [tomcat-coyote.jar:8.0.35]

      at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1476) [tomcat-coyote.jar:8.0.35]

      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_91]

      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_91]

      at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:8.0.35]

      at java.lang.Thread.run(Thread.java:745) [?:1.8.0_91]

      [2017-09-16_19:16:27:793] - [00016171] [DEBUG] - com.test.engine.distributedcache.impl.AppDistributedCache.put(AppDistributedCache.java:453)http-nio-8081-exec-19369 - NOT USING_COMPRESS, key = app_000000000414&_&pro&_&app_0000000000011111&_&-945774822 ,Async, cost time:2012 ms

       

       

      exception type 2)

      ----------------------------------------------------------------------------------------------------------------------------------------

      [2017-09-16_19:16:23:863] - [00016170] [DEBUG] - com.test.engine.distributedcache.impl.AppDistributedCache.put(AppDistributedCache.java:390)http-nio-8081-exec-19368 - [put] cacheName = idatasaas, key = test.paas.portal&_&pro&_&app_0000000000011111&_&922309117

       

       

      [2017-09-16_19:16:37:434] - [00016175] [ERROR] - org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:140)http-nio-8081-exec-19373 - ISPN000136: Error executing command PutKeyValueCommand, writing keys [test.paas.portal&_&pro&_&app_0000000000011111&_&922309117]

      org.infinispan.util.concurrent.TimeoutException: Replication timeout for dggmwc6tmc035-48913

      at org.infinispan.remoting.transport.jgroups.JGroupsTransport.checkRsp(JGroupsTransport.java:801) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.remoting.transport.jgroups.JGroupsTransport.lambda$invokeRemotelyAsync$0(JGroupsTransport.java:629) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602) ~[?:1.8.0_91]

      at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577) ~[?:1.8.0_91]

      at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) ~[?:1.8.0_91]

      at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962) ~[?:1.8.0_91]

      at org.infinispan.remoting.transport.jgroups.SingleResponseFuture.call(SingleResponseFuture.java:46) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.remoting.transport.jgroups.SingleResponseFuture.call(SingleResponseFuture.java:17) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_91]

      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_91]

      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:1.8.0_91]

      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[?:1.8.0_91]

      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[?:1.8.0_91]

      at java.lang.Thread.run(Thread.java:745) [?:1.8.0_91]

      [2017-09-16_19:16:37:442] - [00016175] [DEBUG] - com.test.engine.distributedcache.impl.AppDistributedCache.put(AppDistributedCache.java:453)http-nio-8081-exec-19373 - NOT USING_COMPRESS, key = test.paas.portal&_&pro&_&app_0000000000011111&_&922309117 ,Async, cost time:15009 ms

       

       

      exception type 3)

      ----------------------------------------------------------------------------------------------------------------------------------------

      [2017-09-16_19:16:03:944] - [000160e0] [DEBUG] - com.test.engine.distributedcache.impl.AppDistributedCache.put(AppDistributedCache.java:390)http-nio-8081-exec-19245 - [put] cacheName = idatasaas, key = app_000000000414&_&pro&_&app_0000000000011111&_&1863878812

       

       

      [2017-09-16_19:16:18:946] - [000160e0] [ERROR] - org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:140)http-nio-8081-exec-19245 - ISPN000136: Error executing command PutKeyValueCommand, writing keys [app_000000000414&_&pro&_&app_0000000000011111&_&1863878812]

      org.infinispan.util.concurrent.TimeoutException: Replication timeout for dggmwc6tmc035-48913

      at org.infinispan.remoting.transport.jgroups.JGroupsTransport.checkRsp(JGroupsTransport.java:801) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.remoting.transport.jgroups.JGroupsTransport.lambda$invokeRemotelyAsync$0(JGroupsTransport.java:629) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602) ~[?:1.8.0_91]

      at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577) ~[?:1.8.0_91]

      at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) ~[?:1.8.0_91]

      at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962) ~[?:1.8.0_91]

      at org.infinispan.remoting.transport.jgroups.SingleResponseFuture.call(SingleResponseFuture.java:46) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at org.infinispan.remoting.transport.jgroups.SingleResponseFuture.call(SingleResponseFuture.java:17) ~[infinispan-embedded-8.2.4.Final.jar:8.2.4.Final]

      at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_91]

      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_91]

      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:1.8.0_91]

      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[?:1.8.0_91]

      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[?:1.8.0_91]

      at java.lang.Thread.run(Thread.java:745) [?:1.8.0_91]

      [2017-09-16_19:16:18:955] - [000160e0] [DEBUG] - com.test.engine.distributedcache.impl.AppDistributedCache.put(AppDistributedCache.java:453)http-nio-8081-exec-19245 - NOT USING_COMPRESS, key = app_000000000414&_&pro&_&app_0000000000011111&_&1863878812 ,Async, cost time:15010 ms

        • 1. Re: Infinispan 8.2.4.Final - TimeoutException: ISPN000299: Unable to acquire lock after 2 seconds for key & ISPN000136: Error executing command PutKeyValueCommand, writing keys
          Zefa Guan Newbie

          infinispan.xml

           

          <?xml version="1.0" encoding="UTF-8"?>

          <infinispan>

            <jgroups>

               <stack-file name="stack" path="jgroups-tcp.xml" />

            </jgroups>

            <cache-container default-cache="default" statistics="true">

               <transport stack="stack" cluster="my_cluster" />

               <replicated-cache name="CacheTemplate" mode="SYNC" statistics="true" />

               <!-- <distributed-cache name="CacheTemplate" mode="SYNC" owners="2" />-->

            </cache-container>

          </infinispan>

           

          jgroups-tcp.xml

           

          <!--

              TCP based stack, with flow control and message bundling. This is usually used when IP

              multicasting cannot be used in a network, e.g. because it is disabled (routers discard multicast).

              Note that TCP.bind_addr and TCPPING.initial_hosts should be set, possibly via system properties, e.g.

              -Djgroups.bind_addr=192.168.5.2 and -Djgroups.tcpping.initial_hosts=192.168.5.2[7800]

              author: Bela Ban

          -->

          <config xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"

                  xmlns="urn:org:jgroups"

                  xsi:schemaLocation="urn:org:jgroups http://www.jgroups.org/schema/jgroups.xsd">

              <TCP bind_addr="${jgroups.tcp.address:192.168.43.29}"

                   bind_port="${jgroups.tcp.port:7800}"

                   port_range="10" recv_buf_size="200000000"

                   send_buf_size="6400000" loopback="false" max_bundle_size="64K"

                   bundler_type="sender-sends-with-timer" enable_diagnostics="true"

                   thread_naming_pattern="cl" timer_type="new" timer.min_threads="4"

                   timer.max_threads="10" timer.keep_alive_time="3000"

                   timer.queue_max_size="1000" timer.wheel_size="200" timer.tick_time="50"

                 

                   thread_pool.enabled="true" thread_pool.min_threads="2"

                   thread_pool.max_threads="8" thread_pool.keep_alive_time="5000"

                   thread_pool.queue_enabled="true" thread_pool.queue_max_size="1000"

                   thread_pool.rejection_policy="discard"  oob_thread_pool.enabled="true"

                   oob_thread_pool.min_threads="1" oob_thread_pool.max_threads="8"

                   oob_thread_pool.keep_alive_time="5000" oob_thread_pool.queue_enabled="false"

                   oob_thread_pool.queue_max_size="100" oob_thread_pool.rejection_policy="discard"/>

                                 

              <TCPPING async_discovery="true"

                       initial_hosts="${jgroups.tcpping.initial_hosts:192.168.43.29[7800],192.168.80.101[7800],192.168.80.102[7800]}"

                       port_range="2"/>

                     

              <MERGE3 />

            

              <FD_SOCK/>

              <FD timeout="3000" max_tries="3" />

              <VERIFY_SUSPECT timeout="1500"  />

              <BARRIER />

              <pbcast.NAKACK2 use_mcast_xmit="false"

                             discard_delivered_msgs="true"/>

              <UNICAST3 />

              <pbcast.STABLE stability_delay="1000" desired_avg_gossip="50000"

                             max_bytes="4M"/>

              <pbcast.GMS print_local_addr="true" join_timeout="2000"

                          view_bundling="true"/>

              <MFC max_credits="2M"

                   min_threshold="0.4"/>

              <FRAG2 frag_size="60K"  />

              <!--RSVP resend_interval="2000" timeout="10000"/-->

              <pbcast.STATE_TRANSFER/>

          </config>

           

          EmbeddedCache.java

           

          package com.test;

           

           

          import java.io.IOException;

           

           

          import org.infinispan.Cache;

          import org.infinispan.configuration.cache.AsyncConfigurationBuilder;

          import org.infinispan.configuration.cache.CacheMode;

          import org.infinispan.configuration.cache.Configuration;

          import org.infinispan.configuration.cache.ConfigurationBuilder;

          import org.infinispan.configuration.cache.EvictionConfigurationBuilder;

          import org.infinispan.configuration.cache.HashConfigurationBuilder;

          import org.infinispan.configuration.cache.LockingConfigurationBuilder;

          import org.infinispan.manager.DefaultCacheManager;

          import org.infinispan.manager.EmbeddedCacheManager;

          import org.infinispan.transaction.TransactionMode;

          import org.infinispan.util.concurrent.IsolationLevel;

           

           

          public class EmbeddedCache {

           

           

          private static EmbeddedCacheManager manager;

          private static Cache<String, String> cache;

           

           

          static {

           

          try {

          manager = new DefaultCacheManager("infinispan.xml");

          Configuration rc = manager.getCacheConfiguration("CacheTemplate");

          ConfigurationBuilder builder = new ConfigurationBuilder().read(rc);

          AsyncConfigurationBuilder async = builder.clustering().cacheMode(CacheMode.DIST_ASYNC).async();

          HashConfigurationBuilder hashBuilder = async.l1().enable().lifespan(1000000).hash().numOwners(3);

          LockingConfigurationBuilder lockBuilder = hashBuilder.locking().isolationLevel(IsolationLevel.READ_COMMITTED).lockAcquisitionTimeout(2000).concurrencyLevel(1000).useLockStriping(false);

          EvictionConfigurationBuilder eviBuilder = lockBuilder.transaction().transactionMode(TransactionMode.NON_TRANSACTIONAL).eviction();

           

          Configuration c = eviBuilder.build();

           

          String newCacheName = "myCache";

          manager.defineConfiguration(newCacheName, c);

          cache = manager.getCache(newCacheName);

          } catch (IOException e) {

          e.printStackTrace();

          }

           

           

          }

           

           

          public static void put(String key, String value) {

          cache.put(key, value);

          }

           

           

          public static void putAsync(String key, String value) {

          cache.putAsync(key, value);

          }

           

          public static String get(String key) {

          return cache.get(key);

          }

           

           

          }