You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ignite.apache.org by "Oleg Ignatenko (JIRA)" <ji...@apache.org> on 2019/01/14 14:13:01 UTC

[jira] [Commented] (IGNITE-9138) ZookeeperDiscoverySpiTest#checkInternalStructuresCleanup fails.

    [ https://issues.apache.org/jira/browse/IGNITE-9138?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16742098#comment-16742098 ] 

Oleg Ignatenko commented on IGNITE-9138:
----------------------------------------

One recent example of this issue are frequent failures of {{testTopologyChangeMultithreaded_RestartZk}} when tests were run per IGNITE-10777:
{noformat}
junit.framework.AssertionFailedError: Expected: <null> but was: ZkCommunicationErrorProcessFuture [impl=org.apache.ignite.spi.discovery.zk.internal.ZookeeperDiscoveryImpl@422ad5e2, endTime=0, id=null, state=RESOLVE_STARTED, resolveTopVer=28, resErr=null, collectResFut=null]
------- Stderr: -------
[2019-01-14 13:30:38,523][WARN ][WorkerSender[myid=4]][QuorumCnxManager] Cannot open channel to 5 at election address localhost/127.0.0.1:43671
java.net.ConnectException: Connection refused (Connection refused)
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
	at java.net.Socket.connect(Socket.java:589)
	at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:558)
	at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:534)
	at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:454)
	at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:435)
	at java.lang.Thread.run(Thread.java:748)
[2019-01-14 13:30:38,525][WARN ][WorkerSender[myid=4]][QuorumCnxManager] Cannot open channel to 6 at election address localhost/127.0.0.1:46348
java.net.ConnectException: Connection refused (Connection refused)
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
	at java.net.Socket.connect(Socket.java:589)
	at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:558)
	at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:534)
	at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:454)
	at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:435)
	at java.lang.Thread.run(Thread.java:748)
[2019-01-14 13:30:38,625][WARN ][WorkerSender[myid=5]][QuorumCnxManager] Cannot open channel to 6 at election address localhost/127.0.0.1:46348
java.net.ConnectException: Connection refused (Connection refused)
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
	at java.net.Socket.connect(Socket.java:589)
	at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:558)
	at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:534)
	at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:454)
	at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:435)
	at java.lang.Thread.run(Thread.java:748)
[2019-01-14 13:30:38,628][WARN ][WorkerSender[myid=4]][QuorumCnxManager] Cannot open channel to 6 at election address localhost/127.0.0.1:46348
java.net.ConnectException: Connection refused (Connection refused)
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
	at java.net.Socket.connect(Socket.java:589)
	at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:558)
	at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:534)
	at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:454)
	at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:435)
	at java.lang.Thread.run(Thread.java:748)
[2019-01-14 13:30:38,820][WARN ][NIOServerCxn.Factory:0.0.0.0/0.0.0.0:45319][NIOServerCnxn] Exception causing close of session 0x0: ZooKeeperServer not running{noformat}


In case if this can help, here are some prior error messages from build log:
{noformat}
[16:34:03][Step 4/5] [2019-01-14 13:34:03,501][INFO ][zk-restart-thread-1][root] Close zk client socket for node: internal.ZookeeperDiscoverySpiTest42
[16:34:03][org.apache.ignite:ignite-zookeeper] Jan 14, 2019 1:34:03 PM org.apache.ignite.logger.java.JavaLogger info
[16:34:03][org.apache.ignite:ignite-zookeeper] INFO: ZkTestClientCnxnSocketNIO closeSocket [node=internal.ZookeeperDiscoverySpiTest42, block=false]
[16:34:03][org.apache.ignite:ignite-zookeeper] [2019-01-14 13:34:03,501][WARN ][NIOServerCxn.Factory:0.0.0.0/0.0.0.0:46231][NIOServerCnxn] Unable to read additional data from client sessionid 0x800298e27530013, likely client has closed socket
...
[16:34:16][Step 4/5] [2019-01-14 13:34:16,072][INFO ][zk-internal.ZookeeperDiscoverySpiTest48-EventThread][ZookeeperDiscoveryImpl] Discovery coordinator already exists, watch for previous server node [locId=2d3615a5-9810-47be-bf79-eb1e71500008, watchPath=c2b2b79c-68d6-4691-8355-1a97735266bf:97735887-46ea-4346-bf82-fbfcf1100007:80|0000000049]
[16:34:17][org.apache.ignite:ignite-zookeeper] [2019-01-14 13:34:17,457][WARN ][zk-internal.ZookeeperDiscoverySpiTest40-SendThread(localhost:38552)][ClientCnxn] Session 0x800298e27530012 for server localhost/127.0.0.1:38552, unexpected error, closing socket connection and attempting reconnect
[16:34:17][org.apache.ignite:ignite-zookeeper] java.nio.channels.CancelledKeyException
[16:34:17][org.apache.ignite:ignite-zookeeper] 	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
[16:34:17][org.apache.ignite:ignite-zookeeper] 	at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77)
[16:34:17][org.apache.ignite:ignite-zookeeper] 	at org.apache.zookeeper.ClientCnxnSocketNIO.enableWrite(ClientCnxnSocketNIO.java:389)
[16:34:17][org.apache.ignite:ignite-zookeeper] 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:373)
...
[16:34:20][Step 4/5] [2019-01-14 13:34:20,072][INFO ][exchange-worker-#9695%internal.ZookeeperDiscoverySpiTest44%][GridDhtPartitionsExchangeFuture] Finished waiting for partition release future [topVer=AffinityTopologyVersion [topVer=12, minorTopVer=1], waitTime=0ms, futInfo=NA, mode=DISTRIBUTED]
[16:34:20][org.apache.ignite:ignite-zookeeper] [2019-01-14 13:34:20,550][ERROR][sys-#9501%internal.ZookeeperDiscoverySpiTest40%][TcpCommunicationSpi] Failed to send message to remote node [node=ZookeeperClusterNode [id=76244091-170f-41e7-bad5-e49eba700003, addrs=[172.17.0.6], order=5, loc=false, client=false], msg=GridIoMessage [plc=2, topic=TOPIC_METRICS, topicOrd=29, ordered=false, timeout=0, skipOnTimeout=false, msg=ClusterMetricsUpdateMessage []]]
[16:34:20][org.apache.ignite:ignite-zookeeper] class org.apache.ignite.internal.cluster.ClusterTopologyCheckedException: Failed to send message (node left topology): ZookeeperClusterNode [id=76244091-170f-41e7-bad5-e49eba700003, addrs=[172.17.0.6], order=5, loc=false, client=false]
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.createTcpClient(TcpCommunicationSpi.java:3308)
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.createNioClient(TcpCommunicationSpi.java:3019)
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.reserveClient(TcpCommunicationSpi.java:2900)
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.sendMessage0(TcpCommunicationSpi.java:2743)
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at org.apache.ignite.spi.communication.tcp.TcpCommunicationSpi.sendMessage(TcpCommunicationSpi.java:2702)
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at org.apache.ignite.internal.managers.communication.GridIoManager.send(GridIoManager.java:1652)
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at org.apache.ignite.internal.managers.communication.GridIoManager.sendToGridTopic(GridIoManager.java:1726)
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at org.apache.ignite.internal.processors.cluster.ClusterProcessor.updateMetrics(ClusterProcessor.java:489)
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at org.apache.ignite.internal.processors.cluster.ClusterProcessor.access$2200(ClusterProcessor.java:84)
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at org.apache.ignite.internal.processors.cluster.ClusterProcessor$MetricsUpdateTimeoutObject.run(ClusterProcessor.java:775)
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[16:34:20][org.apache.ignite:ignite-zookeeper] 	at java.lang.Thread.run(Thread.java:748)
{noformat}

> ZookeeperDiscoverySpiTest#checkInternalStructuresCleanup fails.
> ---------------------------------------------------------------
>
>                 Key: IGNITE-9138
>                 URL: https://issues.apache.org/jira/browse/IGNITE-9138
>             Project: Ignite
>          Issue Type: Bug
>    Affects Versions: 2.6
>            Reporter: Vitaliy Biryukov
>            Assignee: Vitaliy Biryukov
>            Priority: Major
>              Labels: MakeTeamcityGreenAgain
>             Fix For: 2.8
>
>
>  
> {noformat}
> junit.framework.AssertionFailedError: Expected: <null> but was: ZkCommunicationErrorProcessFuture [impl=org.apache.ignite.spi.discovery.zk.internal.ZookeeperDiscoveryImpl@180b3819, endTime=1532545453881, id=9e083d2d461-645a2360-f5bb-43d3-8327-83d0a4a00124, state=WAIT_TIMEOUT, resolveTopVer=0, resErr=null, collectResFut=null]
>     at org.apache.ignite.spi.discovery.zk.internal.ZookeeperDiscoverySpiTest.checkInternalStructuresCleanup(ZookeeperDiscoverySpiTest.java:517)
>     at org.apache.ignite.spi.discovery.zk.internal.ZookeeperDiscoverySpiTest.afterTest(ZookeeperDiscoverySpiTest.java:476)
> {noformat}



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)