You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@ignite.apache.org by "Yakov Zhdanov (JIRA)" <ji...@apache.org> on 2015/04/13 18:00:18 UTC
[jira] [Created] (IGNITE-739)
org.apache.ignite.internal.processors.cache.GridCacheTcpClientDiscoveryMultiThreadedTest#testCacheWithServerNodesRestart
fails
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)