Home | About | Sematext search-lucene.com search-hadoop.com
 Search Hadoop and all its subprojects:

Switch to Threaded View
Zookeeper, mail # user - Unhandled proposal scenario


Copy link to this message
-
Re: Unhandled proposal scenario
Flavio Junqueira 2013-01-06, 11:24
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