java.lang.InterruptedException: sleep interrupted

Apache's JIRA Issue Tracker | Michael Han | 4 months ago
  1. 0

    From https://builds.apache.org/job/ZooKeeper_branch34_jdk7/1156 {noformat} Error Message waiting for server up Stacktrace junit.framework.AssertionFailedError: waiting for server up at org.apache.zookeeper.test.QuorumBase.startServers(QuorumBase.java:183) at org.apache.zookeeper.test.QuorumBase.startServers(QuorumBase.java:113) at org.apache.zookeeper.test.QuorumZxidSyncTest.testBehindLeader(QuorumZxidSyncTest.java:67) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55) Standard Output 2016-07-21 08:11:45,722 [myid:] - INFO [main:PortAssignment@32] - assigning port 11221 2016-07-21 08:11:45,729 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testBehindLeader 2016-07-21 08:11:45,729 [myid:] - INFO [main:QuorumBase@69] - QuorumBase.setup null 2016-07-21 08:11:45,926 [myid:] - INFO [main:PortAssignment@32] - assigning port 11222 2016-07-21 08:11:45,926 [myid:] - INFO [main:PortAssignment@32] - assigning port 11223 2016-07-21 08:11:45,927 [myid:] - INFO [main:PortAssignment@32] - assigning port 11224 2016-07-21 08:11:45,927 [myid:] - INFO [main:PortAssignment@32] - assigning port 11225 2016-07-21 08:11:45,927 [myid:] - INFO [main:PortAssignment@32] - assigning port 11226 2016-07-21 08:11:45,928 [myid:] - INFO [main:PortAssignment@32] - assigning port 11227 2016-07-21 08:11:45,928 [myid:] - INFO [main:PortAssignment@32] - assigning port 11228 2016-07-21 08:11:45,928 [myid:] - INFO [main:PortAssignment@32] - assigning port 11229 2016-07-21 08:11:45,928 [myid:] - INFO [main:PortAssignment@32] - assigning port 11230 2016-07-21 08:11:45,929 [myid:] - INFO [main:PortAssignment@32] - assigning port 11231 2016-07-21 08:11:45,929 [myid:] - INFO [main:QuorumBase@93] - Ports are: 127.0.0.1:11222,127.0.0.1:11223,127.0.0.1:11224,127.0.0.1:11225,127.0.0.1:11226 2016-07-21 08:11:45,946 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 127.0.0.1 to address: /127.0.0.1 2016-07-21 08:11:45,946 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 127.0.0.1 to address: /127.0.0.1 2016-07-21 08:11:45,948 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 127.0.0.1 to address: /127.0.0.1 2016-07-21 08:11:45,948 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 127.0.0.1 to address: /127.0.0.1 2016-07-21 08:11:45,949 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 127.0.0.1 to address: /127.0.0.1 2016-07-21 08:11:45,949 [myid:] - INFO [main:QuorumBase@142] - creating QuorumPeer 1 port 11222 2016-07-21 08:11:45,961 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11222 2016-07-21 08:11:45,979 [myid:] - INFO [main:QuorumBase@145] - creating QuorumPeer 2 port 11223 2016-07-21 08:11:45,979 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11223 2016-07-21 08:11:45,980 [myid:] - INFO [main:QuorumBase@148] - creating QuorumPeer 3 port 11224 2016-07-21 08:11:45,980 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11224 2016-07-21 08:11:45,981 [myid:] - INFO [main:QuorumBase@151] - creating QuorumPeer 4 port 11225 2016-07-21 08:11:45,981 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11225 2016-07-21 08:11:45,981 [myid:] - INFO [main:QuorumBase@154] - creating QuorumPeer 5 port 11226 2016-07-21 08:11:45,982 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11226 2016-07-21 08:11:45,982 [myid:] - INFO [main:QuorumBase@163] - QuorumPeer 1 voting view: {1=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@47628981, 2=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@163198c4, 3=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@1224773e, 4=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@181090c0, 5=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@678f3997} 2016-07-21 08:11:45,983 [myid:] - INFO [main:QuorumBase@164] - QuorumPeer 2 voting view: {1=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@47628981, 2=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@163198c4, 3=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@1224773e, 4=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@181090c0, 5=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@678f3997} 2016-07-21 08:11:45,983 [myid:] - INFO [main:QuorumBase@165] - QuorumPeer 3 voting view: {1=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@47628981, 2=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@163198c4, 3=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@1224773e, 4=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@181090c0, 5=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@678f3997} 2016-07-21 08:11:45,983 [myid:] - INFO [main:QuorumBase@166] - QuorumPeer 4 voting view: {1=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@47628981, 2=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@163198c4, 3=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@1224773e, 4=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@181090c0, 5=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@678f3997} 2016-07-21 08:11:45,983 [myid:] - INFO [main:QuorumBase@167] - QuorumPeer 5 voting view: {1=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@47628981, 2=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@163198c4, 3=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@1224773e, 4=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@181090c0, 5=org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@678f3997} 2016-07-21 08:11:45,983 [myid:] - INFO [main:QuorumBase@169] - start QuorumPeer 1 2016-07-21 08:11:45,988 [myid:] - INFO [main:QuorumPeer@533] - currentEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-21 08:11:45,990 [myid:] - INFO [main:QuorumPeer@548] - acceptedEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-21 08:11:45,996 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /127.0.0.1:12227 2016-07-21 08:11:46,001 [myid:] - INFO [main:QuorumBase@171] - start QuorumPeer 2 2016-07-21 08:11:46,002 [myid:] - INFO [main:QuorumPeer@533] - currentEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-21 08:11:46,003 [myid:] - INFO [main:QuorumPeer@548] - acceptedEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-21 08:11:46,004 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /127.0.0.1:12228 2016-07-21 08:11:46,006 [myid:] - INFO [main:QuorumBase@173] - start QuorumPeer 3 2016-07-21 08:11:46,006 [myid:] - INFO [main:QuorumPeer@533] - currentEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-21 08:11:46,007 [myid:] - INFO [main:QuorumPeer@548] - acceptedEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-21 08:11:46,007 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11222:QuorumPeer@774] - LOOKING 2016-07-21 08:11:46,008 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11223:QuorumPeer@774] - LOOKING 2016-07-21 08:11:46,009 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /127.0.0.1:12229 2016-07-21 08:11:46,009 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11222:FastLeaderElection@818] - New election. My id = 1, proposed zxid=0x0 2016-07-21 08:11:46,009 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11223:FastLeaderElection@818] - New election. My id = 2, proposed zxid=0x0 2016-07-21 08:11:46,009 [myid:] - INFO [main:QuorumBase@175] - start QuorumPeer 4 2016-07-21 08:11:46,010 [myid:] - INFO [main:QuorumPeer@533] - currentEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-21 08:11:46,011 [myid:] - INFO [main:QuorumPeer@548] - acceptedEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-21 08:11:46,011 [myid:] - INFO [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:11224:QuorumPeer@774] - LOOKING 2016-07-21 08:11:46,011 [myid:] - INFO [/127.0.0.1:12228:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:38924 2016-07-21 08:11:46,011 [myid:] - INFO [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:11224:FastLeaderElection@818] - New election. My id = 3, proposed zxid=0x0 2016-07-21 08:11:46,011 [myid:] - INFO [/127.0.0.1:12227:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:43415 2016-07-21 08:11:46,011 [myid:] - INFO [WorkerSender[myid=1]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (2, 1) 2016-07-21 08:11:46,011 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,013 [myid:] - INFO [WorkerSender[myid=1]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (3, 1) 2016-07-21 08:11:46,014 [myid:] - INFO [/127.0.0.1:12229:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:51548 2016-07-21 08:11:46,014 [myid:] - INFO [main:QuorumBase@177] - start QuorumPeer 5 2016-07-21 08:11:46,015 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /127.0.0.1:12230 2016-07-21 08:11:46,015 [myid:] - INFO [main:QuorumPeer@533] - currentEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-21 08:11:46,015 [myid:] - WARN [WorkerSender[myid=1]:QuorumCnxManager@400] - Cannot open channel to 4 at election address /127.0.0.1:12230 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:381) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:354) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:452) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:433) at java.lang.Thread.run(Thread.java:745) 2016-07-21 08:11:46,018 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,018 [myid:] - INFO [/127.0.0.1:12229:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:51551 2016-07-21 08:11:46,016 [myid:] - INFO [/127.0.0.1:12227:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:43417 2016-07-21 08:11:46,016 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:QuorumPeer@774] - LOOKING 2016-07-21 08:11:46,016 [myid:] - INFO [main:QuorumPeer@548] - acceptedEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-21 08:11:46,019 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:FastLeaderElection@818] - New election. My id = 4, proposed zxid=0x0 2016-07-21 08:11:46,019 [myid:] - INFO [/127.0.0.1:12230:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:46102 2016-07-21 08:11:46,018 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,018 [myid:] - INFO [WorkerSender[myid=2]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (3, 2) 2016-07-21 08:11:46,018 [myid:] - INFO [WorkerSender[myid=1]:QuorumPeer$QuorumServer@149] - Resolved hostname: 127.0.0.1 to address: /127.0.0.1 2016-07-21 08:11:46,018 [myid:] - INFO [/127.0.0.1:12228:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:38928 2016-07-21 08:11:46,021 [myid:] - INFO [WorkerSender[myid=2]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (4, 2) 2016-07-21 08:11:46,021 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,021 [myid:] - INFO [/127.0.0.1:12229:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:51553 2016-07-21 08:11:46,020 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,019 [myid:] - INFO [WorkerSender[myid=3]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (4, 3) 2016-07-21 08:11:46,022 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,021 [myid:] - WARN [WorkerSender[myid=2]:QuorumCnxManager@400] - Cannot open channel to 5 at election address /127.0.0.1:12231 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:381) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:354) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:452) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:433) at java.lang.Thread.run(Thread.java:745) 2016-07-21 08:11:46,021 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,021 [myid:] - WARN [WorkerSender[myid=1]:QuorumCnxManager@400] - Cannot open channel to 5 at election address /127.0.0.1:12231 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:381) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:354) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:452) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:433) at java.lang.Thread.run(Thread.java:745) 2016-07-21 08:11:46,023 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,023 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,023 [myid:] - INFO [WorkerSender[myid=2]:QuorumPeer$QuorumServer@149] - Resolved hostname: 127.0.0.1 to address: /127.0.0.1 2016-07-21 08:11:46,024 [myid:] - INFO [/127.0.0.1:12230:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:46104 2016-07-21 08:11:46,022 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /127.0.0.1:12231 2016-07-21 08:11:46,022 [myid:] - WARN [WorkerSender[myid=3]:QuorumCnxManager@400] - Cannot open channel to 5 at election address /127.0.0.1:12231 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:579) at org.apache.zookeeper.server.quorum.QuorumCnxManager.connectOne(QuorumCnxManager.java:381) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:354) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:452) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:433) at java.lang.Thread.run(Thread.java:745) 2016-07-21 08:11:46,025 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,025 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,025 [myid:] - INFO [main:QuorumBase@179] - started QuorumPeer 5 2016-07-21 08:11:46,026 [myid:] - INFO [main:QuorumBase@181] - Checking ports 127.0.0.1:11222,127.0.0.1:11223,127.0.0.1:11224,127.0.0.1:11225,127.0.0.1:11226 2016-07-21 08:11:46,025 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,025 [myid:] - INFO [/127.0.0.1:12227:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:43428 2016-07-21 08:11:46,027 [myid:] - INFO [/127.0.0.1:12230:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:46109 2016-07-21 08:11:46,025 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,024 [myid:] - INFO [WorkerSender[myid=1]:QuorumPeer$QuorumServer@149] - Resolved hostname: 127.0.0.1 to address: /127.0.0.1 2016-07-21 08:11:46,027 [myid:] - INFO [WorkerSender[myid=4]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (5, 4) 2016-07-21 08:11:46,027 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 4 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,026 [myid:] - INFO [/127.0.0.1:12228:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:38938 2016-07-21 08:11:46,025 [myid:] - INFO [WorkerSender[myid=3]:QuorumPeer$QuorumServer@149] - Resolved hostname: 127.0.0.1 to address: /127.0.0.1 2016-07-21 08:11:46,025 [myid:] - INFO [WorkerSender[myid=2]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (4, 2) 2016-07-21 08:11:46,028 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11222 2016-07-21 08:11:46,028 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@810] - Connection broken for id 2, my id = 4, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.net.SocketInputStream.read(SocketInputStream.java:210) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:11:46,029 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:11:46,028 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 4 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,027 [myid:] - INFO [QuorumPeer[myid=5]/0:0:0:0:0:0:0:0:11226:QuorumPeer@774] - LOOKING 2016-07-21 08:11:46,027 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,027 [myid:] - INFO [/127.0.0.1:12231:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:52086 2016-07-21 08:11:46,030 [myid:] - WARN [RecvWorker:4:QuorumCnxManager$RecvWorker@810] - Connection broken for id 4, my id = 2, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:11:46,030 [myid:] - WARN [SendWorker:4:QuorumCnxManager$SendWorker@732] - Exception when using channel: for id 4 my id = 2 error = java.net.SocketException: Broken pipe 2016-07-21 08:11:46,029 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,031 [myid:] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11222:NIOServerCnxnFactory@192] - Accepted socket connection from /127.0.0.1:52363 2016-07-21 08:11:46,029 [myid:] - INFO [/127.0.0.1:12228:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:38940 2016-07-21 08:11:46,029 [myid:] - INFO [WorkerSender[myid=1]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (5, 1) 2016-07-21 08:11:46,029 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,032 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,032 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,029 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@732] - Exception when using channel: for id 2 my id = 4 error = java.net.SocketException: Socket closed 2016-07-21 08:11:46,033 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:11:46,029 [myid:] - INFO [WorkerSender[myid=2]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (5, 2) 2016-07-21 08:11:46,028 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,033 [myid:] - INFO [WorkerSender[myid=1]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (5, 1) 2016-07-21 08:11:46,032 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,031 [myid:] - INFO [/127.0.0.1:12231:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:52088 2016-07-21 08:11:46,031 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,031 [myid:] - INFO [/127.0.0.1:12230:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:46117 2016-07-21 08:11:46,030 [myid:] - WARN [SendWorker:4:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:11:46,030 [myid:] - WARN [RecvWorker:4:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:11:46,030 [myid:] - INFO [WorkerSender[myid=3]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (5, 3) 2016-07-21 08:11:46,030 [myid:] - INFO [QuorumPeer[myid=5]/0:0:0:0:0:0:0:0:11226:FastLeaderElection@818] - New election. My id = 5, proposed zxid=0x0 2016-07-21 08:11:46,030 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 4 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,034 [myid:] - INFO [/127.0.0.1:12228:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:38947 2016-07-21 08:11:46,034 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,034 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,033 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,035 [myid:] - INFO [/127.0.0.1:12231:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:52089 2016-07-21 08:11:46,035 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,036 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,036 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,037 [myid:] - INFO [/127.0.0.1:12227:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:43442 2016-07-21 08:11:46,036 [myid:] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 4 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,036 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,037 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 4 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,037 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,038 [myid:] - INFO [/127.0.0.1:12231:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:52091 2016-07-21 08:11:46,037 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 3 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,036 [myid:] - INFO [WorkerSender[myid=1]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (5, 1) 2016-07-21 08:11:46,038 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,038 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,038 [myid:] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,038 [myid:] - INFO [/127.0.0.1:12229:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:51573 2016-07-21 08:11:46,038 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,037 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,039 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 5 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,039 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,039 [myid:] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,040 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 5 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,039 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,039 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 5 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,039 [myid:] - INFO [/127.0.0.1:12231:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:52093 2016-07-21 08:11:46,040 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,040 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,040 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,040 [myid:] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 5 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,041 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,041 [myid:] - INFO [/127.0.0.1:12227:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:43444 2016-07-21 08:11:46,041 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 4 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,041 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@810] - Connection broken for id 1, my id = 5, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.io.DataInputStream.readFully(DataInputStream.java:195) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:805) 2016-07-21 08:11:46,042 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:11:46,041 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 4 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,041 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:11:46,041 [myid:] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11222:NIOServerCnxn@827] - Processing stat command from /127.0.0.1:52363 2016-07-21 08:11:46,041 [myid:] - WARN [RecvWorker:5:QuorumCnxManager$RecvWorker@810] - Connection broken for id 5, my id = 1, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:11:46,043 [myid:] - WARN [RecvWorker:5:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:11:46,041 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,041 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,043 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 4 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,043 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:11:46,042 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 5 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,042 [myid:] - WARN [SendWorker:5:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:11:46,044 [myid:] - WARN [SendWorker:5:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:11:46,042 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,042 [myid:] - INFO [/127.0.0.1:12231:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:52096 2016-07-21 08:11:46,041 [myid:] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@600] - Notification: 1 (message format version), 4 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,045 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:11:46,045 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:11:46,045 [myid:] - INFO [Thread-2:NIOServerCnxn@1008] - Closed socket connection for client /127.0.0.1:52363 (no session established for client) 2016-07-21 08:11:46,044 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,044 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,044 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 4 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,046 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,045 [myid:] - INFO [/127.0.0.1:12227:QuorumCnxManager$Listener@541] - Received connection request /127.0.0.1:43446 2016-07-21 08:11:46,045 [myid:] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,045 [myid:] - WARN [RecvWorker:5:QuorumCnxManager$RecvWorker@810] - Connection broken for id 5, my id = 1, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:11:46,047 [myid:] - WARN [RecvWorker:5:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:11:46,045 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@810] - Connection broken for id 1, my id = 5, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.net.SocketInputStream.read(SocketInputStream.java:210) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:11:46,047 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:11:46,047 [myid:] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 4 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,047 [myid:] - WARN [SendWorker:5:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:11:46,048 [myid:] - WARN [SendWorker:5:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:11:46,046 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,048 [myid:] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 3 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,048 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 5 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,049 [myid:] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,049 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 5 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,049 [myid:] - INFO [WorkerReceiver[myid=5]:FastLeaderElection@600] - Notification: 1 (message format version), 5 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-21 08:11:46,245 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:QuorumPeer@844] - FOLLOWING 2016-07-21 08:11:46,246 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11223:QuorumPeer@844] - FOLLOWING 2016-07-21 08:11:46,247 [myid:] - INFO [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:11224:QuorumPeer@844] - FOLLOWING 2016-07-21 08:11:46,249 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11222:QuorumPeer@844] - FOLLOWING 2016-07-21 08:11:46,249 [myid:] - INFO [QuorumPeer[myid=5]/0:0:0:0:0:0:0:0:11226:QuorumPeer@856] - LEADING 2016-07-21 08:11:46,251 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Learner@86] - TCP NoDelay set to: true 2016-07-21 08:11:46,255 [myid:] - INFO [QuorumPeer[myid=5]/0:0:0:0:0:0:0:0:11226:Leader@59] - TCP NoDelay set to: true 2016-07-21 08:11:46,259 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Environment@100] - Server environment:zookeeper.version=3.4.9-SNAPSHOT-1753645, built on 07/21/2016 07:46 GMT 2016-07-21 08:11:46,259 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Environment@100] - Server environment:host.name=asf907.gq1.ygridcore.net 2016-07-21 08:11:46,260 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Environment@100] - Server environment:java.version=1.7.0_80 2016-07-21 08:11:46,260 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Environment@100] - Server environment:java.vendor=Oracle Corporation 2016-07-21 08:11:46,260 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Environment@100] - Server environment:java.home=/home/jenkins/jenkins-slave/tools/hudson.model.JDK/latest1.7/jre 2016-07-21 08:11:46,260 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Environment@100] - Server environment:java.class.path=/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/antlr-2.7.6.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/checkstyle-5.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-beanutils-core-1.7.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-cli-1.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-collections-3.2.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-lang-1.0.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/commons-logging-1.0.3.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/google-collections-0.9.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/junit-4.8.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/test/lib/mockito-all-1.8.2.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/classes:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/jline-0.9.94.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/log4j-1.2.16.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/netty-3.10.5.Final.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/slf4j-api-1.6.1.jar:/home/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk7/branch-3.4/build/lib/slf4j-log4j12-1.6.1.jar:/home/jenkins/tools/ant/apache-ant-1.9.4/lib/ant-launcher.jar:/home/jenkins/tools/ant/latest/lib/ant-junit.jar:/home/jenkins/tools/ant/latest/lib/ant-junit4.jar 2016-07-21 08:11:46,260 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Environment@100] - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib 2016-07-21 08:11:46,260 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Environment@100] - Server environment:java.io.tmpdir=/tmp 2016-07-21 08:11:46,260 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Environment@100] - Server environment:java.compiler=<NA> 2016-07-21 08:11:46,260 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Environment@100] - Server environment:os.name=Linux 2016-07-21 08:11:46,260 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Environment@100] - Server environment:os.arch=amd64 2016-07-21 08:11:46,260 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11225:Environment@100] - Server environment:os.version=3.13.0-36-lowlatency 2016-07-21 08:11:46,260 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0: ...[truncated 1420555 chars]... ager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:21,678 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:21,672 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@810] - Connection broken for id 1, my id = 5, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:21,679 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:21,672 [myid:] - WARN [SendWorker:5:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:21,679 [myid:] - WARN [SendWorker:5:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:21,679 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:21,679 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:21,678 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:21,679 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:21,677 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:21,680 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:21,675 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:21,680 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:22,000 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-21 08:14:22,317 [myid:] - INFO [/127.0.0.1:12241:QuorumCnxManager$Listener@560] - Leaving listener 2016-07-21 08:14:22,320 [myid:] - INFO [/127.0.0.1:12242:QuorumCnxManager$Listener@560] - Leaving listener 2016-07-21 08:14:22,579 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11233:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:850) 2016-07-21 08:14:22,579 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11233:FollowerZooKeeperServer@140] - Shutting down 2016-07-21 08:14:22,579 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11233:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:14:22,579 [myid:] - WARN [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11233:QuorumPeer@874] - QuorumPeer main thread exited 2016-07-21 08:14:22,582 [myid:] - INFO [main:QuorumBase@306] - Shutting down quorum peer QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11234 2016-07-21 08:14:22,582 [myid:] - INFO [main:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:891) at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:307) at org.apache.zookeeper.test.QuorumBase.shutdownServers(QuorumBase.java:298) at org.apache.zookeeper.test.QuorumBase.tearDown(QuorumBase.java:285) at org.apache.zookeeper.test.QuorumZxidSyncTest.tearDown(QuorumZxidSyncTest.java:169) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37) at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:532) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1179) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1030) 2016-07-21 08:14:22,582 [myid:] - INFO [main:FollowerZooKeeperServer@140] - Shutting down 2016-07-21 08:14:22,582 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:14:22,582 [myid:] - INFO [main:FollowerRequestProcessor@107] - Shutting down 2016-07-21 08:14:22,582 [myid:] - INFO [main:CommitProcessor@184] - Shutting down 2016-07-21 08:14:22,582 [myid:] - INFO [FollowerRequestProcessor:2:FollowerRequestProcessor@97] - FollowerRequestProcessor exited loop! 2016-07-21 08:14:22,582 [myid:] - INFO [CommitProcessor:2:CommitProcessor@153] - CommitProcessor exited loop! 2016-07-21 08:14:22,582 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:14:22,583 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:14:22,583 [myid:] - INFO [SyncThread:2:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:14:22,584 [myid:] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11234:NIOServerCnxnFactory@219] - NIOServerCnxn factory exited run method 2016-07-21 08:14:22,585 [myid:] - WARN [SendWorker:3:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:22,585 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@810] - Connection broken for id 2, my id = 4, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:22,585 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:22,585 [myid:] - WARN [RecvWorker:3:QuorumCnxManager$RecvWorker@810] - Connection broken for id 3, my id = 2, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.net.SocketInputStream.read(SocketInputStream.java:210) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:22,586 [myid:] - WARN [RecvWorker:3:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:22,585 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@810] - Connection broken for id 2, my id = 5, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:22,586 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:22,585 [myid:] - WARN [RecvWorker:5:QuorumCnxManager$RecvWorker@810] - Connection broken for id 5, my id = 2, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.net.SocketInputStream.read(SocketInputStream.java:210) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:22,587 [myid:] - WARN [RecvWorker:5:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:22,585 [myid:] - WARN [SendWorker:3:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:22,585 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@810] - Connection broken for id 2, my id = 3, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:22,587 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:22,585 [myid:] - WARN [SendWorker:5:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:22,587 [myid:] - WARN [SendWorker:5:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:22,585 [myid:] - ERROR [/127.0.0.1:12239:QuorumCnxManager$Listener@547] - Exception while listening java.net.SocketException: Socket closed at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398) at java.net.ServerSocket.implAccept(ServerSocket.java:530) at java.net.ServerSocket.accept(ServerSocket.java:498) at org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:539) 2016-07-21 08:14:22,587 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:22,588 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:22,587 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:22,589 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:22,586 [myid:] - WARN [SendWorker:4:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:22,589 [myid:] - WARN [SendWorker:4:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:22,586 [myid:] - WARN [RecvWorker:4:QuorumCnxManager$RecvWorker@810] - Connection broken for id 4, my id = 2, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.net.SocketInputStream.read(SocketInputStream.java:210) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:22,589 [myid:] - WARN [RecvWorker:4:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:22,586 [myid:] - INFO [main:QuorumBase@310] - Shutting down leader election QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11234 2016-07-21 08:14:22,589 [myid:] - INFO [main:QuorumBase@315] - Waiting for QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11234 to exit thread 2016-07-21 08:14:22,585 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:22,590 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:22,673 [myid:] - INFO [/127.0.0.1:12238:QuorumCnxManager$Listener@560] - Leaving listener 2016-07-21 08:14:23,079 [myid:] - INFO [WorkerSender[myid=3]:FastLeaderElection$Messenger$WorkerSender@438] - WorkerSender is down 2016-07-21 08:14:23,080 [myid:] - INFO [WorkerSender[myid=4]:FastLeaderElection$Messenger$WorkerSender@438] - WorkerSender is down 2016-07-21 08:14:23,084 [myid:] - INFO [WorkerSender[myid=5]:FastLeaderElection$Messenger$WorkerSender@438] - WorkerSender is down 2016-07-21 08:14:23,088 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection$Messenger$WorkerReceiver@407] - WorkerReceiver is down 2016-07-21 08:14:23,088 [myid:] - INFO [WorkerReceiver[myid=4]:FastLeaderElection$Messenger$WorkerReceiver@407] - WorkerReceiver is down 2016-07-21 08:14:23,089 [myid:] - INFO [WorkerReceiver[myid=5]:FastLeaderElection$Messenger$WorkerReceiver@407] - WorkerReceiver is down 2016-07-21 08:14:23,578 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11234:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:850) 2016-07-21 08:14:23,578 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11234:FollowerZooKeeperServer@140] - Shutting down 2016-07-21 08:14:23,578 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11234:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:14:23,578 [myid:] - WARN [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11234:QuorumPeer@874] - QuorumPeer main thread exited 2016-07-21 08:14:23,579 [myid:] - INFO [main:QuorumBase@306] - Shutting down quorum peer QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:11235 2016-07-21 08:14:23,579 [myid:] - INFO [main:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:891) at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:307) at org.apache.zookeeper.test.QuorumBase.shutdownServers(QuorumBase.java:299) at org.apache.zookeeper.test.QuorumBase.tearDown(QuorumBase.java:285) at org.apache.zookeeper.test.QuorumZxidSyncTest.tearDown(QuorumZxidSyncTest.java:169) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37) at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:532) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1179) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1030) 2016-07-21 08:14:23,579 [myid:] - INFO [main:FollowerZooKeeperServer@140] - Shutting down 2016-07-21 08:14:23,579 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:14:23,580 [myid:] - INFO [main:FollowerRequestProcessor@107] - Shutting down 2016-07-21 08:14:23,580 [myid:] - INFO [main:CommitProcessor@184] - Shutting down 2016-07-21 08:14:23,580 [myid:] - INFO [FollowerRequestProcessor:3:FollowerRequestProcessor@97] - FollowerRequestProcessor exited loop! 2016-07-21 08:14:23,580 [myid:] - INFO [CommitProcessor:3:CommitProcessor@153] - CommitProcessor exited loop! 2016-07-21 08:14:23,580 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:14:23,581 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:14:23,581 [myid:] - INFO [SyncThread:3:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:14:23,582 [myid:] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11235:NIOServerCnxnFactory@219] - NIOServerCnxn factory exited run method 2016-07-21 08:14:23,583 [myid:] - ERROR [/127.0.0.1:12240:QuorumCnxManager$Listener@547] - Exception while listening java.net.SocketException: Socket closed at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398) at java.net.ServerSocket.implAccept(ServerSocket.java:530) at java.net.ServerSocket.accept(ServerSocket.java:498) at org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:539) 2016-07-21 08:14:23,583 [myid:] - WARN [SendWorker:5:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:23,585 [myid:] - WARN [SendWorker:5:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:23,584 [myid:] - WARN [RecvWorker:4:QuorumCnxManager$RecvWorker@810] - Connection broken for id 4, my id = 3, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.net.SocketInputStream.read(SocketInputStream.java:210) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:23,585 [myid:] - WARN [RecvWorker:4:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:23,584 [myid:] - WARN [SendWorker:4:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:23,585 [myid:] - WARN [SendWorker:4:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:23,584 [myid:] - WARN [RecvWorker:5:QuorumCnxManager$RecvWorker@810] - Connection broken for id 5, my id = 3, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.net.SocketInputStream.read(SocketInputStream.java:210) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:23,585 [myid:] - WARN [RecvWorker:5:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:23,584 [myid:] - WARN [RecvWorker:3:QuorumCnxManager$RecvWorker@810] - Connection broken for id 3, my id = 5, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:23,586 [myid:] - WARN [RecvWorker:3:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:23,584 [myid:] - WARN [RecvWorker:3:QuorumCnxManager$RecvWorker@810] - Connection broken for id 3, my id = 4, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:23,586 [myid:] - WARN [RecvWorker:3:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:23,584 [myid:] - INFO [main:QuorumBase@310] - Shutting down leader election QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:11235 2016-07-21 08:14:23,586 [myid:] - INFO [main:QuorumBase@315] - Waiting for QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:11235 to exit thread 2016-07-21 08:14:23,586 [myid:] - WARN [SendWorker:3:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:23,586 [myid:] - WARN [SendWorker:3:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:23,586 [myid:] - WARN [SendWorker:3:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:23,587 [myid:] - WARN [SendWorker:3:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:23,588 [myid:] - INFO [/127.0.0.1:12239:QuorumCnxManager$Listener@560] - Leaving listener 2016-07-21 08:14:24,355 [myid:] - INFO [WorkerSender[myid=2]:FastLeaderElection$Messenger$WorkerSender@438] - WorkerSender is down 2016-07-21 08:14:24,358 [myid:] - INFO [WorkerSender[myid=1]:FastLeaderElection$Messenger$WorkerSender@438] - WorkerSender is down 2016-07-21 08:14:24,360 [myid:] - INFO [WorkerSender[myid=3]:FastLeaderElection$Messenger$WorkerSender@438] - WorkerSender is down 2016-07-21 08:14:24,361 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection$Messenger$WorkerReceiver@407] - WorkerReceiver is down 2016-07-21 08:14:24,361 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection$Messenger$WorkerReceiver@407] - WorkerReceiver is down 2016-07-21 08:14:24,362 [myid:] - INFO [WorkerReceiver[myid=3]:FastLeaderElection$Messenger$WorkerReceiver@407] - WorkerReceiver is down 2016-07-21 08:14:24,578 [myid:] - INFO [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:11235:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:850) 2016-07-21 08:14:24,578 [myid:] - INFO [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:11235:FollowerZooKeeperServer@140] - Shutting down 2016-07-21 08:14:24,578 [myid:] - INFO [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:11235:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:14:24,578 [myid:] - WARN [QuorumPeer[myid=3]/0:0:0:0:0:0:0:0:11235:QuorumPeer@874] - QuorumPeer main thread exited 2016-07-21 08:14:24,579 [myid:] - INFO [main:QuorumBase@306] - Shutting down quorum peer QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11236 2016-07-21 08:14:24,579 [myid:] - INFO [main:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:891) at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:307) at org.apache.zookeeper.test.QuorumBase.shutdownServers(QuorumBase.java:300) at org.apache.zookeeper.test.QuorumBase.tearDown(QuorumBase.java:285) at org.apache.zookeeper.test.QuorumZxidSyncTest.tearDown(QuorumZxidSyncTest.java:169) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37) at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:532) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1179) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1030) 2016-07-21 08:14:24,580 [myid:] - INFO [main:FollowerZooKeeperServer@140] - Shutting down 2016-07-21 08:14:24,581 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:14:24,581 [myid:] - INFO [main:FollowerRequestProcessor@107] - Shutting down 2016-07-21 08:14:24,581 [myid:] - INFO [main:CommitProcessor@184] - Shutting down 2016-07-21 08:14:24,581 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:14:24,581 [myid:] - INFO [FollowerRequestProcessor:4:FollowerRequestProcessor@97] - FollowerRequestProcessor exited loop! 2016-07-21 08:14:24,581 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:14:24,581 [myid:] - INFO [CommitProcessor:4:CommitProcessor@153] - CommitProcessor exited loop! 2016-07-21 08:14:24,582 [myid:] - INFO [SyncThread:4:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:14:24,583 [myid:] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11236:NIOServerCnxnFactory@219] - NIOServerCnxn factory exited run method 2016-07-21 08:14:24,585 [myid:] - INFO [main:QuorumBase@310] - Shutting down leader election QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11236 2016-07-21 08:14:24,586 [myid:] - ERROR [/127.0.0.1:12241:QuorumCnxManager$Listener@547] - Exception while listening java.net.SocketException: Socket closed at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398) at java.net.ServerSocket.implAccept(ServerSocket.java:530) at java.net.ServerSocket.accept(ServerSocket.java:498) at org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:539) 2016-07-21 08:14:24,586 [myid:] - WARN [SendWorker:5:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:24,586 [myid:] - WARN [SendWorker:5:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:24,586 [myid:] - INFO [main:QuorumBase@315] - Waiting for QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11236 to exit thread 2016-07-21 08:14:24,586 [myid:] - WARN [RecvWorker:4:QuorumCnxManager$RecvWorker@810] - Connection broken for id 4, my id = 5, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:24,587 [myid:] - WARN [RecvWorker:4:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:24,585 [myid:] - INFO [/127.0.0.1:12240:QuorumCnxManager$Listener@560] - Leaving listener 2016-07-21 08:14:24,585 [myid:] - WARN [RecvWorker:5:QuorumCnxManager$RecvWorker@810] - Connection broken for id 5, my id = 4, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.net.SocketInputStream.read(SocketInputStream.java:210) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-21 08:14:24,588 [myid:] - WARN [RecvWorker:5:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-21 08:14:24,588 [myid:] - WARN [SendWorker:4:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2017) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2095) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:389) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-21 08:14:24,588 [myid:] - WARN [SendWorker:4:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-21 08:14:25,579 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11236:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:850) 2016-07-21 08:14:25,579 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11236:FollowerZooKeeperServer@140] - Shutting down 2016-07-21 08:14:25,579 [myid:] - INFO [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11236:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:14:25,579 [myid:] - WARN [QuorumPeer[myid=4]/0:0:0:0:0:0:0:0:11236:QuorumPeer@874] - QuorumPeer main thread exited 2016-07-21 08:14:25,579 [myid:] - INFO [main:QuorumBase@306] - Shutting down quorum peer QuorumPeer[myid=5]/0:0:0:0:0:0:0:0:11237 2016-07-21 08:14:25,579 [myid:] - INFO [main:Leader@496] - Shutting down 2016-07-21 08:14:25,580 [myid:] - INFO [main:Leader@502] - Shutdown called java.lang.Exception: shutdown Leader! reason: quorum Peer shutdown at org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:502) at org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:888) at org.apache.zookeeper.test.QuorumBase.shutdown(QuorumBase.java:307) at org.apache.zookeeper.test.QuorumBase.shutdownServers(QuorumBase.java:301) at org.apache.zookeeper.test.QuorumBase.tearDown(QuorumBase.java:285) at org.apache.zookeeper.test.QuorumZxidSyncTest.tearDown(QuorumZxidSyncTest.java:169) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37) at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:532) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1179) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1030) 2016-07-21 08:14:25,581 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-21 08:14:25,581 [myid:] - INFO [LearnerCnxAcceptor-/127.0.0.1:12237:Leader$LearnerCnxAcceptor@325] - exception while shutting down acceptor: java.net.SocketException: Socket closed 2016-07-21 08:14:25,582 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-21 08:14:25,582 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-21 08:14:25,582 [myid:] - INFO [main:ProposalRequestProcessor@88] - Shutting down 2016-07-21 08:14:25,582 [myid:] - INFO [main:CommitProcessor@184] - Shutting down 2016-07-21 08:14:25,582 [myid:] - INFO [ProcessThread(sid:5 cport:-1)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-21 08:14:25,583 [myid:] - INFO [CommitProcessor:5:CommitProcessor@153] - CommitProcessor exited loop! 2016-07-21 08:14:25,582 [myid:] - INFO [main:Leader$ToBeAppliedRequestProcessor@661] - Shutting down 2016-07-21 08:14:25,583 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-21 08:14:25,583 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-21 08:14:25,583 [myid:] - INFO [SyncThread:5:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-21 08:14:25,585 [myid:] - WARN [LearnerHandler-/127.0.0.1:43485:LearnerHandler@644] - ******* GOODBYE /127.0.0.1:43485 ******** 2016-07-21 08:14:25,585 [myid:] - WARN [LearnerHandler-/127.0.0.1:43486:LearnerHandler@644] - ******* GOODBYE /127.0.0.1:43486 ******** 2016-07-21 08:14:25,585 [myid:] - WARN [LearnerHandler-/127.0.0.1:43486:LearnerHandler@656] - Ignoring unexpected exception java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1219) at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:340) at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:338) at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:654) at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:647) 2016-07-21 08:14:25,585 [myid:] - WARN [LearnerHandler-/127.0.0.1:43485:LearnerHandler@656] - Ignoring unexpected exception java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1219) at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:340) at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:338) at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:654) at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:647) 2016-07-21 08:14:25,585 [myid:] - WARN [LearnerHandler-/127.0.0.1:43488:LearnerHandler@644] - ******* GOODBYE /127.0.0.1:43488 ******** 2016-07-21 08:14:25,586 [myid:] - INFO [/127.0.0.1:12241:QuorumCnxManager$Listener@560] - Leaving listener 2016-07-21 08:14:25,586 [myid:] - WARN [LearnerHandler-/127.0.0.1:43487:LearnerHandler@644] - ******* GOODBYE /127.0.0.1:43487 ******** 2016-07-21 08:14:25,586 [myid:] - WARN [LearnerHandler-/127.0.0.1:43487:LearnerHandler@656] - Ignoring unexpected exception java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1219) at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:340) at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:338) at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:654) at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:647) 2016-07-21 08:14:25,586 [myid:] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11237:NIOServerCnxnFactory@219] - NIOServerCnxn factory exited run method 2016-07-21 08:14:25,586 [myid:] - WARN [LearnerHandler-/127.0.0.1:43488:LearnerHandler@656] - Ignoring unexpected exception java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1219) at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:340) at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:338) at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:654) at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:647) 2016-07-21 08:14:25,587 [myid:] - WARN [QuorumPeer[myid=5]/0:0:0:0:0:0:0:0:11237:QuorumPeer@862] - Unexpected exception java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:456) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:859) 2016-07-21 08:14:25,588 [myid:] - INFO [QuorumPeer[myid=5]/0:0:0:0:0:0:0:0:11237:Leader@496] - Shutting down 2016-07-21 08:14:25,588 [myid:] - INFO [main:QuorumBase@310] - Shutting down leader election QuorumPeer[myid=5]/0:0:0:0:0:0:0:0:11237 2016-07-21 08:14:25,588 [myid:] - ERROR [/127.0.0.1:12242:QuorumCnxManager$Listener@547] - Exception while listening java.net.SocketException: Socket closed at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398) at java.net.ServerSocket.implAccept(ServerSocket.java:530) at java.net.ServerSocket.accept(ServerSocket.java:498) at org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:539) 2016-07-21 08:14:25,588 [myid:] - INFO [main:QuorumBase@315] - Waiting for QuorumPeer[myid=5]/0:0:0:0:0:0:0:0:11237 to exit thread 2016-07-21 08:14:25,588 [myid:] - WARN [QuorumPeer[myid=5]/0:0:0:0:0:0:0:0:11237:QuorumPeer@874] - QuorumPeer main thread exited 2016-07-21 08:14:25,589 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11233 2016-07-21 08:14:25,589 [myid:] - INFO [main:QuorumBase@291] - 127.0.0.1:11233 is no longer accepting client connections 2016-07-21 08:14:25,589 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11234 2016-07-21 08:14:25,589 [myid:] - INFO [main:QuorumBase@291] - 127.0.0.1:11234 is no longer accepting client connections 2016-07-21 08:14:25,590 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11235 2016-07-21 08:14:25,590 [myid:] - INFO [main:QuorumBase@291] - 127.0.0.1:11235 is no longer accepting client connections 2016-07-21 08:14:25,590 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11236 2016-07-21 08:14:25,590 [myid:] - INFO [main:QuorumBase@291] - 127.0.0.1:11236 is no longer accepting client connections 2016-07-21 08:14:25,590 [myid:] - INFO [main:FourLetterWordMain@62] - connecting to 127.0.0.1 11237 2016-07-21 08:14:25,590 [myid:] - INFO [main:QuorumBase@291] - 127.0.0.1:11237 is no longer accepting client connections 2016-07-21 08:14:25,592 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testLateLogs 2016-07-21 08:14:25,592 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testLateLogs {noformat}

    Apache's JIRA Issue Tracker | 4 months ago | Michael Han
    java.lang.InterruptedException: sleep interrupted
  2. 0

    {noformat} Error Message Broken pipe Stacktrace java.io.IOException: Broken pipe at sun.nio.ch.FileDispatcherImpl.write0(Native Method) at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) at sun.nio.ch.IOUtil.write(IOUtil.java:65) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:466) at java.nio.channels.Channels.writeFullyImpl(Channels.java:78) at java.nio.channels.Channels.writeFully(Channels.java:98) at java.nio.channels.Channels.access$000(Channels.java:61) at java.nio.channels.Channels$1.write(Channels.java:174) at java.io.OutputStream.write(OutputStream.java:75) at java.nio.channels.Channels$1.write(Channels.java:155) at java.io.DataOutputStream.writeInt(DataOutputStream.java:198) at org.apache.zookeeper.server.quorum.CnxManagerTest.testCnxFromFutureVersion(CnxManagerTest.java:318) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55) Standard Output 2016-07-12 22:34:46,623 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testCnxFromFutureVersion 2016-07-12 22:34:46,627 [myid:] - INFO [main:PortAssignment@32] - assigning port 11221 2016-07-12 22:34:46,630 [myid:] - INFO [main:PortAssignment@32] - assigning port 11222 2016-07-12 22:34:46,631 [myid:] - INFO [main:PortAssignment@32] - assigning port 11223 2016-07-12 22:34:46,643 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:46,658 [myid:] - INFO [main:PortAssignment@32] - assigning port 11224 2016-07-12 22:34:46,658 [myid:] - INFO [main:PortAssignment@32] - assigning port 11225 2016-07-12 22:34:46,659 [myid:] - INFO [main:PortAssignment@32] - assigning port 11226 2016-07-12 22:34:46,659 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:46,659 [myid:] - INFO [main:PortAssignment@32] - assigning port 11227 2016-07-12 22:34:46,659 [myid:] - INFO [main:PortAssignment@32] - assigning port 11228 2016-07-12 22:34:46,659 [myid:] - INFO [main:PortAssignment@32] - assigning port 11229 2016-07-12 22:34:46,660 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:46,660 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testCnxFromFutureVersion 2016-07-12 22:34:46,672 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11225 2016-07-12 22:34:46,692 [myid:] - INFO [main:CnxManagerTest@301] - Election port: 11226 2016-07-12 22:34:46,692 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /0.0.0.0:11226 2016-07-12 22:34:47,696 [myid:] - INFO [/0.0.0.0:11226:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:48724 2016-07-12 22:34:49,700 [myid:] - WARN [/0.0.0.0:11226:QuorumCnxManager@274] - Exception reading or writing challenge: java.net.SocketTimeoutException: Read timed out 2016-07-12 22:34:52,700 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@74] - TEST METHOD FAILED testCnxFromFutureVersion java.io.IOException: Broken pipe at sun.nio.ch.FileDispatcherImpl.write0(Native Method) at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) at sun.nio.ch.IOUtil.write(IOUtil.java:65) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:466) at java.nio.channels.Channels.writeFullyImpl(Channels.java:78) at java.nio.channels.Channels.writeFully(Channels.java:98) at java.nio.channels.Channels.access$000(Channels.java:61) at java.nio.channels.Channels$1.write(Channels.java:174) at java.io.OutputStream.write(OutputStream.java:75) at java.nio.channels.Channels$1.write(Channels.java:155) at java.io.DataOutputStream.writeInt(DataOutputStream.java:198) at org.apache.zookeeper.server.quorum.CnxManagerTest.testCnxFromFutureVersion(CnxManagerTest.java:318) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:483) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:518) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1052) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:906) 2016-07-12 22:34:52,705 [myid:] - INFO [main:ZKTestCase$1@65] - FAILED testCnxFromFutureVersion java.io.IOException: Broken pipe at sun.nio.ch.FileDispatcherImpl.write0(Native Method) at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) at sun.nio.ch.IOUtil.write(IOUtil.java:65) at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:466) at java.nio.channels.Channels.writeFullyImpl(Channels.java:78) at java.nio.channels.Channels.writeFully(Channels.java:98) at java.nio.channels.Channels.access$000(Channels.java:61) at java.nio.channels.Channels$1.write(Channels.java:174) at java.io.OutputStream.write(OutputStream.java:75) at java.nio.channels.Channels$1.write(Channels.java:155) at java.io.DataOutputStream.writeInt(DataOutputStream.java:198) at org.apache.zookeeper.server.quorum.CnxManagerTest.testCnxFromFutureVersion(CnxManagerTest.java:318) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:483) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:518) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1052) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:906) 2016-07-12 22:34:52,706 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testCnxFromFutureVersion 2016-07-12 22:34:52,720 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testSocketTimeout 2016-07-12 22:34:52,720 [myid:] - INFO [main:PortAssignment@32] - assigning port 11230 2016-07-12 22:34:52,720 [myid:] - INFO [main:PortAssignment@32] - assigning port 11231 2016-07-12 22:34:52,720 [myid:] - INFO [main:PortAssignment@32] - assigning port 11232 2016-07-12 22:34:52,721 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:52,721 [myid:] - INFO [main:PortAssignment@32] - assigning port 11233 2016-07-12 22:34:52,722 [myid:] - INFO [main:PortAssignment@32] - assigning port 11234 2016-07-12 22:34:52,722 [myid:] - INFO [main:PortAssignment@32] - assigning port 11235 2016-07-12 22:34:52,722 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:52,723 [myid:] - INFO [main:PortAssignment@32] - assigning port 11236 2016-07-12 22:34:52,723 [myid:] - INFO [main:PortAssignment@32] - assigning port 11237 2016-07-12 22:34:52,723 [myid:] - INFO [main:PortAssignment@32] - assigning port 11238 2016-07-12 22:34:52,724 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:52,724 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testSocketTimeout 2016-07-12 22:34:52,725 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11234 2016-07-12 22:34:52,726 [myid:] - INFO [main:CnxManagerTest@370] - Election port: 11235 2016-07-12 22:34:52,726 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /0.0.0.0:11235 2016-07-12 22:34:53,729 [myid:] - INFO [/0.0.0.0:11235:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:34496 2016-07-12 22:34:57,734 [myid:] - WARN [/0.0.0.0:11235:QuorumCnxManager@274] - Exception reading or writing challenge: java.net.SocketTimeoutException: Read timed out 2016-07-12 22:34:57,734 [myid:] - WARN [main:QuorumCnxManager@274] - Exception reading or writing challenge: java.io.EOFException 2016-07-12 22:34:57,734 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 3153 2016-07-12 22:34:57,735 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 6 2016-07-12 22:34:57,735 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testSocketTimeout 2016-07-12 22:34:57,735 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testSocketTimeout 2016-07-12 22:34:57,735 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testSocketTimeout 2016-07-12 22:34:57,735 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testWorkerThreads 2016-07-12 22:34:57,736 [myid:] - INFO [main:PortAssignment@32] - assigning port 11239 2016-07-12 22:34:57,736 [myid:] - INFO [main:PortAssignment@32] - assigning port 11240 2016-07-12 22:34:57,736 [myid:] - INFO [main:PortAssignment@32] - assigning port 11241 2016-07-12 22:34:57,736 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:57,736 [myid:] - INFO [main:PortAssignment@32] - assigning port 11242 2016-07-12 22:34:57,737 [myid:] - INFO [main:PortAssignment@32] - assigning port 11243 2016-07-12 22:34:57,737 [myid:] - INFO [main:PortAssignment@32] - assigning port 11244 2016-07-12 22:34:57,737 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:57,737 [myid:] - INFO [main:PortAssignment@32] - assigning port 11245 2016-07-12 22:34:57,737 [myid:] - INFO [main:PortAssignment@32] - assigning port 11246 2016-07-12 22:34:57,737 [myid:] - INFO [main:PortAssignment@32] - assigning port 11247 2016-07-12 22:34:57,737 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:57,738 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testWorkerThreads 2016-07-12 22:34:57,738 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11240 2016-07-12 22:34:57,784 [myid:] - INFO [main:CnxManagerTest@393] - Starting peer 0 2016-07-12 22:34:57,789 [myid:] - INFO [main:QuorumPeer@533] - currentEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-12 22:34:57,905 [myid:] - INFO [main:QuorumPeer@548] - acceptedEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-12 22:34:57,945 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /0.0.0.0:11241 2016-07-12 22:34:57,953 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11243 2016-07-12 22:34:57,954 [myid:] - INFO [main:CnxManagerTest@393] - Starting peer 1 2016-07-12 22:34:57,954 [myid:] - INFO [main:QuorumPeer@533] - currentEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-12 22:34:58,024 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:QuorumPeer@774] - LOOKING 2016-07-12 22:34:58,025 [myid:] - INFO [main:QuorumPeer@548] - acceptedEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-12 22:34:58,025 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:FastLeaderElection@818] - New election. My id = 0, proposed zxid=0x0 2016-07-12 22:34:58,028 [myid:] - INFO [WorkerReceiver[myid=0]:FastLeaderElection@600] - Notification: 1 (message format version), 0 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,028 [myid:] - WARN [WorkerSender[myid=0]:QuorumCnxManager@400] - Cannot open channel to 1 at election address /0.0.0.0:11244 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:204) 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:381) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:354) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:452) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:433) at java.lang.Thread.run(Thread.java:744) 2016-07-12 22:34:58,029 [myid:] - INFO [WorkerSender[myid=0]:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:58,030 [myid:] - WARN [WorkerSender[myid=0]:QuorumCnxManager@400] - Cannot open channel to 2 at election address /0.0.0.0:11247 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:204) 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:381) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:354) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:452) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:433) at java.lang.Thread.run(Thread.java:744) 2016-07-12 22:34:58,030 [myid:] - INFO [WorkerSender[myid=0]:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:58,050 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /0.0.0.0:11244 2016-07-12 22:34:58,052 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11246 2016-07-12 22:34:58,052 [myid:] - INFO [main:CnxManagerTest@393] - Starting peer 2 2016-07-12 22:34:58,053 [myid:] - INFO [main:QuorumPeer@533] - currentEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-12 22:34:58,057 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:QuorumPeer@774] - LOOKING 2016-07-12 22:34:58,058 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:FastLeaderElection@818] - New election. My id = 1, proposed zxid=0x0 2016-07-12 22:34:58,058 [myid:] - INFO [/0.0.0.0:11241:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:46871 2016-07-12 22:34:58,063 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,064 [myid:] - INFO [WorkerReceiver[myid=0]:FastLeaderElection@600] - Notification: 1 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,064 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 0 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,065 [myid:] - INFO [WorkerReceiver[myid=0]:FastLeaderElection@600] - Notification: 1 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,065 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,065 [myid:] - WARN [WorkerSender[myid=1]:QuorumCnxManager@400] - Cannot open channel to 2 at election address /0.0.0.0:11247 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:204) 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:381) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:354) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:452) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:433) at java.lang.Thread.run(Thread.java:744) 2016-07-12 22:34:58,065 [myid:] - WARN [WorkerSender[myid=0]:QuorumCnxManager@400] - Cannot open channel to 2 at election address /0.0.0.0:11247 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:204) 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:381) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:354) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.process(FastLeaderElection.java:452) at org.apache.zookeeper.server.quorum.FastLeaderElection$Messenger$WorkerSender.run(FastLeaderElection.java:433) at java.lang.Thread.run(Thread.java:744) 2016-07-12 22:34:58,066 [myid:] - INFO [WorkerSender[myid=1]:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:58,066 [myid:] - INFO [WorkerSender[myid=0]:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:58,084 [myid:] - INFO [main:QuorumPeer@548] - acceptedEpoch not found! Creating with a reasonable default of 0. This should only happen when you are upgrading your installation 2016-07-12 22:34:58,133 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /0.0.0.0:11247 2016-07-12 22:34:58,136 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:QuorumPeer@774] - LOOKING 2016-07-12 22:34:58,136 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:FastLeaderElection@818] - New election. My id = 2, proposed zxid=0x0 2016-07-12 22:34:58,137 [myid:] - INFO [/0.0.0.0:11241:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:46874 2016-07-12 22:34:58,138 [myid:] - INFO [/0.0.0.0:11244:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:33135 2016-07-12 22:34:58,141 [myid:] - INFO [WorkerReceiver[myid=0]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,143 [myid:] - INFO [WorkerReceiver[myid=0]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,143 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,143 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,144 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,144 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 1 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,144 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,144 [myid:] - INFO [WorkerReceiver[myid=0]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,144 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,145 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,145 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:58,345 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:QuorumPeer@844] - FOLLOWING 2016-07-12 22:34:58,345 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:QuorumPeer@844] - FOLLOWING 2016-07-12 22:34:58,346 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:QuorumPeer@856] - LEADING 2016-07-12 22:34:58,349 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Learner@86] - TCP NoDelay set to: true 2016-07-12 22:34:58,350 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:Leader@59] - TCP NoDelay set to: true 2016-07-12 22:34:58,354 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:zookeeper.version=3.4.9-SNAPSHOT-1752356, built on 07/12/2016 22:30 GMT 2016-07-12 22:34:58,354 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:host.name=hemera.apache.org 2016-07-12 22:34:58,354 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:java.version=1.8.0 2016-07-12 22:34:58,354 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:java.vendor=Oracle Corporation 2016-07-12 22:34:58,354 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:java.home=/x1/jenkins/jenkins-slave/tools/hudson.model.JDK/jdk-1.8.0/jre 2016-07-12 22:34:58,354 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:java.class.path=/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/classes:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/lib/antlr-2.7.6.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/lib/checkstyle-5.0.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/lib/commons-beanutils-core-1.7.0.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/lib/commons-cli-1.0.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/lib/commons-collections-3.2.2.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/lib/commons-lang-1.0.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/lib/commons-logging-1.0.3.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/lib/google-collections-0.9.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/lib/junit-4.8.1.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/lib/mockito-all-1.8.2.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/classes:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/src/java/lib/ivy-2.4.0.jar:/home/jenkins/tools/ant/latest/lib/ant.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/lib/jline-0.9.94.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/lib/log4j-1.2.16.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/lib/netty-3.10.5.Final.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/lib/slf4j-api-1.6.1.jar:/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/lib/slf4j-log4j12-1.6.1.jar:/home/jenkins/tools/clover/latest/lib/clover.jar:/x1/jenkins/tools/ant/apache-ant-1.8.2/lib/ant-launcher.jar:/home/jenkins/tools/ant/latest/lib/ant-junit.jar:/home/jenkins/tools/ant/latest/lib/ant-junit4.jar 2016-07-12 22:34:58,355 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib 2016-07-12 22:34:58,355 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:java.io.tmpdir=/tmp 2016-07-12 22:34:58,355 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:java.compiler=<NA> 2016-07-12 22:34:58,355 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:os.name=Linux 2016-07-12 22:34:58,355 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:os.arch=amd64 2016-07-12 22:34:58,355 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:os.version=3.2.0-104-generic 2016-07-12 22:34:58,355 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:user.name=jenkins 2016-07-12 22:34:58,355 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:user.home=/home/jenkins 2016-07-12 22:34:58,355 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Environment@100] - Server environment:user.dir=/x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4 2016-07-12 22:34:58,358 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:ZooKeeperServer@170] - Created server with tickTime 1000 minSessionTimeout 2000 maxSessionTimeout 20000 datadir /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test6977370939981061612.junit.dir/version-2 snapdir /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test6977370939981061612.junit.dir/version-2 2016-07-12 22:34:58,358 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:ZooKeeperServer@170] - Created server with tickTime 1000 minSessionTimeout 2000 maxSessionTimeout 20000 datadir /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test4996523116536588259.junit.dir/version-2 snapdir /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test4996523116536588259.junit.dir/version-2 2016-07-12 22:34:58,358 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:ZooKeeperServer@170] - Created server with tickTime 1000 minSessionTimeout 2000 maxSessionTimeout 20000 datadir /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test8108741215991761367.junit.dir/version-2 snapdir /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test8108741215991761367.junit.dir/version-2 2016-07-12 22:34:58,359 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Follower@63] - FOLLOWING - LEADER ELECTION TOOK - 301 2016-07-12 22:34:58,359 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:Follower@63] - FOLLOWING - LEADER ELECTION TOOK - 334 2016-07-12 22:34:58,365 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:Leader@361] - LEADING - LEADER ELECTION TOOK - 224 2016-07-12 22:34:58,370 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:58,373 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:58,383 [myid:] - INFO [LearnerHandler-/140.211.11.27:45223:LearnerHandler@329] - Follower sid: 1 : info : org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@4e46c644 2016-07-12 22:34:58,383 [myid:] - INFO [LearnerHandler-/140.211.11.27:45222:LearnerHandler@329] - Follower sid: 0 : info : org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@23da3d 2016-07-12 22:34:58,528 [myid:] - INFO [LearnerHandler-/140.211.11.27:45222:LearnerHandler@384] - Synchronizing with Follower sid: 0 maxCommittedLog=0x0 minCommittedLog=0x0 peerLastZxid=0x0 2016-07-12 22:34:58,528 [myid:] - INFO [LearnerHandler-/140.211.11.27:45223:LearnerHandler@384] - Synchronizing with Follower sid: 1 maxCommittedLog=0x0 minCommittedLog=0x0 peerLastZxid=0x0 2016-07-12 22:34:58,529 [myid:] - INFO [LearnerHandler-/140.211.11.27:45222:LearnerHandler@393] - leader and follower are in sync, zxid=0x0 2016-07-12 22:34:58,529 [myid:] - INFO [LearnerHandler-/140.211.11.27:45223:LearnerHandler@393] - leader and follower are in sync, zxid=0x0 2016-07-12 22:34:58,529 [myid:] - INFO [LearnerHandler-/140.211.11.27:45223:LearnerHandler@458] - Sending DIFF 2016-07-12 22:34:58,529 [myid:] - INFO [LearnerHandler-/140.211.11.27:45222:LearnerHandler@458] - Sending DIFF 2016-07-12 22:34:58,530 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Learner@326] - Getting a diff from the leader 0x0 2016-07-12 22:34:58,530 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:Learner@326] - Getting a diff from the leader 0x0 2016-07-12 22:34:58,534 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:FileTxnSnapLog@240] - Snapshotting: 0x0 to /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test6977370939981061612.junit.dir/version-2/snapshot.0 2016-07-12 22:34:58,534 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:FileTxnSnapLog@240] - Snapshotting: 0x0 to /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test8108741215991761367.junit.dir/version-2/snapshot.0 2016-07-12 22:34:58,623 [myid:] - INFO [LearnerHandler-/140.211.11.27:45222:LearnerHandler@518] - Received NEWLEADER-ACK message from 0 2016-07-12 22:34:58,623 [myid:] - INFO [LearnerHandler-/140.211.11.27:45223:LearnerHandler@518] - Received NEWLEADER-ACK message from 1 2016-07-12 22:34:58,623 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:Leader@946] - Have quorum of supporters, sids: [ 0,2 ]; starting up and setting last processed zxid: 0x100000000 2016-07-12 22:34:58,634 [myid:] - INFO [main:CnxManagerTest@405] - Round 0, halting peer 0 2016-07-12 22:34:58,634 [myid:] - INFO [main:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:891) at org.apache.zookeeper.server.quorum.CnxManagerTest.testWorkerThreads(CnxManagerTest.java:407) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:483) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:518) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1052) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:906) 2016-07-12 22:34:58,635 [myid:] - INFO [main:FollowerZooKeeperServer@140] - Shutting down 2016-07-12 22:34:58,645 [myid:] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11240:NIOServerCnxnFactory@219] - NIOServerCnxn factory exited run method 2016-07-12 22:34:58,645 [myid:] - INFO [main:FollowerZooKeeperServer@140] - Shutting down 2016-07-12 22:34:58,647 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-12 22:34:58,647 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:850) 2016-07-12 22:34:58,648 [myid:] - INFO [main:FollowerRequestProcessor@107] - Shutting down 2016-07-12 22:34:58,648 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:FollowerZooKeeperServer@140] - Shutting down 2016-07-12 22:34:58,648 [myid:] - INFO [FollowerRequestProcessor:0:FollowerRequestProcessor@97] - FollowerRequestProcessor exited loop! 2016-07-12 22:34:58,648 [myid:] - INFO [main:CommitProcessor@184] - Shutting down 2016-07-12 22:34:58,649 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-12 22:34:58,649 [myid:] - INFO [CommitProcessor:0:CommitProcessor@153] - CommitProcessor exited loop! 2016-07-12 22:34:58,650 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-12 22:34:58,650 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:SyncRequestProcessor@209] - Shutting down 2016-07-12 22:34:58,651 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-12 22:34:58,651 [myid:] - WARN [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:QuorumPeer@874] - QuorumPeer main thread exited 2016-07-12 22:34:58,651 [myid:] - ERROR [/0.0.0.0:11241:QuorumCnxManager$Listener@547] - Exception while listening java.net.SocketException: Socket closed at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404) at java.net.ServerSocket.implAccept(ServerSocket.java:545) at java.net.ServerSocket.accept(ServerSocket.java:513) at org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:539) 2016-07-12 22:34:58,652 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:34:58,653 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@810] - Connection broken for id 2, my id = 0, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:150) at java.net.SocketInputStream.read(SocketInputStream.java:121) at java.net.SocketInputStream.read(SocketInputStream.java:203) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-12 22:34:58,654 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:34:58,653 [myid:] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@810] - Connection broken for id 0, my id = 2, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-12 22:34:58,653 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:34:58,656 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:34:58,652 [myid:] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@810] - Connection broken for id 0, my id = 1, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-12 22:34:58,656 [myid:] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:34:58,652 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@810] - Connection broken for id 1, my id = 0, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:150) at java.net.SocketInputStream.read(SocketInputStream.java:121) at java.net.SocketInputStream.read(SocketInputStream.java:203) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-12 22:34:58,657 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:34:58,657 [myid:] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:34:58,658 [myid:] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:34:58,655 [myid:] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:34:58,654 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:34:58,659 [myid:] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:34:58,659 [myid:] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:34:59,154 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11240 2016-07-12 22:34:59,155 [myid:] - INFO [main:CnxManagerTest@414] - Round {}, restarting peer {}[Ljava.lang.Object;@12bc6874 2016-07-12 22:34:59,157 [myid:] - INFO [main:FileSnap@83] - Reading snapshot /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test8108741215991761367.junit.dir/version-2/snapshot.0 2016-07-12 22:34:59,159 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /0.0.0.0:11241 2016-07-12 22:34:59,161 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:QuorumPeer@774] - LOOKING 2016-07-12 22:34:59,162 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:FastLeaderElection@818] - New election. My id = 0, proposed zxid=0x0 2016-07-12 22:34:59,162 [myid:] - INFO [WorkerReceiver[myid=0]:FastLeaderElection@600] - Notification: 1 (message format version), 0 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x1 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:59,163 [myid:] - INFO [WorkerSender[myid=0]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (1, 0) 2016-07-12 22:34:59,163 [myid:] - INFO [/0.0.0.0:11244:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:33142 2016-07-12 22:34:59,163 [myid:] - INFO [/0.0.0.0:11247:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:44785 2016-07-12 22:34:59,163 [myid:] - INFO [WorkerSender[myid=0]:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (2, 0) 2016-07-12 22:34:59,164 [myid:] - INFO [/0.0.0.0:11241:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:46884 2016-07-12 22:34:59,166 [myid:] - INFO [/0.0.0.0:11241:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:46885 2016-07-12 22:34:59,167 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection@600] - Notification: 1 (message format version), 0 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x1 (n.peerEpoch) FOLLOWING (my state) 2016-07-12 22:34:59,169 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection@600] - Notification: 1 (message format version), 0 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 0 (n.sid), 0x1 (n.peerEpoch) LEADING (my state) 2016-07-12 22:34:59,169 [myid:] - INFO [WorkerReceiver[myid=0]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 1 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:59,169 [myid:] - INFO [WorkerReceiver[myid=0]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LOOKING (n.state), 2 (n.sid), 0x0 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:59,169 [myid:] - INFO [WorkerReceiver[myid=0]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), FOLLOWING (n.state), 1 (n.sid), 0x1 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:59,170 [myid:] - INFO [WorkerReceiver[myid=0]:FastLeaderElection@600] - Notification: 1 (message format version), 2 (n.leader), 0x0 (n.zxid), 0x1 (n.round), LEADING (n.state), 2 (n.sid), 0x1 (n.peerEpoch) LOOKING (my state) 2016-07-12 22:34:59,170 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:QuorumPeer@844] - FOLLOWING 2016-07-12 22:34:59,170 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:ZooKeeperServer@170] - Created server with tickTime 1000 minSessionTimeout 2000 maxSessionTimeout 20000 datadir /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test8108741215991761367.junit.dir/version-2 snapdir /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test8108741215991761367.junit.dir/version-2 2016-07-12 22:34:59,170 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:Follower@63] - FOLLOWING - LEADER ELECTION TOOK - 8 2016-07-12 22:34:59,171 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:34:59,172 [myid:] - INFO [LearnerHandler-/140.211.11.27:45228:LearnerHandler@329] - Follower sid: 0 : info : org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@23da3d 2016-07-12 22:34:59,172 [myid:] - INFO [LearnerHandler-/140.211.11.27:45228:LearnerHandler@384] - Synchronizing with Follower sid: 0 maxCommittedLog=0x0 minCommittedLog=0x0 peerLastZxid=0x0 2016-07-12 22:34:59,172 [myid:] - INFO [LearnerHandler-/140.211.11.27:45228:LearnerHandler@458] - Sending SNAP 2016-07-12 22:34:59,172 [myid:] - INFO [LearnerHandler-/140.211.11.27:45228:LearnerHandler@482] - Sending snapshot last zxid of peer is 0x0 zxid of leader is 0x100000000sent zxid of db as 0x100000000 2016-07-12 22:34:59,172 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:Learner@329] - Getting a snapshot from leader 2016-07-12 22:34:59,174 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:FileTxnSnapLog@240] - Snapshotting: 0x100000000 to /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test8108741215991761367.junit.dir/version-2/snapshot.100000000 2016-07-12 22:34:59,284 [myid:] - INFO [LearnerHandler-/140.211.11.27:45228:LearnerHandler@518] - Received NEWLEADER-ACK message from 0 2016-07-12 22:34:59,652 [myid:] - INFO [/0.0.0.0:11241:QuorumCnxManager$Listener@560] - Leaving listener 2016-07-12 22:34:59,660 [myid:] - INFO [main:CnxManagerTest@405] - Round 1, halting peer 0 2016-07-12 22:34:59,660 [myid:] - INFO [main:Follower@166] - shutdown called j ...[truncated 254755 chars]... Keeper_branch34_jdk8/branch-3.4/build/test/tmp/test4996523116536588259.junit.dir/version-2 snapdir /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test4996523116536588259.junit.dir/version-2 2016-07-12 22:35:13,328 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:Follower@63] - FOLLOWING - LEADER ELECTION TOOK - 3 2016-07-12 22:35:13,329 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:35:13,329 [myid:] - INFO [LearnerHandler-/140.211.11.27:32997:LearnerHandler@329] - Follower sid: 2 : info : org.apache.zookeeper.server.quorum.QuorumPeer$QuorumServer@6f23fc6d 2016-07-12 22:35:13,330 [myid:] - INFO [LearnerHandler-/140.211.11.27:32997:LearnerHandler@384] - Synchronizing with Follower sid: 2 maxCommittedLog=0x0 minCommittedLog=0x0 peerLastZxid=0x200000000 2016-07-12 22:35:13,330 [myid:] - INFO [LearnerHandler-/140.211.11.27:32997:LearnerHandler@393] - leader and follower are in sync, zxid=0x200000000 2016-07-12 22:35:13,330 [myid:] - INFO [LearnerHandler-/140.211.11.27:32997:LearnerHandler@458] - Sending DIFF 2016-07-12 22:35:13,330 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:Learner@326] - Getting a diff from the leader 0x200000000 2016-07-12 22:35:13,331 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:FileTxnSnapLog@240] - Snapshotting: 0x200000000 to /x1/jenkins/jenkins-slave/workspace/ZooKeeper_branch34_jdk8/branch-3.4/build/test/tmp/test4996523116536588259.junit.dir/version-2/snapshot.200000000 2016-07-12 22:35:13,376 [myid:] - INFO [LearnerHandler-/140.211.11.27:32997:LearnerHandler@518] - Received NEWLEADER-ACK message from 2 2016-07-12 22:35:13,821 [myid:] - INFO [/0.0.0.0:11247:QuorumCnxManager$Listener@560] - Leaving listener 2016-07-12 22:35:13,824 [myid:] - INFO [main:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:891) at org.apache.zookeeper.server.quorum.CnxManagerTest.testWorkerThreads(CnxManagerTest.java:424) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:483) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:518) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1052) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:906) 2016-07-12 22:35:13,824 [myid:] - INFO [main:FollowerZooKeeperServer@140] - Shutting down 2016-07-12 22:35:13,824 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-12 22:35:13,825 [myid:] - INFO [main:FollowerRequestProcessor@107] - Shutting down 2016-07-12 22:35:13,825 [myid:] - INFO [main:CommitProcessor@184] - Shutting down 2016-07-12 22:35:13,825 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-12 22:35:13,825 [myid:] - INFO [CommitProcessor:0:CommitProcessor@153] - CommitProcessor exited loop! 2016-07-12 22:35:13,826 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-12 22:35:13,825 [myid:] - INFO [FollowerRequestProcessor:0:FollowerRequestProcessor@97] - FollowerRequestProcessor exited loop! 2016-07-12 22:35:13,826 [myid:] - INFO [SyncThread:0:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-12 22:35:13,827 [myid:] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11240:NIOServerCnxnFactory@219] - NIOServerCnxn factory exited run method 2016-07-12 22:35:13,828 [myid:] - ERROR [/0.0.0.0:11241:QuorumCnxManager$Listener@547] - Exception while listening java.net.SocketException: Socket closed at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404) at java.net.ServerSocket.implAccept(ServerSocket.java:545) at java.net.ServerSocket.accept(ServerSocket.java:513) at org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:539) 2016-07-12 22:35:13,829 [myid:] - INFO [main:Leader@496] - Shutting down 2016-07-12 22:35:13,828 [myid:] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@810] - Connection broken for id 0, my id = 1, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-12 22:35:13,829 [myid:] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:35:13,828 [myid:] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@810] - Connection broken for id 0, my id = 2, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-12 22:35:13,829 [myid:] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:35:13,828 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:35:13,830 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:35:13,828 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:35:13,830 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:35:13,828 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@810] - Connection broken for id 1, my id = 0, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:150) at java.net.SocketInputStream.read(SocketInputStream.java:121) at java.net.SocketInputStream.read(SocketInputStream.java:203) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-12 22:35:13,830 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:35:13,830 [myid:] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:35:13,830 [myid:] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:35:13,829 [myid:] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:35:13,831 [myid:] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:35:13,829 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@810] - Connection broken for id 2, my id = 0, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:150) at java.net.SocketInputStream.read(SocketInputStream.java:121) at java.net.SocketInputStream.read(SocketInputStream.java:203) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-12 22:35:13,831 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:35:13,829 [myid:] - INFO [main:Leader@502] - Shutdown called java.lang.Exception: shutdown Leader! reason: quorum Peer shutdown at org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:502) at org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:888) at org.apache.zookeeper.server.quorum.CnxManagerTest.testWorkerThreads(CnxManagerTest.java:424) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:483) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:518) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1052) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:906) 2016-07-12 22:35:13,831 [myid:] - INFO [main:ZooKeeperServer@469] - shutting down 2016-07-12 22:35:13,831 [myid:] - INFO [main:SessionTrackerImpl@225] - Shutting down 2016-07-12 22:35:13,832 [myid:] - INFO [main:PrepRequestProcessor@765] - Shutting down 2016-07-12 22:35:13,832 [myid:] - INFO [main:ProposalRequestProcessor@88] - Shutting down 2016-07-12 22:35:13,832 [myid:] - INFO [main:CommitProcessor@184] - Shutting down 2016-07-12 22:35:13,832 [myid:] - INFO [main:Leader$ToBeAppliedRequestProcessor@661] - Shutting down 2016-07-12 22:35:13,832 [myid:] - INFO [main:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-12 22:35:13,832 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-12 22:35:13,831 [myid:] - INFO [LearnerCnxAcceptor-/0.0.0.0:11242:Leader$LearnerCnxAcceptor@325] - exception while shutting down acceptor: java.net.SocketException: Socket closed 2016-07-12 22:35:13,832 [myid:] - INFO [SyncThread:1:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-12 22:35:13,832 [myid:] - INFO [CommitProcessor:1:CommitProcessor@153] - CommitProcessor exited loop! 2016-07-12 22:35:13,832 [myid:] - INFO [ProcessThread(sid:1 cport:-1)::PrepRequestProcessor@143] - PrepRequestProcessor exited loop! 2016-07-12 22:35:13,834 [myid:] - WARN [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:Follower@89] - Exception when following the leader java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63) at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83) at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99) at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:153) at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:85) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:846) 2016-07-12 22:35:13,833 [myid:] - WARN [LearnerHandler-/140.211.11.27:32993:LearnerHandler@644] - ******* GOODBYE /140.211.11.27:32993 ******** 2016-07-12 22:35:13,835 [myid:] - WARN [LearnerHandler-/140.211.11.27:32990:LearnerHandler@644] - ******* GOODBYE /140.211.11.27:32990 ******** 2016-07-12 22:35:13,834 [myid:] - WARN [LearnerHandler-/140.211.11.27:32980:LearnerHandler@644] - ******* GOODBYE /140.211.11.27:32980 ******** 2016-07-12 22:35:13,835 [myid:] - WARN [LearnerHandler-/140.211.11.27:32980:LearnerHandler@656] - Ignoring unexpected exception java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:339) at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:654) at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:647) 2016-07-12 22:35:13,834 [myid:] - WARN [LearnerHandler-/140.211.11.27:32997:LearnerHandler@644] - ******* GOODBYE /140.211.11.27:32997 ******** 2016-07-12 22:35:13,835 [myid:] - WARN [LearnerHandler-/140.211.11.27:32997:LearnerHandler@656] - Ignoring unexpected exception java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:339) at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:654) at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:647) 2016-07-12 22:35:13,835 [myid:] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11243:NIOServerCnxnFactory@219] - NIOServerCnxn factory exited run method 2016-07-12 22:35:13,835 [myid:] - WARN [LearnerHandler-/140.211.11.27:32990:LearnerHandler@656] - Ignoring unexpected exception java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:339) at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:654) at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:647) 2016-07-12 22:35:13,836 [myid:] - WARN [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:QuorumPeer@862] - Unexpected exception java.lang.InterruptedException: sleep interrupted at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:456) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:859) 2016-07-12 22:35:13,836 [myid:] - INFO [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:Leader@496] - Shutting down 2016-07-12 22:35:13,836 [myid:] - WARN [QuorumPeer[myid=1]/0:0:0:0:0:0:0:0:11243:QuorumPeer@874] - QuorumPeer main thread exited 2016-07-12 22:35:13,835 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:850) 2016-07-12 22:35:13,837 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:FollowerZooKeeperServer@140] - Shutting down 2016-07-12 22:35:13,837 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:ZooKeeperServer@469] - shutting down 2016-07-12 22:35:13,837 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:FollowerRequestProcessor@107] - Shutting down 2016-07-12 22:35:13,835 [myid:] - WARN [LearnerHandler-/140.211.11.27:32993:LearnerHandler@656] - Ignoring unexpected exception java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) at java.util.concurrent.LinkedBlockingQueue.put(LinkedBlockingQueue.java:339) at org.apache.zookeeper.server.quorum.LearnerHandler.shutdown(LearnerHandler.java:654) at org.apache.zookeeper.server.quorum.LearnerHandler.run(LearnerHandler.java:647) 2016-07-12 22:35:13,835 [myid:] - WARN [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:Follower@89] - Exception when following the leader java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63) at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:83) at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:99) at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:153) at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:85) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:846) 2016-07-12 22:35:13,837 [myid:] - INFO [FollowerRequestProcessor:2:FollowerRequestProcessor@97] - FollowerRequestProcessor exited loop! 2016-07-12 22:35:13,838 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:850) 2016-07-12 22:35:13,837 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:CommitProcessor@184] - Shutting down 2016-07-12 22:35:13,839 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:FinalRequestProcessor@402] - shutdown of request processor complete 2016-07-12 22:35:13,839 [myid:] - INFO [CommitProcessor:2:CommitProcessor@153] - CommitProcessor exited loop! 2016-07-12 22:35:13,837 [myid:] - INFO [main:Follower@166] - shutdown called java.lang.Exception: shutdown Follower at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:166) at org.apache.zookeeper.server.quorum.QuorumPeer.shutdown(QuorumPeer.java:891) at org.apache.zookeeper.server.quorum.CnxManagerTest.testWorkerThreads(CnxManagerTest.java:424) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:483) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:518) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1052) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:906) 2016-07-12 22:35:13,839 [myid:] - INFO [main:FollowerZooKeeperServer@140] - Shutting down 2016-07-12 22:35:13,839 [myid:] - INFO [main:SyncRequestProcessor@209] - Shutting down 2016-07-12 22:35:13,836 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@810] - Connection broken for id 2, my id = 1, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:150) at java.net.SocketInputStream.read(SocketInputStream.java:121) at java.net.SocketInputStream.read(SocketInputStream.java:203) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-12 22:35:13,840 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:35:13,836 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@810] - Connection broken for id 1, my id = 2, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-12 22:35:13,840 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:35:13,836 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:35:13,840 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:35:13,836 [myid:] - ERROR [/0.0.0.0:11244:QuorumCnxManager$Listener@547] - Exception while listening java.net.SocketException: Socket closed at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404) at java.net.ServerSocket.implAccept(ServerSocket.java:545) at java.net.ServerSocket.accept(ServerSocket.java:513) at org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:539) 2016-07-12 22:35:13,840 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:35:13,841 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:35:13,840 [myid:] - INFO [SyncThread:2:SyncRequestProcessor@187] - SyncRequestProcessor exited! 2016-07-12 22:35:13,839 [myid:] - INFO [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:SyncRequestProcessor@209] - Shutting down 2016-07-12 22:35:13,841 [myid:] - WARN [QuorumPeer[myid=2]/0:0:0:0:0:0:0:0:11246:QuorumPeer@874] - QuorumPeer main thread exited 2016-07-12 22:35:13,841 [myid:] - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11246:NIOServerCnxnFactory@219] - NIOServerCnxn factory exited run method 2016-07-12 22:35:13,839 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:FollowerZooKeeperServer@140] - Shutting down 2016-07-12 22:35:13,842 [myid:] - INFO [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:SyncRequestProcessor@209] - Shutting down 2016-07-12 22:35:13,842 [myid:] - WARN [QuorumPeer[myid=0]/0:0:0:0:0:0:0:0:11240:QuorumPeer@874] - QuorumPeer main thread exited 2016-07-12 22:35:13,842 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 11673 2016-07-12 22:35:13,842 [myid:] - ERROR [/0.0.0.0:11247:QuorumCnxManager$Listener@547] - Exception while listening java.net.SocketException: Socket closed at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404) at java.net.ServerSocket.implAccept(ServerSocket.java:545) at java.net.ServerSocket.accept(ServerSocket.java:513) at org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:539) 2016-07-12 22:35:13,842 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 20 2016-07-12 22:35:13,842 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testWorkerThreads 2016-07-12 22:35:13,842 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testWorkerThreads 2016-07-12 22:35:13,843 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testWorkerThreads 2016-07-12 22:35:13,843 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testCnxManager 2016-07-12 22:35:13,843 [myid:] - INFO [main:PortAssignment@32] - assigning port 11248 2016-07-12 22:35:13,843 [myid:] - INFO [main:PortAssignment@32] - assigning port 11249 2016-07-12 22:35:13,843 [myid:] - INFO [main:PortAssignment@32] - assigning port 11250 2016-07-12 22:35:13,843 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:35:13,844 [myid:] - INFO [main:PortAssignment@32] - assigning port 11251 2016-07-12 22:35:13,844 [myid:] - INFO [main:PortAssignment@32] - assigning port 11252 2016-07-12 22:35:13,844 [myid:] - INFO [main:PortAssignment@32] - assigning port 11253 2016-07-12 22:35:13,844 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:35:13,844 [myid:] - INFO [main:PortAssignment@32] - assigning port 11254 2016-07-12 22:35:13,844 [myid:] - INFO [main:PortAssignment@32] - assigning port 11255 2016-07-12 22:35:13,844 [myid:] - INFO [main:PortAssignment@32] - assigning port 11256 2016-07-12 22:35:13,844 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:35:13,844 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testCnxManager 2016-07-12 22:35:13,845 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11252 2016-07-12 22:35:13,846 [myid:] - INFO [Thread-19:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11249 2016-07-12 22:35:13,846 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /0.0.0.0:11253 2016-07-12 22:35:13,846 [myid:] - WARN [main:QuorumCnxManager@400] - Cannot open channel to 0 at election address /0.0.0.0:11250 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:204) 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:381) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:354) at org.apache.zookeeper.server.quorum.CnxManagerTest.testCnxManager(CnxManagerTest.java:142) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:483) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:518) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1052) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:906) 2016-07-12 22:35:13,847 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:35:13,847 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /0.0.0.0:11250 2016-07-12 22:35:13,847 [myid:] - INFO [/0.0.0.0:11253:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:41746 2016-07-12 22:35:13,847 [myid:] - INFO [Thread-19:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (1, 0) 2016-07-12 22:35:13,848 [myid:] - INFO [/0.0.0.0:11250:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:46883 2016-07-12 22:35:13,849 [myid:] - INFO [/0.0.0.0:11253:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:41748 2016-07-12 22:35:13,849 [myid:] - INFO [Thread-19:QuorumCnxManager@199] - Have smaller server identifier, so dropping the connection: (1, 0) 2016-07-12 22:35:13,849 [myid:] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:35:13,849 [myid:] - INFO [/0.0.0.0:11250:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:46885 2016-07-12 22:35:13,849 [myid:] - WARN [SendWorker:0:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:35:13,849 [myid:] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@810] - Connection broken for id 0, my id = 1, error = java.net.SocketException: Socket closed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:150) at java.net.SocketInputStream.read(SocketInputStream.java:121) at java.net.SocketInputStream.read(SocketInputStream.java:203) at java.io.DataInputStream.readInt(DataInputStream.java:387) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-12 22:35:13,850 [myid:] - WARN [RecvWorker:0:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:35:13,849 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@810] - Connection broken for id 1, my id = 0, error = java.io.EOFException at java.io.DataInputStream.readInt(DataInputStream.java:392) at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:795) 2016-07-12 22:35:13,850 [myid:] - WARN [RecvWorker:1:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:35:13,850 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:35:13,851 [myid:] - WARN [SendWorker:1:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:35:13,851 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 12332 2016-07-12 22:35:13,851 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 26 2016-07-12 22:35:13,851 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testCnxManager 2016-07-12 22:35:13,851 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testCnxManager 2016-07-12 22:35:13,851 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testCnxManager 2016-07-12 22:35:13,862 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testCnxManagerTimeout 2016-07-12 22:35:13,862 [myid:] - INFO [main:PortAssignment@32] - assigning port 11257 2016-07-12 22:35:13,862 [myid:] - INFO [main:PortAssignment@32] - assigning port 11258 2016-07-12 22:35:13,862 [myid:] - INFO [main:PortAssignment@32] - assigning port 11259 2016-07-12 22:35:13,862 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:35:13,862 [myid:] - INFO [main:PortAssignment@32] - assigning port 11260 2016-07-12 22:35:13,862 [myid:] - INFO [main:PortAssignment@32] - assigning port 11261 2016-07-12 22:35:13,862 [myid:] - INFO [main:PortAssignment@32] - assigning port 11262 2016-07-12 22:35:13,862 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:35:13,863 [myid:] - INFO [main:PortAssignment@32] - assigning port 11263 2016-07-12 22:35:13,863 [myid:] - INFO [main:PortAssignment@32] - assigning port 11264 2016-07-12 22:35:13,863 [myid:] - INFO [main:PortAssignment@32] - assigning port 11265 2016-07-12 22:35:13,863 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:35:13,863 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testCnxManagerTimeout 2016-07-12 22:35:13,863 [myid:] - INFO [main:PortAssignment@32] - assigning port 11266 2016-07-12 22:35:13,863 [myid:] - INFO [main:CnxManagerTest@171] - This is the dead address I'm trying: 192.0.2.179 2016-07-12 22:35:13,863 [myid:] - INFO [main:PortAssignment@32] - assigning port 11267 2016-07-12 22:35:13,863 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 192.0.2.179 to address: /192.0.2.179 2016-07-12 22:35:13,864 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11261 2016-07-12 22:35:13,864 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /0.0.0.0:11262 2016-07-12 22:35:14,000 [myid:] - INFO [SessionTracker:SessionTrackerImpl@162] - SessionTrackerImpl exited loop! 2016-07-12 22:35:14,310 [myid:] - INFO [WorkerSender[myid=2]:FastLeaderElection$Messenger$WorkerSender@438] - WorkerSender is down 2016-07-12 22:35:14,311 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection$Messenger$WorkerReceiver@407] - WorkerReceiver is down 2016-07-12 22:35:14,829 [myid:] - INFO [/0.0.0.0:11241:QuorumCnxManager$Listener@560] - Leaving listener 2016-07-12 22:35:14,840 [myid:] - INFO [/0.0.0.0:11244:QuorumCnxManager$Listener@560] - Leaving listener 2016-07-12 22:35:14,842 [myid:] - INFO [/0.0.0.0:11247:QuorumCnxManager$Listener@560] - Leaving listener 2016-07-12 22:35:15,319 [myid:] - INFO [WorkerSender[myid=2]:FastLeaderElection$Messenger$WorkerSender@438] - WorkerSender is down 2016-07-12 22:35:15,320 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection$Messenger$WorkerReceiver@407] - WorkerReceiver is down 2016-07-12 22:35:16,327 [myid:] - INFO [WorkerReceiver[myid=0]:FastLeaderElection$Messenger$WorkerReceiver@407] - WorkerReceiver is down 2016-07-12 22:35:16,327 [myid:] - INFO [WorkerSender[myid=2]:FastLeaderElection$Messenger$WorkerSender@438] - WorkerSender is down 2016-07-12 22:35:16,327 [myid:] - INFO [WorkerSender[myid=0]:FastLeaderElection$Messenger$WorkerSender@438] - WorkerSender is down 2016-07-12 22:35:16,328 [myid:] - INFO [WorkerReceiver[myid=1]:FastLeaderElection$Messenger$WorkerReceiver@407] - WorkerReceiver is down 2016-07-12 22:35:16,328 [myid:] - INFO [WorkerSender[myid=1]:FastLeaderElection$Messenger$WorkerSender@438] - WorkerSender is down 2016-07-12 22:35:16,328 [myid:] - INFO [WorkerReceiver[myid=2]:FastLeaderElection$Messenger$WorkerReceiver@407] - WorkerReceiver is down 2016-07-12 22:35:18,869 [myid:] - WARN [main:QuorumCnxManager@400] - Cannot open channel to 2 at election address /192.0.2.179:11267 java.net.SocketTimeoutException: connect timed out at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345) 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:381) at org.apache.zookeeper.server.quorum.QuorumCnxManager.toSend(QuorumCnxManager.java:354) at org.apache.zookeeper.server.quorum.CnxManagerTest.testCnxManagerTimeout(CnxManagerTest.java:187) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:483) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.apache.zookeeper.JUnit4ZKTestRunner$LoggedInvokeMethod.evaluate(JUnit4ZKTestRunner.java:55) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28) at org.junit.rules.TestWatchman$1.evaluate(TestWatchman.java:48) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184) at org.junit.runners.ParentRunner.run(ParentRunner.java:236) at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:518) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1052) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:906) 2016-07-12 22:35:18,870 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 192.0.2.179 to address: /192.0.2.179 2016-07-12 22:35:18,870 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 12750 2016-07-12 22:35:18,870 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 13 2016-07-12 22:35:18,871 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testCnxManagerTimeout 2016-07-12 22:35:18,871 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testCnxManagerTimeout 2016-07-12 22:35:18,871 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testCnxManagerTimeout 2016-07-12 22:35:18,871 [myid:] - INFO [main:ZKTestCase$1@50] - STARTING testCnxManagerSpinLock 2016-07-12 22:35:18,872 [myid:] - INFO [main:PortAssignment@32] - assigning port 11268 2016-07-12 22:35:18,872 [myid:] - INFO [main:PortAssignment@32] - assigning port 11269 2016-07-12 22:35:18,872 [myid:] - INFO [main:PortAssignment@32] - assigning port 11270 2016-07-12 22:35:18,872 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:35:18,872 [myid:] - INFO [main:PortAssignment@32] - assigning port 11271 2016-07-12 22:35:18,872 [myid:] - INFO [main:PortAssignment@32] - assigning port 11272 2016-07-12 22:35:18,872 [myid:] - INFO [main:PortAssignment@32] - assigning port 11273 2016-07-12 22:35:18,873 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:35:18,873 [myid:] - INFO [main:PortAssignment@32] - assigning port 11274 2016-07-12 22:35:18,873 [myid:] - INFO [main:PortAssignment@32] - assigning port 11275 2016-07-12 22:35:18,873 [myid:] - INFO [main:PortAssignment@32] - assigning port 11276 2016-07-12 22:35:18,873 [myid:] - INFO [main:QuorumPeer$QuorumServer@149] - Resolved hostname: 0.0.0.0 to address: /0.0.0.0 2016-07-12 22:35:18,874 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@53] - RUNNING TEST METHOD testCnxManagerSpinLock 2016-07-12 22:35:18,874 [myid:] - INFO [main:NIOServerCnxnFactory@89] - binding to port 0.0.0.0/0.0.0.0:11272 2016-07-12 22:35:18,875 [myid:] - INFO [main:CnxManagerTest@214] - Election port: 11273 2016-07-12 22:35:18,875 [myid:] - INFO [ListenerThread:QuorumCnxManager$Listener@534] - My election bind port: /0.0.0.0:11273 2016-07-12 22:35:19,876 [myid:] - INFO [/0.0.0.0:11273:QuorumCnxManager$Listener@541] - Received connection request /140.211.11.27:37939 2016-07-12 22:35:19,876 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@810] - Connection broken for id 2, my id = 1, error = java.io.IOException: Received packet with invalid packet: -20 at org.apache.zookeeper.server.quorum.QuorumCnxManager$RecvWorker.run(QuorumCnxManager.java:797) 2016-07-12 22:35:19,877 [myid:] - WARN [RecvWorker:2:QuorumCnxManager$RecvWorker@813] - Interrupting SendWorker 2016-07-12 22:35:19,877 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@727] - Interrupted while waiting for message on queue java.lang.InterruptedException at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2088) at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418) at org.apache.zookeeper.server.quorum.QuorumCnxManager.pollSendQueue(QuorumCnxManager.java:879) at org.apache.zookeeper.server.quorum.QuorumCnxManager.access$500(QuorumCnxManager.java:65) at org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:715) 2016-07-12 22:35:19,877 [myid:] - WARN [SendWorker:2:QuorumCnxManager$SendWorker@736] - Send worker leaving thread 2016-07-12 22:35:20,876 [myid:] - INFO [main:CnxManagerTest@249] - Socket has been closed as expected 2016-07-12 22:35:20,876 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@58] - Memory used 12944 2016-07-12 22:35:20,876 [myid:] - ERROR [/0.0.0.0:11273:QuorumCnxManager$Listener@547] - Exception while listening java.net.SocketException: Socket closed at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404) at java.net.ServerSocket.implAccept(ServerSocket.java:545) at java.net.ServerSocket.accept(ServerSocket.java:513) at org.apache.zookeeper.server.quorum.QuorumCnxManager$Listener.run(QuorumCnxManager.java:539) 2016-07-12 22:35:20,877 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@63] - Number of threads 14 2016-07-12 22:35:20,877 [myid:] - INFO [main:JUnit4ZKTestRunner$LoggedInvokeMethod@78] - FINISHED TEST METHOD testCnxManagerSpinLock 2016-07-12 22:35:20,877 [myid:] - INFO [main:ZKTestCase$1@60] - SUCCEEDED testCnxManagerSpinLock 2016-07-12 22:35:20,877 [myid:] - INFO [main:ZKTestCase$1@55] - FINISHED testCnxManagerSpinLock {noformat}

    Apache's JIRA Issue Tracker | 4 months ago | Michael Han
    java.lang.InterruptedException: sleep interrupted
  3. 0

    Bot Stop after find match/ StateAttack

    GitHub | 2 years ago | larknart
    java.lang.InterruptedException: sleep interrupted
  4. Speed up your debug routine!

    Automated exception search integrated into your IDE

  5. 0

    StateIdle

    GitHub | 2 years ago | AomineDaiki21
    java.lang.InterruptedException: sleep interrupted
  6. 0

    Bot worked but now stuck on cant find dependant libraries

    GitHub | 2 years ago | badboy1645
    java.lang.InterruptedException: sleep interrupted

  1. Alexandru Popa 6 times, last 2 weeks ago
  2. danleyb2Interintel 1 times, last 4 weeks ago
  3. filpgame 77 times, last 1 week ago
  4. ajinkya_w 3 times, last 2 months ago
  5. ajinkya_w 3 times, last 2 months ago
8 more registered users
11 unregistered visitors
Not finding the right solution?
Take a tour to get the most out of Samebug.

Tired of useless tips?

Automated exception search integrated into your IDE

Root Cause Analysis

  1. java.lang.InterruptedException

    sleep interrupted

    at java.lang.Thread.sleep()
  2. Java RT
    Thread.sleep
    1. java.lang.Thread.sleep(Native Method)
    1 frame
  3. Zookeeper
    QuorumPeer.run
    1. org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:456)
    2. org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:859)
    2 frames