Yakov Zhdanov created IGNITE-739:
------------------------------------
Summary:
org.apache.ignite.internal.processors.cache.GridCacheTcpClientDiscoveryMultiThreadedTest#testCacheWithServerNodesRestart
fails
Key: IGNITE-739
URL: https://issues.apache.org/jira/browse/IGNITE-739
Project: Ignite
Issue Type: Sub-task
Reporter: Yakov Zhdanov
Assignee: Valentin Kulichenko
Priority: Blocker
Fix For: sprint-3-p1
branch - ignite-709
{code}
[19:22:30,751][INFO ][test-runner][GridDiscoveryManager] Topology snapshot
[ver=3, nodes=3, CPUs=8, heap=3.0GB]
[19:22:30,751][INFO
][preloader-demand-worker-#1406%cache.GridCacheTcpClientDiscoveryMultiThreadedTest2%][GridDhtPreloader]
<default> Completed rebalancing in ASYNC mode [cache=null, time=21 ms]
[19:22:30,751][WARN ][test-runner][root] Grid size is incorrect (will re-run
check in 1000 ms) [name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest0,
size=3]
[19:22:31,752][WARN ][test-runner][root] Grid size is incorrect (will re-run
check in 1000 ms) [name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest0,
size=3]
[19:22:32,083][INFO
][disco-event-worker-#1259%cache.GridCacheTcpClientDiscoveryMultiThreadedTest0%][GridDiscoveryManager]
Added new node to topology: TcpDiscoveryNode
[id=63f10757-ed70-43b8-8331-0e386217e72f, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:0], discPort=0, order=5, intOrder=5, loc=false,
ver=1.0.0#19700101-sha1:00000000, isClient=true]
[19:22:32,083][INFO
][disco-event-worker-#1259%cache.GridCacheTcpClientDiscoveryMultiThreadedTest0%][GridDiscoveryManager]
Topology snapshot [ver=6, nodes=4, CPUs=8, heap=3.0GB]
[19:22:32,084][ERROR][tcp-client-disco-msg-worker-#269%cache.GridCacheTcpClientDiscoveryMultiThreadedTest3][TcpClientDiscoverySpi]
Runtime error caught during grid runnable execution: IgniteSpiThread
[name=tcp-client-disco-msg-worker-#269%cache.GridCacheTcpClientDiscoveryMultiThreadedTest3]
java.lang.AssertionError: lastVer=3, newVer=5
at
org.apache.ignite.spi.discovery.tcp.TcpClientDiscoverySpi$MessageWorker.updateTopologyHistory(TcpClientDiscoverySpi.java:1268)
at
org.apache.ignite.spi.discovery.tcp.TcpClientDiscoverySpi$MessageWorker.processNodeAddFinishedMessage(TcpClientDiscoverySpi.java:954)
at
org.apache.ignite.spi.discovery.tcp.TcpClientDiscoverySpi$MessageWorker.processMessage(TcpClientDiscoverySpi.java:861)
at
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiAdapter$MessageWorkerAdapter.body(TcpDiscoverySpiAdapter.java:983)
at org.apache.ignite.spi.IgniteSpiThread.run(IgniteSpiThread.java:62)
[19:22:32,084][WARN
][disco-event-worker-#1259%cache.GridCacheTcpClientDiscoveryMultiThreadedTest0%][GridDiscoveryManager]
Node FAILED: TcpDiscoveryNode [id=63f10757-ed70-43b8-8331-0e386217e72f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:0], discPort=0, order=5, intOrder=5,
loc=false, ver=1.0.0#19700101-sha1:00000000, isClient=true]
[19:22:32,089][WARN
][disco-event-worker-#1323%cache.GridCacheTcpClientDiscoveryMultiThreadedTest1%][GridDiscoveryManager]
Node FAILED: TcpDiscoveryNode [id=63f10757-ed70-43b8-8331-0e386217e72f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:0], discPort=0, order=5, intOrder=5,
loc=false, ver=1.0.0#19700101-sha1:00000000, isClient=true]
[19:22:32,090][WARN
][disco-event-worker-#1390%cache.GridCacheTcpClientDiscoveryMultiThreadedTest2%][GridDiscoveryManager]
Node FAILED: TcpDiscoveryNode [id=63f10757-ed70-43b8-8331-0e386217e72f,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:0], discPort=0, order=5, intOrder=5,
loc=false, ver=1.0.0#19700101-sha1:00000000, isClient=true]
[19:22:32,087][INFO
][disco-event-worker-#1390%cache.GridCacheTcpClientDiscoveryMultiThreadedTest2%][GridDiscoveryManager]
Added new node to topology: TcpDiscoveryNode
[id=63f10757-ed70-43b8-8331-0e386217e72f, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:0], discPort=0, order=5, intOrder=5, loc=false,
ver=1.0.0#19700101-sha1:00000000, isClient=true]
[19:22:32,084][INFO
][disco-event-worker-#1323%cache.GridCacheTcpClientDiscoveryMultiThreadedTest1%][GridDiscoveryManager]
Added new node to topology: TcpDiscoveryNode
[id=63f10757-ed70-43b8-8331-0e386217e72f, addrs=[127.0.0.1],
sockAddrs=[/127.0.0.1:0], discPort=0, order=5, intOrder=5, loc=false,
ver=1.0.0#19700101-sha1:00000000, isClient=true]
[19:22:32,088][INFO
][disco-event-worker-#1390%cache.GridCacheTcpClientDiscoveryMultiThreadedTest2%][GridDiscoveryManager]
Topology snapshot [ver=6, nodes=3, CPUs=8, heap=3.0GB]
[19:22:32,089][INFO
][disco-event-worker-#1259%cache.GridCacheTcpClientDiscoveryMultiThreadedTest0%][GridDiscoveryManager]
Topology snapshot [ver=6, nodes=3, CPUs=8, heap=3.0GB]
[19:22:32,752][WARN ][test-runner][root] Grid size is incorrect (will re-run
check in 1000 ms) [name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest0,
size=3]
[19:22:33,753][WARN ][test-runner][root] Grid size is incorrect (will re-run
check in 1000 ms) [name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest0,
size=3]
[19:22:34,753][WARN ][test-runner][root] Grid size is incorrect (will re-run
check in 1000 ms) [name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest0,
size=3]
[19:22:35,754][WARN ][test-runner][root] Grid size is incorrect (will re-run
check in 1000 ms) [name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest0,
size=3]
[19:22:36,754][WARN ][test-runner][root] Grid size is incorrect (will re-run
check in 1000 ms) [name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest0,
size=3]
[19:22:37,078][WARN
][tcp-client-disco-disconnect-hnd-#220%cache.GridCacheTcpClientDiscoveryMultiThreadedTest3][TcpClientDiscoverySpi]
Join process timed out (will try other address)
[sock=Socket[addr=/127.0.0.1,port=47500,localport=61086], timeout=5000]
[19:22:37,754][WARN ][test-runner][root] Grid size is incorrect (will re-run
check in 1000 ms) [name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest0,
size=3]
[19:22:38,075][WARN
][tcp-comm-recovery-worker-#211%cache.GridCacheTcpClientDiscoveryMultiThreadedTest3][TcpCommunicationSpi]
Connect timed out (consider increasing 'connTimeout' configuration property)
[addr=/127.0.0.1:45010]
[19:22:38,755][WARN ][test-runner][root] Grid size is incorrect (will re-run
check in 1000 ms) [name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest0,
size=3]
[19:22:39,756][WARN ][test-runner][root] Grid size is incorrect (will re-run
check in 1000 ms) [name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest0,
size=3]
[19:22:40,759][INFO ][main][root] >>> Stopping test:
testCacheWithServerNodesRestart in 31086 ms <<<
[19:22:40,759][INFO ][main][root] >>> Stopping grid
[name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest2,
id=860c20a9-377c-4668-bdec-1012cb6983d6]
[19:22:40,757][ERROR][main][root] Test failed.
java.lang.Exception: Failed to wait for proper topology.
at
org.apache.ignite.testframework.junits.GridAbstractTest.checkTopology(GridAbstractTest.java:609)
at
org.apache.ignite.internal.processors.cache.GridCacheTcpClientDiscoveryMultiThreadedTest.testCacheWithServerNodesRestart(GridCacheTcpClientDiscoveryMultiThreadedTest.java:185)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at junit.framework.TestCase.runTest(TestCase.java:176)
at
org.apache.ignite.testframework.junits.GridAbstractTest.runTestInternal(GridAbstractTest.java:1346)
at
org.apache.ignite.testframework.junits.GridAbstractTest.access$000(GridAbstractTest.java:67)
at
org.apache.ignite.testframework.junits.GridAbstractTest$2.run(GridAbstractTest.java:1289)
[19:22:40,766][INFO
][disco-event-worker-#1259%cache.GridCacheTcpClientDiscoveryMultiThreadedTest0%][GridDiscoveryManager]
Node left topology: TcpDiscoveryNode [id=860c20a9-377c-4668-bdec-1012cb6983d6,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:47502], discPort=47502, order=3,
intOrder=3, loc=false, ver=1.0.0#19700101-sha1:00000000, isClient=false]
[19:22:40,767][INFO
][disco-event-worker-#1259%cache.GridCacheTcpClientDiscoveryMultiThreadedTest0%][GridDiscoveryManager]
Topology snapshot [ver=8, nodes=2, CPUs=8, heap=3.0GB]
[19:22:40,766][ERROR][tcp-client-disco-msg-worker-#273%cache.GridCacheTcpClientDiscoveryMultiThreadedTest3][TcpClientDiscoverySpi]
Runtime error caught during grid runnable execution: IgniteSpiThread
[name=tcp-client-disco-msg-worker-#273%cache.GridCacheTcpClientDiscoveryMultiThreadedTest3]
java.lang.AssertionError: lastVer=6, newVer=8
at
org.apache.ignite.spi.discovery.tcp.TcpClientDiscoverySpi$MessageWorker.updateTopologyHistory(TcpClientDiscoverySpi.java:1268)
at
org.apache.ignite.spi.discovery.tcp.TcpClientDiscoverySpi$MessageWorker.processNodeLeftMessage(TcpClientDiscoverySpi.java:1024)
at
org.apache.ignite.spi.discovery.tcp.TcpClientDiscoverySpi$MessageWorker.processMessage(TcpClientDiscoverySpi.java:863)
at
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpiAdapter$MessageWorkerAdapter.body(TcpDiscoverySpiAdapter.java:983)
at org.apache.ignite.spi.IgniteSpiThread.run(IgniteSpiThread.java:62)
[19:22:41,773][WARN
][tcp-comm-recovery-worker-#233%cache.GridCacheTcpClientDiscoveryMultiThreadedTest1][TcpCommunicationSpi]
Connect timed out (consider increasing 'connTimeout' configuration property)
[addr=/127.0.0.1:45012]
[19:22:42,082][WARN
][tcp-client-disco-disconnect-hnd-#220%cache.GridCacheTcpClientDiscoveryMultiThreadedTest3][TcpClientDiscoverySpi]
Join process timed out (will try other address)
[sock=Socket[addr=/127.0.0.1,port=47500,localport=59308], timeout=5000]
[19:22:44,743][WARN
][tcp-disco-msg-worker-#237%cache.GridCacheTcpClientDiscoveryMultiThreadedTest1][TcpDiscoverySpi]
Timed out waiting for message delivery receipt (most probably, the reason is
in long GC pauses on remote node; consider tuning GC and increasing
'ackTimeout' configuration property). Will retry to send message with increased
timeout. Current timeout: 5000.
[19:22:44,750][INFO
][disco-event-worker-#1323%cache.GridCacheTcpClientDiscoveryMultiThreadedTest1%][GridDiscoveryManager]
Node left topology: TcpDiscoveryNode [id=860c20a9-377c-4668-bdec-1012cb6983d6,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:47502], discPort=47502, order=3,
intOrder=3, loc=false, ver=1.0.0#19700101-sha1:00000000, isClient=false]
[19:22:44,751][INFO
][disco-event-worker-#1323%cache.GridCacheTcpClientDiscoveryMultiThreadedTest1%][GridDiscoveryManager]
Topology snapshot [ver=8, nodes=2, CPUs=8, heap=3.0GB]
[19:22:44,753][INFO ][main][GridCacheProcessor] Stopped cache: null
[19:22:44,753][INFO ][main][GridCacheProcessor] Stopped cache:
ignite-marshaller-sys-cache
[19:22:44,753][INFO ][main][GridCacheProcessor] Stopped cache: ignite-sys-cache
[19:22:44,753][INFO ][main][GridCacheProcessor] Stopped cache:
ignite-atomics-sys-cache
[19:22:44,754][INFO ][main][GridDeploymentLocalStore] Removed undeployed class:
GridDeployment [ts=1428938550724, depMode=SHARED,
clsLdr=sun.misc.Launcher$AppClassLoader@56092666,
clsLdrId=d879e53bc41-860c20a9-377c-4668-bdec-1012cb6983d6, userVer=0, loc=true,
sampleClsName=org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionFullMap,
pendingUndeploy=false, undeployed=true, usage=0]
[19:22:44,754][INFO ][main][GridDeploymentLocalStore] Class locally undeployed:
class
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionFullMap
[19:22:44,754][INFO ][main][GridDeploymentLocalStore] Class locally undeployed:
class
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionMap
[19:22:44,758][INFO ][main][GridCacheTcpClientDiscoveryMultiThreadedTest2]
>>> +--------------------------------------------+
>>> Ignite ver. 1.0.0#19700101-sha1:DEV stopped OK
>>> +--------------------------------------------+
>>> Grid name: cache.GridCacheTcpClientDiscoveryMultiThreadedTest2
>>> Grid uptime: 00:00:14:10
[19:22:44,760][INFO ][main][root] >>> Stopping grid
[name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest3,
id=63f10757-ed70-43b8-8331-0e386217e72f]
[19:22:44,762][ERROR][tcp-comm-recovery-worker-#211%cache.GridCacheTcpClientDiscoveryMultiThreadedTest3][TcpCommunicationSpi]
Runtime error caught during grid runnable execution: IgniteSpiThread
[name=tcp-comm-recovery-worker-#211%cache.GridCacheTcpClientDiscoveryMultiThreadedTest3]
class org.apache.ignite.spi.IgniteSpiException: Node is stopping.
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.reserveClient(TcpCommunicationSpi.java:1621)
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.access$4000(TcpCommunicationSpi.java:141)
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi$RecoveryWorker.body(TcpCommunicationSpi.java:2450)
at org.apache.ignite.spi.IgniteSpiThread.run(IgniteSpiThread.java:62)
[19:22:44,767][INFO ][main][GridCacheProcessor] Stopped cache: null
[19:22:44,768][INFO ][main][GridCacheProcessor] Stopped cache:
ignite-marshaller-sys-cache
[19:22:44,768][INFO ][main][GridCacheProcessor] Stopped cache:
ignite-atomics-sys-cache
[19:22:44,768][INFO ][main][GridCacheProcessor] Stopped cache: ignite-sys-cache
[19:22:44,769][INFO ][main][GridDeploymentLocalStore] Removed undeployed class:
GridDeployment [ts=1428938540157, depMode=SHARED,
clsLdr=sun.misc.Launcher$AppClassLoader@56092666,
clsLdrId=d098e53bc41-63f10757-ed70-43b8-8331-0e386217e72f, userVer=0, loc=true,
sampleClsName=org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionFullMap,
pendingUndeploy=false, undeployed=true, usage=0]
[19:22:44,770][INFO ][main][GridDeploymentLocalStore] Class locally undeployed:
class
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionFullMap
[19:22:44,770][INFO ][main][GridDeploymentLocalStore] Class locally undeployed:
class java.lang.Integer
[19:22:44,770][INFO ][main][GridDeploymentLocalStore] Class locally undeployed:
class
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionMap
[19:22:44,773][INFO ][main][GridCacheTcpClientDiscoveryMultiThreadedTest3]
>>> +--------------------------------------------+
>>> Ignite ver. 1.0.0#19700101-sha1:DEV stopped OK
>>> +--------------------------------------------+
>>> Grid name: cache.GridCacheTcpClientDiscoveryMultiThreadedTest3
>>> Grid uptime: 00:00:24:598
[19:22:44,775][INFO ][main][root] >>> Stopping grid
[name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest0,
id=9e6125e2-2637-419b-9efd-d20bba6cec48]
[19:22:44,780][INFO
][disco-event-worker-#1323%cache.GridCacheTcpClientDiscoveryMultiThreadedTest1%][GridDiscoveryManager]
Node left topology: TcpDiscoveryNode [id=9e6125e2-2637-419b-9efd-d20bba6cec48,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:47500], discPort=47500, order=1,
intOrder=1, loc=false, ver=1.0.0#19700101-sha1:00000000, isClient=false]
[19:22:44,782][INFO
][disco-event-worker-#1323%cache.GridCacheTcpClientDiscoveryMultiThreadedTest1%][GridDiscoveryManager]
Topology snapshot [ver=10, nodes=1, CPUs=8, heap=3.0GB]
[19:22:44,784][INFO ][main][GridCacheProcessor] Stopped cache: null
[19:22:44,784][INFO ][main][GridCacheProcessor] Stopped cache:
ignite-marshaller-sys-cache
[19:22:44,784][INFO ][main][GridCacheProcessor] Stopped cache: ignite-sys-cache
[19:22:44,784][INFO ][main][GridCacheProcessor] Stopped cache:
ignite-atomics-sys-cache
[19:22:44,785][INFO ][main][GridDeploymentLocalStore] Removed undeployed class:
GridDeployment [ts=1428938550630, depMode=SHARED,
clsLdr=sun.misc.Launcher$AppClassLoader@56092666,
clsLdrId=7639e53bc41-9e6125e2-2637-419b-9efd-d20bba6cec48, userVer=0, loc=true,
sampleClsName=org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionMap,
pendingUndeploy=false, undeployed=true, usage=0]
[19:22:44,785][INFO ][main][GridDeploymentLocalStore] Class locally undeployed:
class
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionMap
[19:22:44,785][INFO ][main][GridDeploymentLocalStore] Class locally undeployed:
class org.apache.ignite.internal.GridTopic$T7
[19:22:44,788][INFO ][main][GridCacheTcpClientDiscoveryMultiThreadedTest0]
>>> +--------------------------------------------+
>>> Ignite ver. 1.0.0#19700101-sha1:DEV stopped OK
>>> +--------------------------------------------+
>>> Grid name: cache.GridCacheTcpClientDiscoveryMultiThreadedTest0
>>> Grid uptime: 00:00:14:219
[19:22:44,789][INFO ][main][root] >>> Stopping grid
[name=cache.GridCacheTcpClientDiscoveryMultiThreadedTest1,
id=1cbf6dfb-0e5d-4bed-bc1e-162755624999]
[19:22:44,795][INFO ][main][GridCacheProcessor] Stopped cache: null
[19:22:44,796][INFO ][main][GridCacheProcessor] Stopped cache:
ignite-marshaller-sys-cache
[19:22:44,796][INFO ][main][GridCacheProcessor] Stopped cache: ignite-sys-cache
[19:22:44,796][INFO ][main][GridCacheProcessor] Stopped cache:
ignite-atomics-sys-cache
[19:22:44,796][INFO ][main][GridDeploymentLocalStore] Removed undeployed class:
GridDeployment [ts=1428938550630, depMode=SHARED,
clsLdr=sun.misc.Launcher$AppClassLoader@56092666,
clsLdrId=9639e53bc41-1cbf6dfb-0e5d-4bed-bc1e-162755624999, userVer=0, loc=true,
sampleClsName=org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionFullMap,
pendingUndeploy=false, undeployed=true, usage=0]
[19:22:44,797][INFO ][main][GridDeploymentLocalStore] Class locally undeployed:
class
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionFullMap
[19:22:44,797][INFO ][main][GridDeploymentLocalStore] Class locally undeployed:
class
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionMap
[19:22:44,797][INFO ][main][GridDeploymentLocalStore] Class locally undeployed:
class org.apache.ignite.internal.GridTopic$T7
[19:22:44,800][INFO ][main][GridCacheTcpClientDiscoveryMultiThreadedTest1]
>>> +--------------------------------------------+
>>> Ignite ver. 1.0.0#19700101-sha1:DEV stopped OK
>>> +--------------------------------------------+
>>> Grid name: cache.GridCacheTcpClientDiscoveryMultiThreadedTest1
>>> Grid uptime: 00:00:14:146
[19:22:44,801][INFO ][main][root] >>> Stopping test class:
GridCacheTcpClientDiscoveryMultiThreadedTest <<<
java.lang.Exception: Failed to wait for proper topology.
at
org.apache.ignite.testframework.junits.GridAbstractTest.checkTopology(GridAbstractTest.java:609)
at
org.apache.ignite.internal.processors.cache.GridCacheTcpClientDiscoveryMultiThreadedTest.testCacheWithServerNodesRestart(GridCacheTcpClientDiscoveryMultiThreadedTest.java:185)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at
org.apache.ignite.testframework.junits.GridAbstractTest.runTestInternal(GridAbstractTest.java:1346)
at
org.apache.ignite.testframework.junits.GridAbstractTest.access$000(GridAbstractTest.java:67)
at
org.apache.ignite.testframework.junits.GridAbstractTest$2.run(GridAbstractTest.java:1289)
{code}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
