You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ignite.apache.org by "Pavel Pereslegin (JIRA)" <ji...@apache.org> on 2018/10/31 12:13:01 UTC

[jira] [Updated] (IGNITE-9225) Cache 7 (With Persistence) configuration halted by failure handler.

     [ https://issues.apache.org/jira/browse/IGNITE-9225?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Pavel Pereslegin updated IGNITE-9225:
-------------------------------------
    Ignite Flags:   (was: Docs Required)

> 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
>            Priority: Major
>             Fix For: 2.7
>
>
> WalModeChangeCommonAbstractSelfTest uses default failure handler and can 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)