Pavel Pereslegin created IGNITE-9225:
----------------------------------------
Summary: Cache 7 (With Persistence) configuration halted by
failure handler.
Key: IGNITE-9225
URL: https://issues.apache.org/jira/browse/IGNITE-9225
Project: Ignite
Issue Type: Bug
Affects Versions: 2.6
Reporter: Pavel Pereslegin
Assignee: Pavel Pereslegin
Fix For: 2.7
WalModeChangeCommonAbstractSelfTest uses default failure handler and could halt
JVM.
Example of such failure on TC:
https://ci.ignite.apache.org/viewLog.html?buildId=1589136&buildTypeId=IgniteTests24Java8_Cache7&tab=buildResultsDiv
Log output:
{noformat}
[12:51:02]W: [org.apache.ignite:ignite-core] [2018-08-04
09:51:02,859][ERROR][main][root] Test failed.
[12:51:02]W: [org.apache.ignite:ignite-core]
junit.framework.AssertionFailedError: Failed to wait for disconnect/reconnect
event.
[12:51:02]W: [org.apache.ignite:ignite-core] at
junit.framework.Assert.fail(Assert.java:57)
[12:51:02]W: [org.apache.ignite:ignite-core] at
junit.framework.TestCase.fail(TestCase.java:227)
[12:51:02]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.IgniteClientReconnectAbstractTest.waitReconnectEvent(IgniteClientReconnectAbstractTest.java:122)
[12:51:02]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.IgniteClientReconnectAbstractTest.reconnectClientNodes(IgniteClientReconnectAbstractTest.java:314)
[12:51:02]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.IgniteClientReconnectAbstractTest.reconnectClientNode(IgniteClientReconnectAbstractTest.java:256)
[12:51:02]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.processors.cache.WalModeChangeAdvancedSelfTest.testClientReconnect(WalModeChangeAdvancedSelfTest.java:350)
[12:51:02] : [Step 3/4] [2018-08-04 09:51:02,861][INFO ][main][root] >>>
Stopping test: WalModeChangeAdvancedSelfTest#testClientReconnect in 33858 ms <<<
[12:51:02]W: [org.apache.ignite:ignite-core] at
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[12:51:02] : [Step 3/4] [2018-08-04 09:51:02,861][INFO ][main][root] >>>
Stopping test class: WalModeChangeAdvancedSelfTest <<<
[12:51:02]W: [org.apache.ignite:ignite-core] at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[12:51:02] : [Step 3/4] [2018-08-04 09:51:02,861][INFO ][main][root] >>>
Stopping grid [name=cli, id=6481a605-7bfb-486d-a796-2a4f1c8d0469]
[12:51:02]W: [org.apache.ignite:ignite-core] at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[12:51:02]W: [org.apache.ignite:ignite-core] at
java.lang.reflect.Method.invoke(Method.java:498)
[12:51:02]W: [org.apache.ignite:ignite-core] at
junit.framework.TestCase.runTest(TestCase.java:176)
[12:51:02]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.testframework.junits.GridAbstractTest.runTestInternal(GridAbstractTest.java:2156)
[12:51:02]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.testframework.junits.GridAbstractTest.access$000(GridAbstractTest.java:143)
[12:51:02]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.testframework.junits.GridAbstractTest$5.run(GridAbstractTest.java:2071)
[12:51:02]W: [org.apache.ignite:ignite-core] at
java.lang.Thread.run(Thread.java:748)
[12:51:03]W: [org.apache.ignite:ignite-core] Aug 04, 2018 9:51:03
AM org.apache.ignite.logger.java.JavaLogger warning
[12:51:03]W: [org.apache.ignite:ignite-core] WARNING: Local node
was dropped from cluster due to network problems, will try to reconnect with
new id after 1ms (reconnect delay can be changed using
IGNITE_DISCO_FAILED_CLIENT_RECONNECT_DELAY system property)
[newId=788c53f8-f985-449a-853e-bf47ed90e388,
prevId=6481a605-7bfb-486d-a796-2a4f1c8d0469, locNode=TcpDiscoveryNode
[id=6481a605-7bfb-486d-a796-2a4f1c8d0469, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:0], discPort=0, order=18, intOrder=0,
lastExchangeTime=1533376229447, loc=true, ver=2.7.0#20180803-sha1:3ab8bbad,
isClient=true], nodeInitiatedFail=53d116c7-bb4f-43e9-b97c-6d3ce404cd51,
msg=null]
[12:51:03]W: [org.apache.ignite:ignite-core] Aug 04, 2018 9:51:03
AM org.apache.ignite.logger.java.JavaLogger info
[12:51:03]W: [org.apache.ignite:ignite-core] INFO: TCP discovery
accepted incoming connection [rmtAddr=/127.0.0.1, rmtPort=53351]
[12:51:03]W: [org.apache.ignite:ignite-core] Aug 04, 2018 9:51:03
AM org.apache.ignite.logger.java.JavaLogger info
[12:51:03]W: [org.apache.ignite:ignite-core] INFO: TCP discovery
spawning a new thread for connection [rmtAddr=/127.0.0.1, rmtPort=53351]
[12:51:03]W: [org.apache.ignite:ignite-core] Aug 04, 2018 9:51:03
AM org.apache.ignite.logger.java.JavaLogger info
[12:51:03]W: [org.apache.ignite:ignite-core] INFO: Started serving
remote node connection [rmtAddr=/127.0.0.1:53351, rmtPort=53351]
[12:51:03]W: [org.apache.ignite:ignite-core] Aug 04, 2018 9:51:03
AM org.apache.ignite.logger.java.JavaLogger info
[12:51:03]W: [org.apache.ignite:ignite-core] INFO: Block join
[12:51:03]W: [org.apache.ignite:ignite-core] Exception in thread
"wal-load-cli" java.lang.IllegalStateException: Grid is in invalid state to
perform this operation. It either not started yet or has already being or have
stopped [igniteInstanceName=cli, state=STOPPING]
[12:51:03]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.GridKernalGatewayImpl.illegalState(GridKernalGatewayImpl.java:201)
[12:51:03]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.GridKernalGatewayImpl.readLock(GridKernalGatewayImpl.java:95)
[12:51:03]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.cluster.ClusterGroupAdapter.guard(ClusterGroupAdapter.java:169)
[12:51:03]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.cluster.IgniteClusterImpl.changeWalMode(IgniteClusterImpl.java:559)
[12:51:03]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.cluster.IgniteClusterImpl.disableWal(IgniteClusterImpl.java:546)
[12:51:03]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.processors.cache.WalModeChangeAdvancedSelfTest$2.run(WalModeChangeAdvancedSelfTest.java:325)
[12:51:03]W: [org.apache.ignite:ignite-core] at
java.lang.Thread.run(Thread.java:748)
[12:51:08]W: [org.apache.ignite:ignite-core] Aug 04, 2018 9:51:08
AM org.apache.ignite.logger.java.JavaLogger warning
[12:51:08]W: [org.apache.ignite:ignite-core] WARNING: Failed to
left node: timeout [nodeId=TcpDiscoveryNode
[id=788c53f8-f985-449a-853e-bf47ed90e388, addrs=ArrayList [127.0.0.1],
sockAddrs=HashSet [/127.0.0.1:0], discPort=0, order=18, intOrder=0,
lastExchangeTime=1533376229447, loc=true, ver=2.7.0#20180803-sha1:3ab8bbad,
isClient=true]]
[12:51:08]W: [org.apache.ignite:ignite-core] Aug 04, 2018 9:51:08
AM java.util.logging.LogManager$RootLogger log
[12:51:08]W: [org.apache.ignite:ignite-core] SEVERE: Critical
system error detected. Will be handled accordingly to configured handler
[hnd=class o.a.i.failure.StopNodeOrHaltFailureHandler,
failureCtx=FailureContext [type=CRITICAL_ERROR, err=class
o.a.i.IgniteException: null]]
[12:51:08]W: [org.apache.ignite:ignite-core] class
org.apache.ignite.IgniteException: null
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.DiscoverySpiTestListener.beforeJoin(DiscoverySpiTestListener.java:86)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi.writeToSocket(TcpDiscoverySpi.java:1632)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.IgniteClientReconnectAbstractTest$TestTcpDiscoverySpi.writeToSocket(IgniteClientReconnectAbstractTest.java:432)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.spi.discovery.tcp.TcpDiscoverySpi.writeToSocket(TcpDiscoverySpi.java:1588)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.spi.discovery.tcp.ClientImpl.sendJoinRequest(ClientImpl.java:721)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.spi.discovery.tcp.ClientImpl.joinTopology(ClientImpl.java:586)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.spi.discovery.tcp.ClientImpl.access$900(ClientImpl.java:137)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.spi.discovery.tcp.ClientImpl$MessageWorker.tryJoin(ClientImpl.java:1920)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.spi.discovery.tcp.ClientImpl$MessageWorker.body(ClientImpl.java:1824)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.util.worker.GridWorker.run(GridWorker.java:110)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.spi.discovery.tcp.ClientImpl$1.body(ClientImpl.java:295)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.spi.IgniteSpiThread.run(IgniteSpiThread.java:62)
[12:51:08]W: [org.apache.ignite:ignite-core] Caused by: class
org.apache.ignite.internal.IgniteInterruptedCheckedException: null
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.util.IgniteUtils.await(IgniteUtils.java:7544)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.DiscoverySpiTestListener.beforeJoin(DiscoverySpiTestListener.java:82)
[12:51:08]W: [org.apache.ignite:ignite-core] ... 11 more
[12:51:08]W: [org.apache.ignite:ignite-core] Caused by:
java.lang.InterruptedException
[12:51:08]W: [org.apache.ignite:ignite-core] at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:998)
[12:51:08]W: [org.apache.ignite:ignite-core] at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
[12:51:08]W: [org.apache.ignite:ignite-core] at
java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
[12:51:08]W: [org.apache.ignite:ignite-core] at
org.apache.ignite.internal.util.IgniteUtils.await(IgniteUtils.java:7539)
[12:51:08]W: [org.apache.ignite:ignite-core] ... 12 more
[12:51:08]W: [org.apache.ignite:ignite-core]
[12:51:08]W: [org.apache.ignite:ignite-core] Aug 04, 2018 9:51:08
AM java.util.logging.LogManager$RootLogger log
[12:51:08]W: [org.apache.ignite:ignite-core] SEVERE: JVM will be
halted immediately due to the failure: [failureCtx=FailureContext
[type=CRITICAL_ERROR, err=class o.a.i.IgniteException: null]]
[12:51:08]W: [org.apache.ignite:ignite-core] Process exited with
code 130
[12:51:08]E: [Step 3/4] Process exited with code 130
{noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
