[IGNITE-5759] IgniteCache 6 suite timed out by GridCachePartitionEvictionDuringReadThroughSelfTest.testPartitionRent

• Type: Bug
• Status: Resolved
• Priority: Critical
• Resolution: Fixed
• Fix Version/s: 2.8
• Labels: MakeTeamcityGreenAgain test-fail
• Assignee: Anton Kalashnikov
• Reporter: Dmitry Pavlov
• Created: 15/Jul/17 13:06
• Updated: 03/Dec/18 15:26
• Resolved: 03/Dec/18 15:25

Description

Test history:
https://ci.ignite.apache.org/project.html?projectId=IgniteTests20&testNameId=-7061194995222816963&tab=testDetails

There is no 'Test has been timed out' message in logs.
Last 'Starting test:' message was GridCachePartitionEvictionDuringReadThroughSelfTest#testPartitionRent

Latest exception from working test was as follows;

[23:19:11]W:		 [org.apache.ignite:ignite-core] [2017-07-14 20:19:11,392][ERROR][tcp-comm-worker-#8980%distributed.GridCachePartitionEvictionDuringReadThroughSelfTest4%][TcpCommunicationSpi] TcpCommunicationSpi failed to establish connection to node, node will be dropped from cluster [rmtNode=TcpDiscoveryNode [id=a93fce57-6b2d-4947-8c23-8a677b900003, addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:47503], discPort=47503, order=4, intOrder=4, lastExchangeTime=1500063443391, loc=false, ver=2.1.0#19700101-sha1:00000000, isClient=false]]
[23:19:11]W:		 [org.apache.ignite:ignite-core] class org.apache.ignite.IgniteCheckedException: Failed to connect to node (is node still alive?). Make sure that each ComputeTask and cache Transaction has a timeout set in order to prevent parties from waiting forever in case of network issues [nodeId=a93fce57-6b2d-4947-8c23-8a677b900003, addrs=[/127.0.0.1:45273]]
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.createTcpClient(TcpCommunicationSpi.java:3173)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.createNioClient(TcpCommunicationSpi.java:2757)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.reserveClient(TcpCommunicationSpi.java:2649)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.access$5900(TcpCommunicationSpi.java:245)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$CommunicationWorker.processDisconnect(TcpCommunicationSpi.java:4065)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$CommunicationWorker.body(TcpCommunicationSpi.java:3891)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.spi.IgniteSpiThread.run(IgniteSpiThread.java:62)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	Suppressed: class org.apache.ignite.IgniteCheckedException: Failed to connect to address [addr=/127.0.0.1:45273, err=Connection refused]
[23:19:11]W:		 [org.apache.ignite:ignite-core] 		at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.createTcpClient(TcpCommunicationSpi.java:3178)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 		... 6 more
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	Caused by: java.net.ConnectException: Connection refused
[23:19:11]W:		 [org.apache.ignite:ignite-core] 		at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 		at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:744)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 		at sun.nio.ch.SocketAdaptor.connect(SocketAdaptor.java:117)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 		at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.createTcpClient(TcpCommunicationSpi.java:3024)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 		... 6 more

and then

[23:19:11]W:		 [org.apache.ignite:ignite-core] [2017-07-14 20:19:11,895][WARN ][main][root] Interrupting threads started so far: 5
[23:19:11] :	 [Step 4/5] [2017-07-14 20:19:11,895][INFO ][main][root] >>> Stopping test class: GridCachePartitionEvictionDuringReadThroughSelfTest <<<
[23:19:11]W:		 [org.apache.ignite:ignite-core] [20:19:11] (err) Failed to execute compound future reducer: GridCompoundFuture [rdc=LongSumReducer [sum=0], initFlag=1, lsnrCalls=1, done=false, cancelled=false, err=null, futs=[true, true]]class org.apache.ignite.IgniteCheckedException: null
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.internal.util.IgniteUtils.cast(IgniteUtils.java:7246)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.internal.util.future.GridFutureAdapter.resolve(GridFutureAdapter.java:258)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.internal.util.future.GridFutureAdapter.get0(GridFutureAdapter.java:170)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.internal.util.future.GridFutureAdapter.get(GridFutureAdapter.java:139)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.internal.util.future.GridCompoundFuture.apply(GridCompoundFuture.java:92)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.internal.util.future.GridCompoundFuture.apply(GridCompoundFuture.java:45)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.internal.util.future.GridFutureAdapter.notifyListener(GridFutureAdapter.java:382)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.internal.util.future.GridFutureAdapter.unblock(GridFutureAdapter.java:346)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.internal.util.future.GridFutureAdapter.unblockAll(GridFutureAdapter.java:334)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:494)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:473)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.internal.util.future.GridFutureAdapter.onDone(GridFutureAdapter.java:461)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.testframework.GridTestUtils$7.run(GridTestUtils.java:919)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.testframework.GridTestUtils$9.call(GridTestUtils.java:1210)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.testframework.GridTestThread.run(GridTestThread.java:86)
[23:19:11]W:		 [org.apache.ignite:ignite-core] Caused by: java.lang.InterruptedException
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at java.lang.Object.wait(Native Method)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at java.lang.Thread.join(Thread.java:1281)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at java.lang.Thread.join(Thread.java:1355)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.testframework.GridTestUtils.runMultiThreaded(GridTestUtils.java:806)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.testframework.GridTestUtils$4.call(GridTestUtils.java:746)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.testframework.GridTestUtils$4.call(GridTestUtils.java:744)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	at org.apache.ignite.testframework.GridTestUtils$7.run(GridTestUtils.java:914)
[23:19:11]W:		 [org.apache.ignite:ignite-core] 	... 2 more

Then at 0200+ test was considered timed out

Issue Links

• relates to: IGNITE-5528 IS_EVICT_DISABLED flag is not cleared when cache store throws an exception
• links to: GitHub Pull Request #2373
• links to: GitHub Pull Request #5531