zookeeper-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Jared Cantwell <jared.cantw...@gmail.com>
Subject Re: Unhandled proposal scenario
Date Sun, 06 Jan 2013 15:01:29 GMT
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 <fpjunqueira@yahoo.com>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 <jared.cantwell@gmail.com>
> 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
>
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message