-
Bug
-
Resolution: Unresolved
-
Major
-
None
-
None
-
None
The testStatsUponRestart test now fails frequently enough but is still flaky. It appears the issue is solely with passivation when the index is not deleted.
https://ci.infinispan.org/job/Infinispan/job/main/1444/
java.lang.AssertionError: Restart attempt: 3 expected:<697> but was:<660> at org.infinispan.persistence.sifs.SoftIndexFileStoreRestartTest.performRestart(SoftIndexFileStoreRestartTest.java:208) at org.infinispan.persistence.sifs.SoftIndexFileStoreRestartTest.testStatsUponRestart(SoftIndexFileStoreRestartTest.java:176) at org.infinispan.commons.test.TestNGLongTestsHook.run(TestNGLongTestsHook.java:24) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) at java.base/java.lang.Thread.run(Thread.java:1583) ... Removed 20 stack frames
It appears the cause is related to passivation not updating the store in a prompt manner before shutdown.
Unfortunately, enabling TRACE does not allow the issue to be reproduced, but DEBUG will still do so and we can see the following difference between runs:
When it works
07:42:58,767 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 0 Length: 1030 free: 370 07:42:59,174 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 0 Length: 1030 free: 436 07:42:59,174 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 1 Length: 103 free: 37 07:42:59,550 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 0 Length: 1030 free: 502 07:42:59,550 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 1 Length: 103 free: 37 07:42:59,550 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 2 Length: 103 free: 37 07:42:59,915 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 1 Length: 103 free: 37 07:42:59,915 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 2 Length: 103 free: 37 07:42:59,915 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 3 Length: 103 free: 37 07:42:59,915 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 4 Length: 462 free: 0
When it doesn't work
22:00:06,513 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 0 Length: 1030 free: 333 22:00:06,680 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 0 Length: 1030 free: 399 22:00:06,680 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 1 Length: 103 free: 37 22:00:06,835 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 0 Length: 1030 free: 465 22:00:06,835 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 1 Length: 103 free: 37 22:00:06,835 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 2 Length: 103 free: 37 22:00:06,991 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 1 Length: 103 free: 37 22:00:06,991 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 2 Length: 103 free: 37 22:00:06,991 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 3 Length: 103 free: 37 22:00:06,991 DEBUG (testng-SoftIndexFileStoreRestartTest:[]) [o.i.t.AbstractInfinispanTest] File: 4 Length: 462 free: 0
As you can see the first iteration the free size is not correct after shutdown for some reason. This is much more likely to happen to a LOCAL cache as well.