[infinispan-issues] [JBoss JIRA] (ISPN-11422) ClusterExpirationFunctionalTest.testWriteExpiredEntry random failures
Dan Berindei (Jira)
issues at jboss.org
Wed Mar 4 08:59:54 EST 2020
[ https://issues.redhat.com/browse/ISPN-11422?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Dan Berindei updated ISPN-11422:
--------------------------------
Status: Open (was: New)
> ClusterExpirationFunctionalTest.testWriteExpiredEntry random failures
> ---------------------------------------------------------------------
>
> Key: ISPN-11422
> URL: https://issues.redhat.com/browse/ISPN-11422
> Project: Infinispan
> Issue Type: Bug
> Components: Core, Test Suite
> Affects Versions: 11.0.0.Alpha2
> Reporter: Dan Berindei
> Assignee: Will Burns
> Priority: Major
> Labels: testsuite_stability
> Fix For: 11.0.0.Final
>
> Attachments: ISPN-11367_default_configuration_20200301-2115_ClusterExpirationFunctionalTest-infinispan-core.log.gz
>
>
> {noformat}
> 21:20:48,799 TRACE (testng-Test:[]) [InvocationContextInterceptor] Invoked with command PutKeyValueCommand{key=key, value=value, flags=[], commandInvocationId=CommandInvocation:Test-NodeA:15530, putIfAbsent=true, valueMatcher=MATCH_EXPECTED, metadata=EmbeddedExpirableMetadata{version=null, lifespan=1000, maxIdle=-1}, successful=true, topologyId=-1} and InvocationContext [SingleKeyNonTxInvocationContext{isLocked=false, key=null, cacheEntry=null, origin=null, lockOwner=CommandInvocation:Test-NodeA:15530}]
> 21:20:48,800 TRACE (jgroups-5,Test-NodeA:[]) [TriangleDistributionInterceptor] Command CommandInvocation:Test-NodeA:15530 send to backup owner [Test-NodeB].
> 21:20:48,800 TRACE (jgroups-5,Test-NodeA:[]) [TriangleDistributionInterceptor] Command CommandInvocation:Test-NodeA:15530 got sequence 56 for segment 99
> 21:20:48,801 TRACE (jgroups-6,Test-NodeB:[]) [TriangleOrderManager] Receiver old topology. Current sequence (27:56), command sequence (27:56)
> 21:20:48,802 TRACE (remote-thread-Test-NodeB-p15169-t1:[]) [ClusterExpirationManager] Submitting expiration removal for key: key which is maxIdle: false of: 1000
> 21:20:48,802 TRACE (remote-thread-Test-NodeB-p15169-t1:[]) [CommandAckCollector] Created new collector for 15533. BackupOwners=[Test-NodeB]
> 21:20:48,802 TRACE (remote-thread-Test-NodeB-p15169-t1:[]) [JGroupsTransport] Test-NodeB sending single request 48 to Test-NodeA: SingleRpcCommand{cacheName='defaultcache', command=RemoveExpiredCommand{key=key, value=value, lifespan=1000, maxIde=false}}
> 21:20:48,803 TRACE (remote-thread-Test-NodeA-p15163-t3:[]) [TriangleDistributionInterceptor] Command CommandInvocation:Test-NodeB:15533 got sequence 57 for segment 99
> 21:20:48,804 TRACE (jgroups-5,Test-NodeB:[]) [CommandAckCollector] Pending backup acks: [Test-NodeB]
> 21:20:48,804 TRACE (jgroups-6,Test-NodeB:[]) [TriangleOrderAction] Checking if next for segment 99 and sequence 57
> 21:20:48,804 TRACE (jgroups-6,Test-NodeB:[]) [TriangleOrderManager] Receiver old topology. Current sequence (27:56), command sequence (27:57)
> 21:20:48,804 TRACE (Controller-remote-thread-Test-NodeB:[]) [TriangleOrderManager] Receiver old topology. Current sequence (27:56), command sequence (27:57)
> 21:20:48,804 TRACE (Controller-remote-thread-Test-NodeB:[]) [BlockingTaskAwareExecutorServiceImpl] Tasks to be executed=0, still pending=~1
> 21:21:03,801 ERROR (timeout-thread-Test-NodeA-p15164-t1:[]) [InvocationContextInterceptor] ISPN000136: Error executing command PutKeyValueCommand on Cache 'defaultcache', writing keys [key]
> org.infinispan.util.concurrent.TimeoutException: ISPN000427: Timeout after 15 seconds waiting for acks. Id=15530
> 21:21:03,805 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.expiration.impl.ClusterExpirationFunctionalTest.testWriteExpiredEntry[DIST_SYNC, tx=false, storageType=OBJECT]
> org.infinispan.util.concurrent.TimeoutException: ISPN000427: Timeout after 15 seconds waiting for acks. Id=15530
> at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:255) ~[classes/:?]
> at org.infinispan.cache.impl.InvocationHelper.doInvoke(InvocationHelper.java:296) ~[classes/:?]
> at org.infinispan.cache.impl.InvocationHelper.invoke(InvocationHelper.java:100) ~[classes/:?]
> at org.infinispan.cache.impl.InvocationHelper.invoke(InvocationHelper.java:82) ~[classes/:?]
> at org.infinispan.cache.impl.CacheImpl.putIfAbsent(CacheImpl.java:1331) ~[classes/:?]
> at org.infinispan.cache.impl.CacheImpl.putIfAbsent(CacheImpl.java:1325) ~[classes/:?]
> at org.infinispan.cache.impl.CacheImpl.putIfAbsent(CacheImpl.java:1321) ~[classes/:?]
> at org.infinispan.cache.impl.CacheImpl.putIfAbsent(CacheImpl.java:232) ~[classes/:?]
> at org.infinispan.cache.impl.AbstractDelegatingCache.putIfAbsent(AbstractDelegatingCache.java:127) ~[classes/:?]
> at org.infinispan.cache.impl.EncoderCache.putIfAbsent(EncoderCache.java:215) ~[classes/:?]
> at org.infinispan.expiration.impl.ClusterExpirationFunctionalTest.testWriteExpiredEntry(ClusterExpirationFunctionalTest.java:374) ~[test-classes/:?]
> at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
> at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
> at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
> at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
> at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:124) ~[testng-6.14.3.jar:?]
> at org.testng.internal.MethodInvocationHelper$1.runTestMethod(MethodInvocationHelper.java:230) ~[testng-6.14.3.jar:?]
> at org.infinispan.commons.test.TestNGLongTestsHook.run(TestNGLongTestsHook.java:24) ~[infinispan-commons-test-11.0.0-SNAPSHOT.jar:11.0.0-SNAPSHOT]
> at org.testng.internal.MethodInvocationHelper.invokeHookable(MethodInvocationHelper.java:242) ~[testng-6.14.3.jar:?]
> at org.testng.internal.Invoker.invokeMethod(Invoker.java:579) [testng-6.14.3.jar:?]
> at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:719) [testng-6.14.3.jar:?]
> at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:989) [testng-6.14.3.jar:?]
> at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:125) [testng-6.14.3.jar:?]
> at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:109) [testng-6.14.3.jar:?]
> at org.testng.TestRunner.privateRun(TestRunner.java:648) [testng-6.14.3.jar:?]
> at org.testng.TestRunner.run(TestRunner.java:505) [testng-6.14.3.jar:?]
> at org.testng.SuiteRunner.runTest(SuiteRunner.java:455) [testng-6.14.3.jar:?]
> at org.testng.SuiteRunner.access$000(SuiteRunner.java:40) [testng-6.14.3.jar:?]
> at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:489) [testng-6.14.3.jar:?]
> at org.testng.internal.thread.ThreadUtil$1.call(ThreadUtil.java:52) [testng-6.14.3.jar:?]
> at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
> at java.lang.Thread.run(Thread.java:834) [?:?]
> Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000427: Timeout after 15 seconds waiting for acks. Id=15530
> at org.infinispan.util.concurrent.CommandAckCollector.createTimeoutException(CommandAckCollector.java:222) ~[classes/:?]
> at org.infinispan.util.concurrent.CommandAckCollector.access$700(CommandAckCollector.java:58) ~[classes/:?]
> at org.infinispan.util.concurrent.CommandAckCollector$BaseCollector.call(CommandAckCollector.java:275) ~[classes/:?]
> at org.infinispan.util.concurrent.CommandAckCollector$BaseCollector.call(CommandAckCollector.java:255) ~[classes/:?]
> at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
> ... 3 more
> Suppressed: org.infinispan.util.logging.TraceException
> at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:39) ~[classes/:?]
> at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:246) ~[classes/:?]
> at org.infinispan.cache.impl.InvocationHelper.doInvoke(InvocationHelper.java:296) ~[classes/:?]
> at org.infinispan.cache.impl.InvocationHelper.invoke(InvocationHelper.java:100) ~[classes/:?]
> at org.infinispan.cache.impl.InvocationHelper.invoke(InvocationHelper.java:82) ~[classes/:?]
> at org.infinispan.cache.impl.CacheImpl.putIfAbsent(CacheImpl.java:1331) ~[classes/:?]
> at org.infinispan.cache.impl.CacheImpl.putIfAbsent(CacheImpl.java:1325) ~[classes/:?]
> at org.infinispan.cache.impl.CacheImpl.putIfAbsent(CacheImpl.java:1321) ~[classes/:?]
> at org.infinispan.cache.impl.CacheImpl.putIfAbsent(CacheImpl.java:232) ~[classes/:?]
> at org.infinispan.cache.impl.AbstractDelegatingCache.putIfAbsent(AbstractDelegatingCache.java:127) ~[classes/:?]
> at org.infinispan.cache.impl.EncoderCache.putIfAbsent(EncoderCache.java:215) ~[classes/:?]
> at org.infinispan.expiration.impl.ClusterExpirationFunctionalTest.testWriteExpiredEntry(ClusterExpirationFunctionalTest.java:374) ~[test-classes/:?]
> at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
> at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
> at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
> at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
> at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:124) ~[testng-6.14.3.jar:?]
> at org.testng.internal.MethodInvocationHelper$1.runTestMethod(MethodInvocationHelper.java:230) ~[testng-6.14.3.jar:?]
> at org.infinispan.commons.test.TestNGLongTestsHook.run(TestNGLongTestsHook.java:24) ~[infinispan-commons-test-11.0.0-SNAPSHOT.jar:11.0.0-SNAPSHOT]
> at org.testng.internal.MethodInvocationHelper.invokeHookable(MethodInvocationHelper.java:242) ~[testng-6.14.3.jar:?]
> at org.testng.internal.Invoker.invokeMethod(Invoker.java:579) [testng-6.14.3.jar:?]
> at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:719) [testng-6.14.3.jar:?]
> at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:989) [testng-6.14.3.jar:?]
> at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:125) [testng-6.14.3.jar:?]
> at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:109) [testng-6.14.3.jar:?]
> at org.testng.TestRunner.privateRun(TestRunner.java:648) [testng-6.14.3.jar:?]
> at org.testng.TestRunner.run(TestRunner.java:505) [testng-6.14.3.jar:?]
> at org.testng.SuiteRunner.runTest(SuiteRunner.java:455) [testng-6.14.3.jar:?]
> at org.testng.SuiteRunner.access$000(SuiteRunner.java:40) [testng-6.14.3.jar:?]
> at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:489) [testng-6.14.3.jar:?]
> at org.testng.internal.thread.ThreadUtil$1.call(ThreadUtil.java:52) [testng-6.14.3.jar:?]
> at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
> at java.lang.Thread.run(Thread.java:834) [?:?]
> {noformat}
> Looks like a deadlock: the {{RemoveExpiredCommand}} can't run on backup B because the sequence number is still 56 (the seqno of the {{PutKeyValueCommand}}).
--
This message was sent by Atlassian Jira
(v7.13.8#713008)
More information about the infinispan-issues
mailing list