[
https://issues.apache.org/jira/browse/ZOOKEEPER-2502?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15433873#comment-15433873
]
Patrick Hunt commented on ZOOKEEPER-2502:
-----------------------------------------
A sync limit of 2 seems pretty low in general. Shouldn't we fix this for all
the tests? Why just this one line? It looks to me like there are a number of
QuorumPeer constructors called with this low limit. Also shouldn't we be fixing
this on trunk/3.5 as well?
> Flaky Test:
> org.apache.zookeeper.server.quorum.CnxManagerTest.testCnxFromFutureVersion
> --------------------------------------------------------------------------------------
>
> Key: ZOOKEEPER-2502
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2502
> Project: ZooKeeper
> Issue Type: Bug
> Components: tests
> Affects Versions: 3.4.9
> Reporter: Michael Han
> Assignee: Michael Han
> Labels: flaky, flaky-test
> Fix For: 3.4.10
>
> Attachments: ZOOKEEPER-2502.patch, ZOOKEEPER-2502.patch
>
>
> {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}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
