[
https://issues.apache.org/jira/browse/ZOOKEEPER-1006?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13002357#comment-13002357
]
Patrick Hunt commented on ZOOKEEPER-1006:
-----------------------------------------
here's an example of recent failure on ubuntu:
{noformat}
2011-03-03 16:25:53,599 - INFO [main:CnxManagerTest@309] - Round 0, restarting
peer 1
2011-03-03 16:25:53,600 - INFO [main:FileSnap@82] - Reading snapshot
/home/phunt/zookeeper/build/test/tmp/test4354134956302701428.junit.dir/version-2/snapshot.0
2011-03-03 16:25:53,601 - INFO [Thread-96:QuorumCnxManager$Listener@473] - My
election bind port: 11255
2011-03-03 16:25:53,602 - INFO
[QuorumPeer:/0:0:0:0:0:0:0:0:11254:QuorumPeer@621] - LOOKING
2011-03-03 16:25:53,603 - INFO
[QuorumPeer:/0:0:0:0:0:0:0:0:11254:FastLeaderElection@663] - New election. My
id = 1, Proposed zxid = 0
2011-03-03 16:25:53,637 - INFO [WorkerReceiver Thread:FastLeaderElection@496]
- Notification: 1 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
(n.sid), FOLLOWING (my state)
2011-03-03 16:25:53,637 - INFO [WorkerReceiver Thread:FastLeaderElection@496]
- Notification: 0 (n.leader), 4294967296 (n.zxid), 1 (n.round), LOOKING
(n.state), 0 (n.sid), LOOKING (my state)
2011-03-03 16:25:53,638 - INFO
[QuorumPeer:/0:0:0:0:0:0:0:0:11254:FastLeaderElection@721] - Updating proposal
2011-03-03 16:25:53,638 - INFO [WorkerReceiver Thread:FastLeaderElection@496]
- Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), FOLLOWING (n.state), 0
(n.sid), LOOKING (my state)
2011-03-03 16:25:53,638 - INFO [WorkerReceiver Thread:FastLeaderElection@496]
- Notification: 1 (n.leader), 0 (n.zxid), 1 (n.round), LOOKING (n.state), 1
(n.sid), LOOKING (my state)
2011-03-03 16:25:53,654 - INFO [WorkerSender Thread:QuorumCnxManager@183] -
Have smaller server identifier, so dropping the connection: (2, 1)
2011-03-03 16:25:53,654 - INFO [WorkerReceiver Thread:FastLeaderElection@496]
- Notification: 0 (n.leader), 4294967296 (n.zxid), 1 (n.round), LOOKING
(n.state), 1 (n.sid), FOLLOWING (my state)
2011-03-03 16:25:53,654 - INFO [WorkerReceiver Thread:FastLeaderElection@496]
- Notification: 0 (n.leader), 4294967296 (n.zxid), 1 (n.round), LOOKING
(n.state), 1 (n.sid), LOOKING (my state)
2011-03-03 16:25:53,655 - INFO [WorkerReceiver Thread:FastLeaderElection@496]
- Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), FOLLOWING (n.state), 0
(n.sid), LOOKING (my state)
2011-03-03 16:25:53,657 - INFO [WorkerSender Thread:QuorumCnxManager@183] -
Have smaller server identifier, so dropping the connection: (2, 1)
2011-03-03 16:25:53,657 - WARN [Thread-102:QuorumCnxManager$RecvWorker@727] -
Connection broken for id 1, my id = 2, error =
java.nio.channels.AsynchronousCloseException
2011-03-03 16:25:53,658 - WARN [Thread-102:QuorumCnxManager$RecvWorker@730] -
Interrupting SendWorker
2011-03-03 16:25:53,687 - WARN [Thread-103:QuorumCnxManager$SendWorker@638] -
Exception when using channel: for id 2 my id = 1 error = java.io.IOException:
Broken pipe
2011-03-03 16:25:53,687 - WARN [Thread-104:QuorumCnxManager$RecvWorker@727] -
Connection broken for id 2, my id = 1, error =
java.nio.channels.ClosedChannelException
2011-03-03 16:25:53,687 - WARN [Thread-104:QuorumCnxManager$RecvWorker@730] -
Interrupting SendWorker
2011-03-03 16:25:53,688 - ERROR [Thread-101:QuorumCnxManager$SendWorker@611] -
Failed to send last message. Shutting down thread.
java.nio.channels.ClosedChannelException
at
sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:126)
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:324)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.send(QuorumCnxManager.java:599)
at
org.apache.zookeeper.server.quorum.QuorumCnxManager$SendWorker.run(QuorumCnxManager.java:609)
2011-03-03 16:25:53,688 - WARN [Thread-101:QuorumCnxManager$SendWorker@642] -
Send worker leaving thread
2011-03-03 16:25:53,688 - WARN [Thread-103:QuorumCnxManager$SendWorker@642] -
Send worker leaving thread
2011-03-03 16:25:53,855 - INFO
[QuorumPeer:/0:0:0:0:0:0:0:0:11254:FastLeaderElection@697] - Notification time
out: 400
2011-03-03 16:25:53,855 - INFO [WorkerReceiver Thread:FastLeaderElection@496]
- Notification: 0 (n.leader), 4294967296 (n.zxid), 1 (n.round), LOOKING
(n.state), 1 (n.sid), LOOKING (my state)
2011-03-03 16:25:53,856 - INFO [WorkerReceiver Thread:FastLeaderElection@496]
- Notification: 0 (n.leader), 4294967296 (n.zxid), 1 (n.round), LOOKING
(n.state), 1 (n.sid), FOLLOWING (my state)
2011-03-03 16:25:53,856 - INFO [WorkerReceiver Thread:FastLeaderElection@496]
- Notification: 2 (n.leader), 0 (n.zxid), 1 (n.round), FOLLOWING (n.state), 0
(n.sid), LOOKING (my state)
2011-03-03 16:25:54,256 - INFO
[QuorumPeer:/0:0:0:0:0:0:0:0:11254:FastLeaderElection@697] - Notification time
out: 800
2011-03-03 16:25:55,057 - INFO
[QuorumPeer:/0:0:0:0:0:0:0:0:11254:FastLeaderElection@697] - Notification time
out: 1600
2011-03-03 16:25:56,657 - INFO
[QuorumPeer:/0:0:0:0:0:0:0:0:11254:FastLeaderElection@697] - Notification time
out: 3200
------------- ---------------- ---------------
FAILURE
{noformat}
> QuorumPeer "Address already in use" -- regression in 3.3.3
> ----------------------------------------------------------
>
> Key: ZOOKEEPER-1006
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-1006
> Project: ZooKeeper
> Issue Type: Bug
> Affects Versions: 3.3.3
> Reporter: Patrick Hunt
> Priority: Blocker
> Attachments: TEST-org.apache.zookeeper.test.CnxManagerTest.txt,
> ZOOKEEPER-1006.patch, workerthreads_badtest.txt
>
>
> CnxManagerTest.testWorkerThreads
> See attachment, this is the first time I've seen this test fail, and it's
> failed 2 out of the last three test runs.
> Notice (attachment) once this happens the port never becomes available.
> {noformat}
> 2011-03-02 15:53:12,425 - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11245:NIOServerCnxn$Factory@251] -
> Accepted socket connection from /172.29.6.162:51441
> 2011-03-02 15:53:12,430 - WARN
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11245:NIOServerCnxn@639] - Exception
> causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not
> running
> 2011-03-02 15:53:12,430 - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11245:NIOServerCnxn@1435] - Closed
> socket connection for client /172.29.6.162:51441 (no session established for
> client)
> 2011-03-02 15:53:12,430 - WARN
> [QuorumPeer:/0:0:0:0:0:0:0:0:11241:Follower@82] - Exception when following
> the leader
> java.io.EOFException
> at java.io.DataInputStream.readInt(DataInputStream.java:375)
> at
> org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:63)
> at
> org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:84)
> at
> org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:108)
> at
> org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:148)
> at
> org.apache.zookeeper.server.quorum.Learner.registerWithLeader(Learner.java:267)
> at
> org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:66)
> at
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:645)
> 2011-03-02 15:53:12,431 - INFO
> [QuorumPeer:/0:0:0:0:0:0:0:0:11241:Follower@165] - shutdown called
> java.lang.Exception: shutdown Follower
> at
> org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:165)
> at
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:649)
> 2011-03-02 15:53:12,432 - INFO
> [QuorumPeer:/0:0:0:0:0:0:0:0:11241:QuorumPeer@621] - LOOKING
> 2011-03-02 15:53:12,432 - INFO
> [QuorumPeer:/0:0:0:0:0:0:0:0:11241:FastLeaderElection@663] - New election. My
> id = 0, Proposed zxid = 0
> 2011-03-02 15:53:12,433 - INFO [WorkerReceiver
> Thread:FastLeaderElection@496] - Notification: 0 (n.leader), 0 (n.zxid), 2
> (n.round), LOOKING (n.state), 0 (n.sid), LOOKING (my state)
> 2011-03-02 15:53:12,433 - INFO [WorkerReceiver
> Thread:FastLeaderElection@496] - Notification: 0 (n.leader), 0 (n.zxid), 2
> (n.round), LOOKING (n.state), 0 (n.sid), LOOKING (my state)
> 2011-03-02 15:53:12,433 - INFO [WorkerReceiver
> Thread:FastLeaderElection@496] - Notification: 0 (n.leader), 0 (n.zxid), 2
> (n.round), LOOKING (n.state), 0 (n.sid), LOOKING (my state)
> 2011-03-02 15:53:12,633 - INFO [WorkerReceiver
> Thread:FastLeaderElection@496] - Notification: 0 (n.leader), 0 (n.zxid), 2
> (n.round), LOOKING (n.state), 0 (n.sid), LOOKING (my state)
> 2011-03-02 15:53:12,633 - INFO
> [QuorumPeer:/0:0:0:0:0:0:0:0:11245:QuorumPeer@655] - LEADING
> 2011-03-02 15:53:12,636 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:11245:Leader@54]
> - TCP NoDelay set to: true
> 2011-03-02 15:53:12,638 - INFO
> [QuorumPeer:/0:0:0:0:0:0:0:0:11245:ZooKeeperServer@151] - Created server with
> tickTime 1000 minSessionTimeout 2000 maxSessionTimeout 20000 datadir
> /var/lib/hudson/workspace/CDH3-ZooKeeper-3.3.3_sles/build/test/tmp/test9001250572426375869.junit.dir/version-2
> snapdir
> /var/lib/hudson/workspace/CDH3-ZooKeeper-3.3.3_sles/build/test/tmp/test9001250572426375869.junit.dir/version-2
> 2011-03-02 15:53:12,639 - ERROR
> [QuorumPeer:/0:0:0:0:0:0:0:0:11245:Leader@133] - Couldn't bind to port 11245
> java.net.BindException: Address already in use
> at java.net.PlainSocketImpl.socketBind(Native Method)
> at java.net.PlainSocketImpl.bind(PlainSocketImpl.java:365)
> at java.net.ServerSocket.bind(ServerSocket.java:319)
> at java.net.ServerSocket.<init>(ServerSocket.java:185)
> at java.net.ServerSocket.<init>(ServerSocket.java:97)
> at org.apache.zookeeper.server.quorum.Leader.<init>(Leader.java:131)
> at
> org.apache.zookeeper.server.quorum.QuorumPeer.makeLeader(QuorumPeer.java:512)
> at
> org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:657)
> {noformat}
--
This message is automatically generated by JIRA.
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
