Anton Vinogradov created IGNITE-1913:
----------------------------------------
Summary: Assertion fail cause Grid hangs
Key: IGNITE-1913
URL: https://issues.apache.org/jira/browse/IGNITE-1913
Project: Ignite
Issue Type: Bug
Reporter: Anton Vinogradov
Assignee: Anton Vinogradov
Priority: Critical
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,762][INFO
][async-runner-1][GridDiscoveryManager] Topology snapshot [ver=278, servers=4,
clients=0, CPUs=8, heap=2.8GB]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,763][INFO
][ignite-#69277%sys-atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest3%][GridDhtPartitionDemander]
<default> Completed rebalancing [cache=null,
fromNode=0002a176-16e7-41e3-9b45-cce0a55a5000, topology=AffinityTopologyVersion
[topVer=278, minorTopVer=0], time=10 ms]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,767][INFO
][ignite-#69279%sys-atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest3%][GridDhtPartitionDemander]
<default> Completed rebalancing [cache=null,
fromNode=102f9887-7fbd-4010-a93b-5c239c38d001, topology=AffinityTopologyVersion
[topVer=278, minorTopVer=0], time=20 ms]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,767][INFO
][ignite-#69280%sys-atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest3%][GridDhtPartitionDemander]
<default> Completed (final) rebalancing [cache=null,
fromNode=204c4f10-06ca-4e70-9b67-13baf27f1002, topology=AffinityTopologyVersion
[topVer=278, minorTopVer=0], time=20 ms]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,768][INFO
][main][root] >>> Stopping test: testPutInsideTransaction in 83897 ms <<<
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,769][INFO
][exchange-worker-#62068%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest1%][GridCachePartitionExchangeManager]
Nothing scheduled, skipping rebalancing [top=AffinityTopologyVersion
[topVer=278, minorTopVer=1]]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,769][INFO
][exchange-worker-#62066%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest0%][GridCachePartitionExchangeManager]
Nothing scheduled, skipping rebalancing [top=AffinityTopologyVersion
[topVer=278, minorTopVer=1]]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,769][INFO
][exchange-worker-#69294%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest3%][GridCachePartitionExchangeManager]
Nothing scheduled, skipping rebalancing [top=AffinityTopologyVersion
[topVer=278, minorTopVer=1]]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,769][INFO
][exchange-worker-#62069%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest2%][GridCachePartitionExchangeManager]
Nothing scheduled, skipping rebalancing [top=AffinityTopologyVersion
[topVer=278, minorTopVer=1]]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,791][INFO
][ignite-#61916%sys-atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest0%][GridCacheProcessor]
Stopped cache: null
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,791][INFO
][main][root] >>> Starting test: testPutAsyncStoreEnabled <<<
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,794][INFO
][exchange-worker-#62066%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest0%][GridCachePartitionExchangeManager]
Nothing scheduled, skipping rebalancing [top=AffinityTopologyVersion
[topVer=278, minorTopVer=2]]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,812][INFO
][ignite-#69275%sys-atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest3%][GridCacheProcessor]
Stopped cache: null
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,814][INFO
][exchange-worker-#69294%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest3%][GridCachePartitionExchangeManager]
Nothing scheduled, skipping rebalancing [top=AffinityTopologyVersion
[topVer=278, minorTopVer=2]]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,815][INFO
][ignite-#61990%sys-atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest2%][GridCacheProcessor]
Stopped cache: null
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,818][INFO
][exchange-worker-#62069%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest2%][GridCachePartitionExchangeManager]
Nothing scheduled, skipping rebalancing [top=AffinityTopologyVersion
[topVer=278, minorTopVer=2]]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,824][INFO
][exchange-worker-#62066%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest0%][GridCacheProcessor]
Started cache [name=default, mode=PARTITIONED]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,825][INFO
][ignite-#62003%sys-atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest1%][GridCacheProcessor]
Stopped cache: null
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,828][INFO
][exchange-worker-#62068%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest1%][GridCachePartitionExchangeManager]
Nothing scheduled, skipping rebalancing [top=AffinityTopologyVersion
[topVer=278, minorTopVer=2]]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,832][INFO
][exchange-worker-#62069%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest2%][GridCacheProcessor]
Started cache [name=default, mode=PARTITIONED]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,833][INFO
][exchange-worker-#69294%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest3%][GridCacheProcessor]
Started cache [name=default, mode=PARTITIONED]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,833][INFO
][exchange-worker-#62068%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest1%][GridCacheProcessor]
Started cache [name=default, mode=PARTITIONED]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,859][INFO
][exchange-worker-#62066%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest0%][GridCachePartitionExchangeManager]
Nothing scheduled, skipping rebalancing [top=AffinityTopologyVersion
[topVer=278, minorTopVer=3]]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,861][INFO
][exchange-worker-#69294%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest3%][GridCachePartitionExchangeManager]
Nothing scheduled, skipping rebalancing [top=AffinityTopologyVersion
[topVer=278, minorTopVer=3]]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,861][INFO
][async-runner-1][root] >>> Stopping grid
[name=atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest3,
id=305994f0-968c-4b20-abce-8e9d49502003]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,861][INFO
][exchange-worker-#62069%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest2%][GridCachePartitionExchangeManager]
Nothing scheduled, skipping rebalancing [top=AffinityTopologyVersion
[topVer=278, minorTopVer=3]]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,898][INFO
][exchange-worker-#62068%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest1%][GridCachePartitionExchangeManager]
Nothing scheduled, skipping rebalancing [top=AffinityTopologyVersion
[topVer=278, minorTopVer=3]]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,900][INFO
][disco-event-worker-#62057%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest0%][GridDiscoveryManager]
Node left topology: TcpDiscoveryNode [id=305994f0-968c-4b20-abce-8e9d49502003,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:47501], discPort=47501, order=278,
intOrder=141, lastExchangeTime=1447231557651, loc=false,
ver=1.5.0#20151110-sha1:81b600de, isClient=false]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,900][INFO
][disco-event-worker-#62057%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest0%][GridDiscoveryManager]
Topology snapshot [ver=279, servers=3, clients=0, CPUs=8, heap=2.8GB]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,900][INFO
][disco-event-worker-#62062%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest1%][GridDiscoveryManager]
Node left topology: TcpDiscoveryNode [id=305994f0-968c-4b20-abce-8e9d49502003,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:47501], discPort=47501, order=278,
intOrder=141, lastExchangeTime=1447231557661, loc=false,
ver=1.5.0#20151110-sha1:81b600de, isClient=false]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,900][INFO
][disco-event-worker-#62062%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest1%][GridDiscoveryManager]
Topology snapshot [ver=279, servers=3, clients=0, CPUs=8, heap=2.8GB]
[08:45:57]W: [org.apache.ignite:ignite-core] [08:45:57,900][WARN
][tcp-disco-sock-reader-#20488%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest3][TestTcpDiscoverySpi]
Failed to read magic header (too few bytes received)
[rmtAddr=/127.0.0.1:47844, locAddr=/127.0.0.1:47501]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,903][INFO
][disco-event-worker-#62064%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest2%][GridDiscoveryManager]
Node left topology: TcpDiscoveryNode [id=305994f0-968c-4b20-abce-8e9d49502003,
addrs=[127.0.0.1], sockAddrs=[/127.0.0.1:47501], discPort=47501, order=278,
intOrder=141, lastExchangeTime=1447231557661, loc=false,
ver=1.5.0#20151110-sha1:81b600de, isClient=false]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,903][INFO
][disco-event-worker-#62064%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest2%][GridDiscoveryManager]
Topology snapshot [ver=279, servers=3, clients=0, CPUs=8, heap=2.8GB]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,903][INFO
][async-runner-1][GridCacheProcessor] Stopped cache: ignite-marshaller-sys-cache
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,903][INFO
][async-runner-1][GridCacheProcessor] Stopped cache: ignite-sys-cache
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,903][INFO
][async-runner-1][GridCacheProcessor] Stopped cache: ignite-atomics-sys-cache
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,903][INFO
][async-runner-1][GridCacheProcessor] Stopped cache: tx-cache
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,904][INFO
][async-runner-1][GridCacheProcessor] Stopped cache: null
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,904][INFO
][async-runner-1][GridDeploymentLocalStore] Removed undeployed class:
GridDeployment [ts=1447231557734, depMode=SHARED,
clsLdr=IsolatedClassLoader{roleName='test'},
clsLdrId=51557b8f051-305994f0-968c-4b20-abce-8e9d49502003, userVer=0, loc=true,
sampleClsName=org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionFullMap,
pendingUndeploy=false, undeployed=true, usage=0]
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,904][INFO
][async-runner-1][GridDeploymentLocalStore] Class locally undeployed: class
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionFullMap
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,904][INFO
][async-runner-1][GridDeploymentLocalStore] Class locally undeployed: class
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionMap
[08:45:57] : [org.apache.ignite:ignite-core] [08:45:57,913][INFO
][async-runner-1][IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest3]
[08:45:57] : [org.apache.ignite:ignite-core]
[08:45:57] : [org.apache.ignite:ignite-core] >>>
+------------------------------------------------------------------------------------------+
[08:45:57] : [org.apache.ignite:ignite-core] >>> Ignite ver.
1.5.0-SNAPSHOT#20151110-sha1:81b600de52e5fb023e16e6bffd56c4d14a4a770f stopped OK
[08:45:57] : [org.apache.ignite:ignite-core] >>>
+------------------------------------------------------------------------------------------+
[08:45:57] : [org.apache.ignite:ignite-core] >>> Grid name:
atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest3
[08:45:57] : [org.apache.ignite:ignite-core] >>> Grid uptime:
00:00:00:156
[08:45:57] : [org.apache.ignite:ignite-core]
[08:45:57] : [org.apache.ignite:ignite-core]
[08:45:57]W: [org.apache.ignite:ignite-core]
[08:45:57,915][ERROR][exchange-worker-#62068%atomic.IgniteCachePutRetryAtomicPrimaryWriteOrderSelfTest1%][GridDhtPartitionsExchangeFuture]
Failed to reinitialize local partitions (preloading will be stopped):
GridDhtPartitionExchangeId [topVer=AffinityTopologyVersion [topVer=279,
minorTopVer=0], nodeId=305994f0, evt=NODE_LEFT]
[08:45:57]W: [org.apache.ignite:ignite-core]
java.lang.AssertionError: Invalid update sequence [cur=1000, new=5]
[08:45:57]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionMap.updateSequence(GridDhtPartitionMap.java:185)
[08:45:57]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtPartitionTopologyImpl.updateLocal(GridDhtPartitionTopologyImpl.java:1140)
[08:45:57]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.processors.cache.distributed.dht.GridDhtPartitionTopologyImpl.beforeExchange(GridDhtPartitionTopologyImpl.java:357)
[08:45:57]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.processors.cache.distributed.dht.preloader.GridDhtPartitionsExchangeFuture.init(GridDhtPartitionsExchangeFuture.java:837)
[08:45:57]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.processors.cache.GridCachePartitionExchangeManager$ExchangeWorker.body(GridCachePartitionExchangeManager.java:1237)
[08:45:57]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
[08:45:57]W: [org.apache.ignite:ignite-core] at
java.lang.Thread.run(Thread.java:745)
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
