Ryabov Dmitrii created IGNITE-11571:
---------------------------------------
Summary: Ignored critical failure
Key: IGNITE-11571
URL: https://issues.apache.org/jira/browse/IGNITE-11571
Project: Ignite
Issue Type: Bug
Affects Versions: 2.7
Reporter: Ryabov Dmitrii
Critical failure in
{{TcpCommunicationSpiFaultyClientTest#testNotAcceptedConnection()}} is ignored
because of no-op failure handler.
{code:java}
[2019-03-19 15:09:18,970][WARN
][disco-event-worker-#237%tcp.TcpCommunicationSpiFaultyClientTest0%][GridDiscoveryManager]
Node FAILED: TcpDiscoveryNode [id=2d7a1e30-585f-44af-88af-60065ca00002,
consistentId=2d7a1e30-585f-44af-88af-60065ca00002, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:0], discPort=0, order=3, intOrder=3,
lastExchangeTime=1552997347220, loc=false, ver=2.7.0#20190319-sha1:00000000,
isClient=true]
[2019-03-19 15:09:18,972][WARN ][tcp-disco-msg-worker-[9f201bd5
127.0.0.1:47500]-#36%tcp.TcpCommunicationSpiFaultyClientTest1%][TestTcpDiscoverySpi]
Received EVT_NODE_FAILED event with warning [nodeInitiatedEvt=TcpDiscoveryNode
[id=9f201bd5-f120-4365-8477-d9ff50e00000, consistentId=127.0.0.1:47500,
addrs=ArrayList [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500],
discPort=47500, order=1, intOrder=1, lastExchangeTime=1552997347060, loc=false,
ver=2.7.0#20190319-sha1:00000000, isClient=false], msg=TcpCommunicationSpi
failed to establish connection to node [rmtNode=TcpDiscoveryNode
[id=2d7a1e30-585f-44af-88af-60065ca00002,
consistentId=2d7a1e30-585f-44af-88af-60065ca00002, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:0], discPort=0, order=3, intOrder=3,
lastExchangeTime=1552997347220, loc=false, ver=2.7.0#20190319-sha1:00000000,
isClient=true], errs=class o.a.i.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=2d7a1e30-585f-44af-88af-60065ca00002,
addrs=[/127.0.0.1:47200]], connectErrs=[]]]
[2019-03-19 15:09:18,973][WARN
][tcp-client-disco-msg-worker-#54%tcp.TcpCommunicationSpiFaultyClientTest3%][TestTcpDiscoverySpi]
Received EVT_NODE_FAILED event with warning [nodeInitiatedEvt=TcpDiscoveryNode
[id=9f201bd5-f120-4365-8477-d9ff50e00000, consistentId=127.0.0.1:47500,
addrs=ArrayList [127.0.0.1], sockAddrs=HashSet [/127.0.0.1:47500],
discPort=47500, order=1, intOrder=1, lastExchangeTime=1552997347390, loc=false,
ver=2.7.0#20190319-sha1:00000000, isClient=false], msg=TcpCommunicationSpi
failed to establish connection to node [rmtNode=TcpDiscoveryNode
[id=2d7a1e30-585f-44af-88af-60065ca00002,
consistentId=2d7a1e30-585f-44af-88af-60065ca00002, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:0], discPort=0, order=3, intOrder=3,
lastExchangeTime=1552997347220, loc=false, ver=2.7.0#20190319-sha1:00000000,
isClient=true], errs=class o.a.i.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=2d7a1e30-585f-44af-88af-60065ca00002,
addrs=[/127.0.0.1:47200]], connectErrs=[]]]
[2019-03-19 15:09:18,975][WARN
][disco-event-worker-#380%tcp.TcpCommunicationSpiFaultyClientTest3%][GridDiscoveryManager]
Node FAILED: TcpDiscoveryNode [id=2d7a1e30-585f-44af-88af-60065ca00002,
consistentId=2d7a1e30-585f-44af-88af-60065ca00002, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:0], discPort=0, order=3, intOrder=3,
lastExchangeTime=1552997347390, loc=false, ver=2.7.0#20190319-sha1:00000000,
isClient=true]
[2019-03-19 15:09:18,975][INFO
][disco-event-worker-#380%tcp.TcpCommunicationSpiFaultyClientTest3%][GridDiscoveryManager]
Topology snapshot [ver=5, locNode=0f4451ab, servers=2, clients=1,
state=ACTIVE, CPUs=8, offheap=0.1GB, heap=3.5GB]
[2019-03-19
15:09:18,969][ERROR][sys-#240%tcp.TcpCommunicationSpiFaultyClientTest0%][TcpCommunicationSpiFaultyClientTest$TestCommunicationSpi]
Failed to send message to remote node [node=TcpDiscoveryNode
[id=2d7a1e30-585f-44af-88af-60065ca00002,
consistentId=2d7a1e30-585f-44af-88af-60065ca00002, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:0], discPort=0, order=3, intOrder=3,
lastExchangeTime=1552997347220, loc=false, ver=2.7.0#20190319-sha1:00000000,
isClient=true], msg=GridIoMessage [plc=2, topic=TOPIC_CACHE, topicOrd=8,
ordered=false, timeout=0, skipOnTimeout=false, msg=GridDhtPartitionsFullMessage
[parts=HashMap {-2100569601=GridDhtPartitionFullMap
{9f201bd5-f120-4365-8477-d9ff50e00000=GridDhtPartitionMap [moving=0,
top=AffinityTopologyVersion [topVer=4, minorTopVer=1], updateSeq=12, size=100],
7f025ffe-76b4-420e-b476-f6db8ff00001=GridDhtPartitionMap [moving=0,
top=AffinityTopologyVersion [topVer=4, minorTopVer=1], updateSeq=109,
size=100]}}, partCntrs=null, partCntrs2=null, partHistSuppliers=null,
partsToReload=null, partsSizes=HashMap {-2100569601=UnmodifiableMap {0=0, 1=0,
2=0, 3=0, 4=0, 5=0, 6=0, 7=0, 8=0, 9=0, 10=0, 11=0, 12=0, 13=0, 14=0, 15=0,
16=0, 17=0, 18=0, 19=0, 20=0, 21=0, 22=0, 23=0, 24=0, 25=0, 26=0, 27=0, 28=0,
29=0, 30=0, 31=0, 32=0, 33=0, 34=0, 35=0, 36=0, 37=0, 38=0, 39=0, 40=0, 41=0,
42=0, 43=0, 44=0, 45=0, 46=0, 47=0, 48=0, 49=0, 50=0, 51=0, 52=0, 53=0, 54=0,
55=0, 56=0, 57=0, 58=0, 59=0, 60=0, 61=0, 62=0, 63=0, 64=0, 65=0, 66=0, 67=0,
68=0, 69=0, 70=0, 71=0, 72=0, 73=0, 74=0, 75=0, 76=0, 77=0, 78=0, 79=0, 80=0,
81=0, 82=0, 83=0, 84=0, 85=0, 86=0, 87=0, 88=0, 89=0, 90=0, 91=0, 92=0, 93=0,
94=0, 95=0, 96=0, 97=0, 98=0, 99=0}}, topVer=AffinityTopologyVersion [topVer=4,
minorTopVer=1], errs=null, compress=true, resTopVer=null, partCnt=1,
super=GridDhtPartitionsAbstractMessage [exchId=null, lastVer=null,
super=GridCacheMessage [msgId=33, depInfo=null,
lastAffChangedTopVer=AffinityTopologyVersion [topVer=4, minorTopVer=1],
err=null, skipPrepare=false]]]]]
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=2d7a1e30-585f-44af-88af-60065ca00002, addrs=[/127.0.0.1:47200]]
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.createNioSession(TcpCommunicationSpi.java:3513)
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.createTcpClient(TcpCommunicationSpi.java:3279)
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpiFaultyClientTest$TestCommunicationSpi.createTcpClient(TcpCommunicationSpiFaultyClientTest.java:346)
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.createCommunicationClient(TcpCommunicationSpi.java:3039)
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.reserveClient(TcpCommunicationSpi.java:2919)
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.sendMessage0(TcpCommunicationSpi.java:2759)
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.sendMessage(TcpCommunicationSpi.java:2718)
at
org.apache.ignite.internal.managers.communication.GridIoManager.send(GridIoManager.java:1648)
at
org.apache.ignite.internal.managers.communication.GridIoManager.sendToGridTopic(GridIoManager.java:1722)
at
org.apache.ignite.internal.processors.task.GridTaskWorker.sendRequest(GridTaskWorker.java:1445)
at
org.apache.ignite.internal.processors.task.GridTaskWorker.processMappedJobs(GridTaskWorker.java:664)
at
org.apache.ignite.internal.processors.task.GridTaskWorker.body(GridTaskWorker.java:536)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at
org.apache.ignite.internal.processors.task.GridTaskProcessor.startTask(GridTaskProcessor.java:808)
at
org.apache.ignite.internal.processors.task.GridTaskProcessor.execute(GridTaskProcessor.java:476)
at
org.apache.ignite.internal.processors.closure.GridClosureProcessor.runAsync(GridClosureProcessor.java:244)
at
org.apache.ignite.internal.processors.closure.GridClosureProcessor.runAsync(GridClosureProcessor.java:216)
at
org.apache.ignite.internal.IgniteComputeImpl.broadcastAsync0(IgniteComputeImpl.java:598)
at
org.apache.ignite.internal.IgniteComputeImpl.broadcast(IgniteComputeImpl.java:574)
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpiFaultyClientTest.testFailClient(TcpCommunicationSpiFaultyClientTest.java:243)
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpiFaultyClientTest.testNotAcceptedConnection(TcpCommunicationSpiFaultyClientTest.java:172)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2019-03-19 15:09:18,982][INFO
][sys-#240%tcp.TcpCommunicationSpiFaultyClientTest0%][GridCachePartitionExchangeManager]
Finished sending full message [msgTopVer=AffinityTopologyVersion [topVer=4,
minorTopVer=1], groups=[CacheGroupContext [grp=ignite-sys-cache]],
latency=8862ms]
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47)
at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44)
at
org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at
org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at
org.apache.ignite.testframework.junits.GridAbstractTest$7.run(GridAbstractTest.java:2107)
at java.lang.Thread.run(Thread.java:748)
Caused by: class org.apache.ignite.spi.IgniteSpiOperationTimeoutException:
Failed to perform handshake due to timeout (consider increasing
'connectionTimeout' configuration property).
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.handshakeTimeoutException(TcpCommunicationSpi.java:3664)
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.safeTcpHandshake(TcpCommunicationSpi.java:3908)
at
org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.createNioSession(TcpCommunicationSpi.java:3423)
... 32 more
[2019-03-19 15:09:18,982][INFO
][exchange-worker-#381%tcp.TcpCommunicationSpiFaultyClientTest3%][time] Started
exchange init [topVer=AffinityTopologyVersion [topVer=5, minorTopVer=0],
crd=false, evt=NODE_FAILED, evtNode=2d7a1e30-585f-44af-88af-60065ca00002,
customEvt=null, allowMerge=true]
[2019-03-19 15:09:18,980][WARN
][tcp-client-disco-msg-worker-#47%tcp.TcpCommunicationSpiFaultyClientTest2%][TestTcpDiscoverySpi]
Local node was dropped from cluster due to network problems
[nodeInitiatedFail=9f201bd5-f120-4365-8477-d9ff50e00000,
msg=TcpCommunicationSpi failed to establish connection to node
[rmtNode=TcpDiscoveryNode [id=2d7a1e30-585f-44af-88af-60065ca00002,
consistentId=2d7a1e30-585f-44af-88af-60065ca00002, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:0], discPort=0, order=3, intOrder=3,
lastExchangeTime=1552997347220, loc=false, ver=2.7.0#20190319-sha1:00000000,
isClient=true], errs=class o.a.i.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=2d7a1e30-585f-44af-88af-60065ca00002,
addrs=[/127.0.0.1:47200]], connectErrs=[]]]
[2019-03-19 15:09:18,983][WARN
][disco-event-worker-#333%tcp.TcpCommunicationSpiFaultyClientTest2%][GridDiscoveryManager]
Local node SEGMENTED: TcpDiscoveryNode
[id=2d7a1e30-585f-44af-88af-60065ca00002,
consistentId=2d7a1e30-585f-44af-88af-60065ca00002, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:0], discPort=0, order=3, intOrder=0,
lastExchangeTime=1552997347210, loc=true, ver=2.7.0#20190319-sha1:00000000,
isClient=true]
[2019-03-19 15:09:18,983][INFO
][exchange-worker-#381%tcp.TcpCommunicationSpiFaultyClientTest3%][GridDhtPartitionsExchangeFuture]
Finish exchange future [startVer=AffinityTopologyVersion [topVer=5,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=5, minorTopVer=0],
err=null]
[2019-03-19 15:09:18,984][INFO
][exchange-worker-#381%tcp.TcpCommunicationSpiFaultyClientTest3%][GridDhtPartitionsExchangeFuture]
Completed partition exchange [localNode=0f4451ab-23c0-4371-9a78-49fd33100003,
exchange=GridDhtPartitionsExchangeFuture [topVer=AffinityTopologyVersion
[topVer=5, minorTopVer=0], evt=NODE_FAILED, evtNode=TcpDiscoveryNode
[id=2d7a1e30-585f-44af-88af-60065ca00002,
consistentId=2d7a1e30-585f-44af-88af-60065ca00002, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:0], discPort=0, order=3, intOrder=3,
lastExchangeTime=1552997347390, loc=false, ver=2.7.0#20190319-sha1:00000000,
isClient=true], done=true], topVer=AffinityTopologyVersion [topVer=5,
minorTopVer=0]]
[2019-03-19 15:09:18,984][INFO
][exchange-worker-#381%tcp.TcpCommunicationSpiFaultyClientTest3%][GridDhtPartitionsExchangeFuture]
Exchange timings [startVer=AffinityTopologyVersion [topVer=5, minorTopVer=0],
resVer=AffinityTopologyVersion [topVer=5, minorTopVer=0], stage="Waiting in
exchange queue" (1 ms), stage="Exchange parameters initialization" (0 ms),
stage="Determine exchange type" (0 ms), stage="Exchange done" (0 ms),
stage="Total time" (1 ms)]
[2019-03-19 15:09:18,984][INFO
][exchange-worker-#381%tcp.TcpCommunicationSpiFaultyClientTest3%][GridDhtPartitionsExchangeFuture]
Exchange longest local stages [startVer=AffinityTopologyVersion [topVer=5,
minorTopVer=0], resVer=AffinityTopologyVersion [topVer=5, minorTopVer=0]]
[2019-03-19 15:09:18,984][INFO
][exchange-worker-#381%tcp.TcpCommunicationSpiFaultyClientTest3%][time]
Finished exchange init [topVer=AffinityTopologyVersion [topVer=5,
minorTopVer=0], crd=false]
[2019-03-19
15:09:18,985][ERROR][tcp-client-disco-msg-worker-#47%tcp.TcpCommunicationSpiFaultyClientTest2%][IgniteTestResources]
Critical system error detected. Will be handled accordingly to configured
handler [hnd=NoOpFailureHandler [super=AbstractFailureHandler
[ignoredFailureTypes=UnmodifiableSet [SYSTEM_WORKER_BLOCKED,
SYSTEM_CRITICAL_OPERATION_TIMEOUT]]], failureCtx=FailureContext
[type=CRITICAL_ERROR, err=class o.a.i.IgniteInterruptedException: Got
interrupted while waiting for future to complete.]]
class org.apache.ignite.IgniteInterruptedException: Got interrupted while
waiting for future to complete.
at
org.apache.ignite.internal.util.IgniteUtils$3.apply(IgniteUtils.java:880)
at
org.apache.ignite.internal.util.IgniteUtils$3.apply(IgniteUtils.java:878)
at
org.apache.ignite.internal.util.IgniteUtils.convertException(IgniteUtils.java:1054)
at
org.apache.ignite.internal.util.future.IgniteFutureImpl.convertException(IgniteFutureImpl.java:168)
at
org.apache.ignite.internal.util.future.IgniteFutureImpl.get(IgniteFutureImpl.java:137)
at
org.apache.ignite.spi.discovery.tcp.ClientImpl$MessageWorker.notifyDiscovery(ClientImpl.java:2621)
at
org.apache.ignite.spi.discovery.tcp.ClientImpl$MessageWorker.notifyDiscovery(ClientImpl.java:2595)
at
org.apache.ignite.spi.discovery.tcp.ClientImpl$MessageWorker.body(ClientImpl.java:1838)
at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:120)
at
org.apache.ignite.spi.discovery.tcp.ClientImpl$1.body(ClientImpl.java:302)
at org.apache.ignite.spi.IgniteSpiThread.run(IgniteSpiThread.java:61)
{code}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
