Thanks Flavio. We haven't 100% figured out what was happening, but once we do I'll update if your explanation doesn't match up.
~Jared On Sun, Jan 6, 2013 at 4:24 AM, Flavio Junqueira <[email protected]>wrote: > Hi Jared, > > The message is definitely not very informative, but the scenario I believe > is harmless. The log entries that really matter are 1 and 3, not 2 and 3 as > you pointed out originally: > > 1) Nov 5 12:46:34 zookeeper - INFO [LearnerHandler-/10.10.5.13:51363 > :LearnerHandler@326] - Synchronizing with Follower sid: 2 > maxCommittedLog=0x900000004 minCommittedLog=0x900000001 > peerLastZxid=0x700000001 > > 2) *Nov 5 12:46:34 zookeeper - INFO [LearnerHandler-/10.10.5.12:44880 > :LearnerHandler@326] - Synchronizing with Follower sid: 1 > maxCommittedLog=0x900000004 minCommittedLog=0x900000001 > peerLastZxid=0x900000004* > > 3) *Nov 5 12:46:34 zookeeper - WARN [LearnerHandler-/10.10.5.13:51363 > :LearnerHandler@387] - Unhandled proposal scenario* > > The unhandled message is generate when we are trying to decide whether to > send a diff or to truncate, so you've hit the case in which we do neither. > However, by default, we send a snapshot, as your logs are showing we do: > > Nov 5 12:46:34 zookeeper - INFO [LearnerHandler-/10.10.5.13:51363 > :LearnerHandler@402] - Sending SNAP > > Please let me know if you disagree with this analysis. It might be worth > having a trivial jura to change that log message. > > -Flavio > > > On Jan 6, 2013, at 4:55 AM, Jared Cantwell <[email protected]> > wrote: > > > Some code that we're testing was causing some servers to thrash, but once > > things settled down leader election was getting "Unhandled proposal > > scenario". Anyone know what might cause a server to get into this > > situation? > > > > Nov 5 12:46:33 zookeeper - INFO [QuorumPeer[myid=5]/10.10.5.82:2181 > > :Leader@424] - LEADING - LEADER ELECTION TOOK - 12 > > Nov 5 12:46:33 zookeeper - INFO [QuorumPeer[myid=5]/10.10.5.82:2181 > > :FileSnap@83] - Reading snapshot /sf/data/zookeeper/ > > 10.10.5.82/version-2/snapshot.800000017 > > Nov 5 12:46:33 zookeeper - INFO [QuorumPeer[myid=5]/10.10.5.82:2181 > > :FileTxnSnapLog@270] - Snapshotting: 0x900000004 to /sf/data/zookeeper/ > > 10.10.5.82/version-2/snapshot.900000004 > > Nov 5 12:46:34 zookeeper - INFO [LearnerHandler-/10.10.5.13:51363 > > :LearnerHandler@267] - Follower sid: 2 : info : 10.10.5.13:2182 > > :2183:participant;10.10.5.13:2181 > > Nov 5 12:46:34 zookeeper - INFO [LearnerHandler-/10.10.5.12:44880 > > :LearnerHandler@267] - Follower sid: 1 : info : 10.10.5.12:2182 > > :2183:participant;10.10.5.12:2181 > > Nov 5 12:46:34 zookeeper - INFO [LearnerHandler-/10.10.5.13:51363 > > :LearnerHandler@326] - Synchronizing with Follower sid: 2 > > maxCommittedLog=0x900000004 minCommittedLog=0x900000001 > > peerLastZxid=0x700000001 > > *Nov 5 12:46:34 zookeeper - INFO [LearnerHandler-/10.10.5.12:44880 > > :LearnerHandler@326] - Synchronizing with Follower sid: 1 > > maxCommittedLog=0x900000004 minCommittedLog=0x900000001 > > peerLastZxid=0x900000004* > > *Nov 5 12:46:34 zookeeper - WARN [LearnerHandler-/10.10.5.13:51363 > > :LearnerHandler@387] - Unhandled proposal scenario* > > Nov 5 12:46:34 zookeeper - INFO [LearnerHandler-/10.10.5.13:51363 > > :LearnerHandler@402] - Sending SNAP > > Nov 5 12:46:34 zookeeper - INFO [LearnerHandler-/10.10.5.12:44880 > > :LearnerHandler@402] - Sending DIFF > > Nov 5 12:46:34 zookeeper - INFO [LearnerHandler-/10.10.5.13:51363 > > :LearnerHandler@433] - Sending snapshot last zxid of peer is 0x700000001 > > zxid of leader is 0xa00000000sent zxid of db as 0x900000004 > > Nov 5 12:46:34 zookeeper - WARN [LearnerHandler-/10.10.5.13:51363 > > :Leader@698] - Commiting zxid 0xa00000000 from /10.10.5.82:2182 not > first! > > Nov 5 12:46:34 zookeeper - WARN [LearnerHandler-/10.10.5.13:51363 > > :Leader@700] - First is 0 > > Nov 5 12:46:34 zookeeper - INFO [LearnerHandler-/10.10.5.13:51363 > > :Leader@753] - Have quorum of supporters; starting up and setting last > > processed zxid: 42949672960 > > Nov 5 12:46:34 zookeeper - INFO [SyncThread:5:FileTxnLog@199] - > Creating > > new log file: log.a00000001 > > > > ~Jared > >
