You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@zookeeper.apache.org by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org> on 2010/06/22 18:49:54 UTC
[jira] Created: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Last processed zxid set prematurely while establishing leadership
-----------------------------------------------------------------
Key: ZOOKEEPER-790
URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
Project: Zookeeper
Issue Type: Bug
Components: quorum
Affects Versions: 3.3.1
Reporter: Flavio Paiva Junqueira
Fix For: 3.3.2
Attachments: ZOOKEEPER-790.patch
The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
Re: [jira] Commented: (ZOOKEEPER-790) Last processed zxid set prematurely while establishing leadership
Posted by Flavio Junqueira <fp...@yahoo-inc.com>.
I forgot if you have provided already a description of how you
reproduce it. If you could point me out to that, I would appreciate.
-Flavio
On Jul 13, 2010, at 11:33 PM, Vishal K wrote:
> Hi Flavio ,
>
> I got the same error messages. I can reproduce this quite easily. I
> will
> capture the logs again. Is there anything else you would like me to
> provide?
> Thanks.
>
> -Vishal
>
> On Tue, Jul 13, 2010 at 3:52 PM, Flavio Paiva Junqueira (JIRA) <
> jira@apache.org> wrote:
>
>>
>> [
>> https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12887969
>> #action_12887969]
>>
>> Flavio Paiva Junqueira commented on ZOOKEEPER-790:
>> --------------------------------------------------
>>
>> Vishal, What exactly didn't work? Do you get the same error
>> messages with
>> the patch? Do you have a reliable way of reproducing it? In
>> general, it
>> would be useful if you could provide more detail.
>>
>> Thanks!
>>
>>
>>> Last processed zxid set prematurely while establishing leadership
>>> -----------------------------------------------------------------
>>>
>>> Key: ZOOKEEPER-790
>>> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
>>> Project: Zookeeper
>>> Issue Type: Bug
>>> Components: quorum
>>> Affects Versions: 3.3.1
>>> Reporter: Flavio Paiva Junqueira
>>> Assignee: Flavio Paiva Junqueira
>>> Priority: Blocker
>>> Fix For: 3.3.2, 3.4.0
>>>
>>> Attachments: ZOOKEEPER-790.patch
>>>
>>>
>>> The leader code is setting the last processed zxid to the first of
>>> the
>> new epoch even before connecting to a quorum of followers. Because
>> the
>> leader code sets this value before connecting to a quorum of
>> followers
>> (Leader.java:281) and the follower code throws an IOException
>> (Follower.java:73) if the leader epoch is smaller, we have that
>> when the
>> false leader drops leadership and becomes a follower, it finds a
>> smaller
>> epoch and kills itself.
>>
>> --
>> This message is automatically generated by JIRA.
>> -
>> You can reply to this email to add a comment to the issue online.
>>
>>
flavio
junqueira
research scientist
fpj@yahoo-inc.com
direct +34 93-183-8828
avinguda diagonal 177, 8th floor, barcelona, 08018, es
phone (408) 349 3300 fax (408) 349 3301
Re: [jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by Vishal K <vi...@gmail.com>.
Hi Flavio ,
I got the same error messages. I can reproduce this quite easily. I will
capture the logs again. Is there anything else you would like me to provide?
Thanks.
-Vishal
On Tue, Jul 13, 2010 at 3:52 PM, Flavio Paiva Junqueira (JIRA) <
jira@apache.org> wrote:
>
> [
> https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12887969#action_12887969]
>
> Flavio Paiva Junqueira commented on ZOOKEEPER-790:
> --------------------------------------------------
>
> Vishal, What exactly didn't work? Do you get the same error messages with
> the patch? Do you have a reliable way of reproducing it? In general, it
> would be useful if you could provide more detail.
>
> Thanks!
>
>
> > Last processed zxid set prematurely while establishing leadership
> > -----------------------------------------------------------------
> >
> > Key: ZOOKEEPER-790
> > URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> > Project: Zookeeper
> > Issue Type: Bug
> > Components: quorum
> > Affects Versions: 3.3.1
> > Reporter: Flavio Paiva Junqueira
> > Assignee: Flavio Paiva Junqueira
> > Priority: Blocker
> > Fix For: 3.3.2, 3.4.0
> >
> > Attachments: ZOOKEEPER-790.patch
> >
> >
> > The leader code is setting the last processed zxid to the first of the
> new epoch even before connecting to a quorum of followers. Because the
> leader code sets this value before connecting to a quorum of followers
> (Leader.java:281) and the follower code throws an IOException
> (Follower.java:73) if the leader epoch is smaller, we have that when the
> false leader drops leadership and becomes a follower, it finds a smaller
> epoch and kills itself.
>
> --
> This message is automatically generated by JIRA.
> -
> You can reply to this email to add a comment to the issue online.
>
>
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Paiva Junqueira updated ZOOKEEPER-790:
---------------------------------------------
Attachment: ZOOKEEPER-790.patch
Hi! I'm attaching a patch that works for my setup (and passes the unit tests as well), so I would appreciate if you could give it a try.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888304#action_12888304 ]
Flavio Paiva Junqueira commented on ZOOKEEPER-790:
--------------------------------------------------
Hi Vishal, Thanks for all the information. I haven't been able to reproduce it yet, but here are some thoughts after looking over your logs again:
1- It is not a problem that server 0 is declaring itself leader, even though there is another leader running. Server 0 will be ignored by the others and eventually will drop its leadership as you have observed;
2- The notifications of 1 and 2 say looking because they have been queued at the time 1 and 2 were looking for a leader. That's not an issue;
3- I don't understand why the patch doesn't work. Let me tell you how I'm interpreting your run. Server 0 is receiving the notifications from 1 and 2, and deciding that it should be the leader. Because in the current trunk code we set the first zxid for the new epoch before hearing from a quorum, once server 0 drops leadership, it has a higher zxid than everyone else. Consequently, it correctly refuses to talk to the current leader. Now, setting the first epoch zxid prematurely is a problem, and the patch I have uploaded should fix it. The bottom line is that I can't understand why the patch I uploaded does not fix it. Have you made sure to apply it before running your new tests? Either way, I would appreciate if you could upload logs out of a run with the current 790 patch.
Thanks!
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Flavio Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12892520#action_12892520 ]
Flavio Junqueira commented on ZOOKEEPER-790:
--------------------------------------------
Hi VIshal, Thanks for testing as well. The issue you mention about the LOOKING state, if I understand correctly, is not about the state of the server, but the state reported in the notification.
If so, then it happens because we always repeat the last message sent. Such duplicate messages cause what you have observed, but they are supposed to be harmless, in the sense that
I do not expect them to lead to any inconsistency in the ZooKeeper service. Instead, it may only cause some periods in which some process believes incorrectly to be the leader, but again,
the service is robust to such scenarios.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Junqueira updated ZOOKEEPER-790:
---------------------------------------
Status: Patch Available (was: Open)
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.v2.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Vishal K (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12892478#action_12892478 ]
Vishal K commented on ZOOKEEPER-790:
------------------------------------
Hi Flavio,
Apologies for not trying the patch sooner. I will try out the patch soon (altough Sergey has pointed out a potential problem).
I am still not conviced why the other two nodes that have formed the cluster are in LOOKING state?
You mentioned that - "The notifications of 1 and 2 say looking because they have been queued at the time 1 and 2 were looking for a leader. That's not an issue".
However, in this case, we have failed a follower and not a leader. Why would failure of a follower cause the other two nodes (including the leader) to start looking for a leader?
Am I missing something?
Thanks.
-Vishal
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Vishal K (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12889225#action_12889225 ]
Vishal K commented on ZOOKEEPER-790:
------------------------------------
great! I will give it a try. Thanks.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Hudson (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12894000#action_12894000 ]
Hudson commented on ZOOKEEPER-790:
----------------------------------
Integrated in ZooKeeper-trunk #890 (See [http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/890/])
ZOOKEEPER-790. Last processed zxid set prematurely while establishing leadership (flavio via mahadev)
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.v2.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Paiva Junqueira updated ZOOKEEPER-790:
---------------------------------------------
Attachment: ZOOKEEPER-790.patch
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Junqueira updated ZOOKEEPER-790:
---------------------------------------
Attachment: ZOOKEEPER-790-3.3.v2.patch
Fixed issue pointed out by Mahadev. Submitting patch for 3.3 first.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.v2.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Paiva Junqueira updated ZOOKEEPER-790:
---------------------------------------------
Status: Open (was: Patch Available)
Just in case will cancel and resubmit.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Travis Crawford (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888576#action_12888576 ]
Travis Crawford commented on ZOOKEEPER-790:
-------------------------------------------
Sure, I'll help test this too.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Patrick Hunt (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12892528#action_12892528 ]
Patrick Hunt commented on ZOOKEEPER-790:
----------------------------------------
Would be great to have a test for this latest change.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Sergey Doroshenko (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12892442#action_12892442 ]
Sergey Doroshenko commented on ZOOKEEPER-790:
---------------------------------------------
Easy way to reproduce:
* start 2 out of 3 peers
* connect to the ensemble by zkCli.sh
* shutdown a peer, wait a bit
* start the peer
Due to NPE (which is not seen in logs however) servers can't form a quorum, and client is unable to reconnect.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Junqueira updated ZOOKEEPER-790:
---------------------------------------
Status: Open (was: Patch Available)
Submitting a new patch right after.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Sergey Doroshenko (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Sergey Doroshenko updated ZOOKEEPER-790:
----------------------------------------
Attachment: ZOOKEEPER-790-test.patch
The test that was failing was the test for r/o mode, so it wouldn't apply here.
I've extracted necessary code from it and made it a test case in QuorumTest. It fails against current trunk but passes against latest patch.
This test case uses QuorumUtil which I also extracted from my r/o mode patch. I made it for convenient quorum testing, it's more handy than current QuorumBase, and I plan to make QuorumBase a special case of it.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Vishal K (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888119#action_12888119 ]
Vishal K commented on ZOOKEEPER-790:
------------------------------------
copying comments from email to jira.
Hi Flavio ,
I got the same error messages. I can reproduce this quite easily. I will capture the logs again. Is there anything else you would like me to provide? Thanks.
-Vishal
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Travis Crawford (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12890512#action_12890512 ]
Travis Crawford commented on ZOOKEEPER-790:
-------------------------------------------
I tested this patch on a build with the following, applied in the listed order: 3.3.1 release + ZOOKEEPER-744.patch + ZOOKEEPER-790-3.3.patch
Looks good!
{code}
2010-07-20 23:43:34,229 - INFO [Thread-2545:NIOServerCnxn@1516] - Closed socket connection for client /10.209.21.181:53743 (no session established for client)
2010-07-20 23:43:34,659 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@639] - EndOfStreamException: Unable to read additional data from client sessionid 0x129d3fcb5a6f60d, likely client has closed socket
2010-07-20 23:43:34,660 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1516] - Closed socket connection for client /10.209.21.204:59727 which had sessionid 0x129d3fcb5a6f60d
2010-07-20 23:43:34,684 - INFO [ProcessThread:-1:PrepRequestProcessor@385] - Processed session termination for sessionid: 0x329d3fcb6594e53
2010-07-20 23:52:14,522 - INFO [main:QuorumPeerConfig@90] - Reading configuration from: /etc/zookeeper/conf/zoo.cfg
2010-07-20 23:52:14,529 - INFO [main:QuorumPeerConfig@287] - Defaulting to majority quorums
2010-07-20 23:52:14,540 - INFO [main:QuorumPeerMain@119] - Starting quorum peer
2010-07-20 23:52:14,562 - INFO [main:NIOServerCnxn$Factory@149] - binding to port 0.0.0.0/0.0.0.0:2181
2010-07-20 23:52:14,578 - INFO [main:QuorumPeer@818] - tickTime set to 2000
2010-07-20 23:52:14,579 - INFO [main:QuorumPeer@829] - minSessionTimeout set to -1
2010-07-20 23:52:14,579 - INFO [main:QuorumPeer@840] - maxSessionTimeout set to -1
2010-07-20 23:52:14,579 - INFO [main:QuorumPeer@855] - initLimit set to 10
2010-07-20 23:52:14,798 - INFO [main:FileSnap@82] - Reading snapshot /data/zookeeper/version-2/snapshot.2500197ee5
2010-07-20 23:52:15,660 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@256] - Accepted socket connection from /10.209.45.76:57030
2010-07-20 23:52:15,661 - INFO [Thread-1:QuorumCnxManager$Listener@436] - My election bind port: 3888
2010-07-20 23:52:15,663 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@644] - Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
2010-07-20 23:52:15,664 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1516] - Closed socket connection for client /10.209.45.76:57030 (no session established for client)
2010-07-20 23:52:15,670 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:QuorumPeer@620] - LOOKING
2010-07-20 23:52:15,672 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FastLeaderElection@649] - New election. My id = 1, Proposed zxid = 158915472832
2010-07-20 23:52:15,674 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FastLeaderElection@689] - Notification: 1, 158915472832, 1, 1, LOOKING, LOOKING, 1
2010-07-20 23:52:15,674 - INFO [WorkerSender Thread:QuorumCnxManager@162] - Have smaller server identifier, so dropping the connection: (2, 1)
2010-07-20 23:52:15,675 - INFO [WorkerSender Thread:QuorumCnxManager@162] - Have smaller server identifier, so dropping the connection: (3, 1)
2010-07-20 23:52:15,676 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FastLeaderElection@689] - Notification: 2, 158915472832, 5, 1, LOOKING, LOOKING, 2
2010-07-20 23:52:15,676 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FastLeaderElection@689] - Notification: 3, 158915472832, 5, 1, LOOKING, LOOKING, 2
2010-07-20 23:52:15,676 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FastLeaderElection@711] - Updating proposal
2010-07-20 23:52:15,677 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FastLeaderElection@799] - Notification: 3, 158915472832, 5, 1, LOOKING, FOLLOWING, 2
2010-07-20 23:52:15,677 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FastLeaderElection@689] - Notification: 3, 158915472832, 5, 1, LOOKING, LOOKING, 3
2010-07-20 23:52:15,879 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:QuorumPeer@642] - FOLLOWING
2010-07-20 23:52:15,885 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Learner@72] - TCP NoDelay set to: true
2010-07-20 23:52:15,893 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:zookeeper.version=3.3.1-942149, built on 05/07/2010 17:14 GMT
2010-07-20 23:52:15,893 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:host.name=sjc1k029.twitter.com
2010-07-20 23:52:15,894 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:java.version=1.6.0_16
2010-07-20 23:52:15,894 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:java.vendor=Sun Microsystems Inc.
2010-07-20 23:52:15,894 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:java.home=/usr/java/jdk1.6.0_16/jre
2010-07-20 23:52:15,894 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:java.class.path=/etc/zookeeper/conf::/usr/local/zookeeper/../zookeeper-*.jar:/usr/local/zookeeper/../lib/*.jar:/usr/local/zookeeper/../src/java/lib/*.jar:/usr/local/zookeeper/jline-0.9.94.jar:/usr/local/zookeeper/log4j-1.2.15.jar:/usr/local/zookeeper/zookeeper-3.3.2-dev.jar
2010-07-20 23:52:15,895 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:java.library.path=/usr/java/jdk1.6.0_16/jre/lib/amd64/server:/usr/java/jdk1.6.0_16/jre/lib/amd64:/usr/java/jdk1.6.0_16/jre/../lib/amd64:/usr/java/packages/lib/amd64:/lib:/usr/lib
2010-07-20 23:52:15,895 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:java.io.tmpdir=/tmp
2010-07-20 23:52:15,895 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:java.compiler=<NA>
2010-07-20 23:52:15,896 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:os.name=Linux
2010-07-20 23:52:15,896 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:os.arch=amd64
2010-07-20 23:52:15,896 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:os.version=2.6.18-164.6.1.el5
2010-07-20 23:52:15,897 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:user.name=root
2010-07-20 23:52:15,897 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:user.home=/root
2010-07-20 23:52:15,897 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:user.dir=/
2010-07-20 23:52:15,899 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:ZooKeeperServer@151] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /data/zookeeper/txlog/version-2 snapdir /data/zookeeper/version-2
2010-07-20 23:52:15,911 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Learner@285] - Getting a snapshot from leader
2010-07-20 23:52:16,152 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Learner@315] - Setting leader epoch 26
2010-07-20 23:52:16,166 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FileTxnSnapLog@208] - Snapshotting: 260000195d
2010-07-20 23:52:16,200 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@256] - Accepted socket connection from /10.209.21.181:49189
2010-07-20 23:52:16,200 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1314] - Processing stat command from /10.209.21.181:49189
2010-07-20 23:52:16,203 - INFO [Thread-6:NIOServerCnxn@1516] - Closed socket connection for client /10.209.21.181:49189 (no session established for client)
2010-07-20 23:52:16,446 - WARN [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Follower@116] - Got zxid 0x260000195e expected 0x1
2010-07-20 23:52:16,446 - INFO [SyncThread:1:FileTxnLog@197] - Creating new log file: log.260000195e
2010-07-20 23:52:19,205 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@256] - Accepted socket connection from /10.209.21.181:49192
2010-07-20 23:52:19,205 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1314] - Processing stat command from /10.209.21.181:49192
2010-07-20 23:52:19,206 - INFO [Thread-7:NIOServerCnxn$StatCommand@1167] - Stat command output
2010-07-20 23:52:19,208 - INFO [Thread-7:NIOServerCnxn@1516] - Closed socket connection for client /10.209.21.181:49192 (no session established for client)
2010-07-20 23:52:20,562 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@256] - Accepted socket connection from /10.209.44.180:47281
2010-07-20 23:52:20,564 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@782] - Client attempting to establish new session at /10.209.44.180:47281
2010-07-20 23:52:20,574 - INFO [CommitProcessor:1:NIOServerCnxn@1661] - Established session 0x129f245a01c0000 with negotiated timeout 10000 for client /10.209.44.180:47281
2010-07-20 23:52:20,581 - INFO [CommitProcessor:1:PrepRequestProcessor@69] - zookeeper.skipACL=="yes", ACL checks will be skipped
2010-07-20 23:52:20,586 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@639] - EndOfStreamException: Unable to read additional data from client sessionid 0x129f245a01c0000, likely client has closed socket
2010-07-20 23:52:20,587 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1516] - Closed socket connection for client /10.209.44.180:47281 which had sessionid 0x129f245a01c0000
2010-07-20 23:52:20,826 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@256] - Accepted socket connection from /10.209.48.78:52838
2010-07-20 23:52:20,827 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@782] - Client attempting to establish new session at /10.209.48.78:52838
2010-07-20 23:52:20,829 - INFO [CommitProcessor:1:NIOServerCnxn@1661] - Established session 0x129f245a01c0001 with negotiated timeout 10000 for client /10.209.48.78:52838
2010-07-20 23:52:20,832 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@639] - EndOfStreamException: Unable to read additional data from client sessionid 0x129f245a01c0001, likely client has closed socket
2010-07-20 23:52:20,833 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1516] - Closed socket connection for client /10.209.48.78:52838 which had sessionid 0x129f245a01c0001
2010-07-20 23:52:22,210 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@256] - Accepted socket connection from /10.209.21.181:49197
2010-07-20 23:52:22,210 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1314] - Processing stat command from /10.209.21.181:49197
2010-07-20 23:52:22,211 - INFO [Thread-8:NIOServerCnxn$StatCommand@1167] - Stat command output
2010-07-20 23:52:22,227 - INFO [Thread-8:NIOServerCnxn@1516] - Closed socket connection for client /10.209.21.181:49197 (no session established for client)
2010-07-20 23:52:22,551 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@256] - Accepted socket connection from /10.209.45.104:42183
2010-07-20 23:52:22,552 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@782] - Client attempting to establish new session at /10.209.45.104:42183
2010-07-20 23:52:22,554 - INFO [CommitProcessor:1:NIOServerCnxn@1661] - Established session 0x129f245a01c0002 with negotiated timeout 10000 for client /10.209.45.104:42183
2010-07-20 23:52:22,560 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@639] - EndOfStreamException: Unable to read additional data from client sessionid 0x129f245a01c0002, likely client has closed socket
{code}
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Travis Crawford (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Travis Crawford updated ZOOKEEPER-790:
--------------------------------------
Attachment: ZOOKEEPER-790.travis.log.bz2
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Mahadev konar (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12892542#action_12892542 ]
Mahadev konar commented on ZOOKEEPER-790:
-----------------------------------------
sergey,
your +1 does count :). Also, can you please upload the testcase that was failing? It would be good to include the testcase with the patch as pat mentioned above.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Paiva Junqueira updated ZOOKEEPER-790:
---------------------------------------------
Status: Patch Available (was: Open)
Thank for reviewing, Ben. Resubmitting with the proposed fix.
Thanks for testing the patch, Travis. I don't really know why you're observing the wrong dates, though. Anyone else?
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Junqueira updated ZOOKEEPER-790:
---------------------------------------
Status: Patch Available (was: Reopened)
The latest patch applies to both trunk and 3.3.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Paiva Junqueira updated ZOOKEEPER-790:
---------------------------------------------
Status: Patch Available (was: Open)
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Vishal K (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12887941#action_12887941 ]
Vishal K commented on ZOOKEEPER-790:
------------------------------------
Folks,
Sorry to the delay. The patch did not work. Any other ideas? Thanks.
-Vishal
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12889072#action_12889072 ]
Flavio Paiva Junqueira commented on ZOOKEEPER-790:
--------------------------------------------------
Some additional information. We create a new transaction log when we try to append a transaction and there is no log file open. Consequently, we only create it when there is something to write. For the bad run above, here is the content of the log:
{noformat}
ZooKeeper Transactional Log File with dbid 0 txnlog format version 2
7/15/10 5:27:45 PM CEST session 0x129d6b61b5b0000 cxid 0x0 zxid 0x200000001 closeSession
EOF reached after 1 txns.
{noformat}
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Benjamin Reed (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12891210#action_12891210 ]
Benjamin Reed commented on ZOOKEEPER-790:
-----------------------------------------
looks great flavio! the only nit i have is that the test case assumes that s1 is not the leader. you might want to check that.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Vishal K (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888443#action_12888443 ]
Vishal K commented on ZOOKEEPER-790:
------------------------------------
Hi Patrick,
I had done that earlier. I will do it again to reconfirm. I would also help if Travis or Charity can also try to verify the patch, if possible.
-Vishal
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Paiva Junqueira updated ZOOKEEPER-790:
---------------------------------------------
Attachment: ZOOKEEPER-790.patch
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Fix For: 3.3.2
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Vishal K (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12881282#action_12881282 ]
Vishal K commented on ZOOKEEPER-790:
------------------------------------
I will try out the patch. I will try it out on 3.3.0 since that is the version we are currently using.
-Vishal
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Vishal K (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888121#action_12888121 ]
Vishal K commented on ZOOKEEPER-790:
------------------------------------
copying comments from email to jira.
I forgot if you have provided already a description of how you reproduce it. If you could point me out to that, I would appreciate.
-Flavio
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Paiva Junqueira updated ZOOKEEPER-790:
---------------------------------------------
Status: Patch Available (was: Open)
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Hadoop QA (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12890451#action_12890451 ]
Hadoop QA commented on ZOOKEEPER-790:
-------------------------------------
-1 overall. Here are the results of testing the latest attachment
http://issues.apache.org/jira/secure/attachment/12449972/ZOOKEEPER-790.patch
against trunk revision 963957.
+1 @author. The patch does not contain any @author tags.
+1 tests included. The patch appears to include 6 new or modified tests.
+1 javadoc. The javadoc tool did not generate any warning messages.
+1 javac. The applied patch does not increase the total number of javac compiler warnings.
+1 findbugs. The patch does not introduce any new Findbugs warnings.
+1 release audit. The applied patch does not increase the total number of release audit warnings.
-1 core tests. The patch failed core unit tests.
+1 contrib tests. The patch passed contrib unit tests.
Test results: http://hudson.zones.apache.org/hudson/job/Zookeeper-Patch-h1.grid.sp2.yahoo.net/150/testReport/
Findbugs warnings: http://hudson.zones.apache.org/hudson/job/Zookeeper-Patch-h1.grid.sp2.yahoo.net/150/artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
Console output: http://hudson.zones.apache.org/hudson/job/Zookeeper-Patch-h1.grid.sp2.yahoo.net/150/console
This message is automatically generated.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Issue Comment Edited: (ZOOKEEPER-790) Last processed zxid
set prematurely while establishing leadership
Posted by "Mahadev konar (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12893219#action_12893219 ]
Mahadev konar edited comment on ZOOKEEPER-790 at 7/28/10 11:54 AM:
-------------------------------------------------------------------
flavio, the patch looks good. Any reason you have this code in learnerhandler?
{code}
@@ -475,6 +497,7 @@
} catch (IOException e) {
LOG.warn("Ignoring unexpected exception during socket close", e);
}
+ this.interrupt();
leader.removeLearnerHandler(this);
}
{code}
The interrupt? Why is this necessary?
was (Author: mahadev):
flavio, the patch looks good. Any reason you have this code in learnerhandler?
{quote}
@@ -475,6 +497,7 @@
} catch (IOException e) {
LOG.warn("Ignoring unexpected exception during socket close", e);
}
+ this.interrupt();
leader.removeLearnerHandler(this);
}
{quote}
The interrupt? Why is this necessary?
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Paiva Junqueira updated ZOOKEEPER-790:
---------------------------------------------
Status: Open (was: Patch Available)
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Paiva Junqueira updated ZOOKEEPER-790:
---------------------------------------------
Attachment: ZOOKEEPER-790.patch
This patch is very simple: it moves two function calls such that a leader only starts up and sets the the last processed zxid after it has a quorum of supporters. It also includes a unit test. I had to make a few modifications here and there to be able to write this test. I tried to minimize changes as much as possible.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Vishal K (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888123#action_12888123 ]
Vishal K commented on ZOOKEEPER-790:
------------------------------------
Hi Flavio,
I think there are two additional related problems:
1. Why are the other two nodes that have formed the cluster in LOOKING state? Both should reply with FOLLOWING
174 2010-06-20 23:22:46,440 - INFO [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@689] - Notification: 2, 73014444097, 1, 0, LOOKING, LOOKING, 2
2. The node attempting to join goes in an infinite loop of join fails. We should add a delay.
Thanks,
Vishal
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Sergey Doroshenko (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12892536#action_12892536 ]
Sergey Doroshenko commented on ZOOKEEPER-790:
---------------------------------------------
Hey Flavio,
Patch works ok: passes both manual testing and my unit test which was previously failing.
It looks conceptually correct, I'd give it +1 if I'd have such authority :)
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Flavio Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12893236#action_12893236 ]
Flavio Junqueira commented on ZOOKEEPER-790:
--------------------------------------------
Thanks for reviewing, Mahadev. The interrupt is necessary to guarantee that we will break this loop:
{noformat}
+ /*
+ * Wait until leader starts up
+ */
+ synchronized(leader.zk){
+ while(!leader.zk.isRunning()){
+ leader.zk.wait(500);
+ }
+ }
{noformat}
when shutting down the learner handler.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Mahadev konar (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12893219#action_12893219 ]
Mahadev konar commented on ZOOKEEPER-790:
-----------------------------------------
flavio, the patch looks good. Any reason you have this code in learnerhandler?
{quote}
@@ -475,6 +497,7 @@
} catch (IOException e) {
LOG.warn("Ignoring unexpected exception during socket close", e);
}
+ this.interrupt();
leader.removeLearnerHandler(this);
}
{quote}
The interrupt? Why is this necessary?
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Sergey Doroshenko (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Sergey Doroshenko updated ZOOKEEPER-790:
----------------------------------------
Attachment: ZOOKEEPER-790-follower-request-NPE.log
It seems this patch introduces a bug: followers get synchronized with leader and start serving clients before leader startups its own zk instance.
As the result, when a follower forward request to the leader, for example session revalidation request, it fails because leader's sessionTracker is null.
Previously this was not the case because leader started its zk immediately after quorum peer is switched to LEADING state.
See attached log.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Travis Crawford (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12890513#action_12890513 ]
Travis Crawford commented on ZOOKEEPER-790:
-------------------------------------------
Just to double-check, I'm really really sure the running jar was freshly built. For example, lsof says:
java 4473 root mem REG 104,1 1012397 10092999 /usr/local/zookeeper/zookeeper-3.3.2-dev.jar
Yes, the version number is 3.3.2, but this was built from the 3.3.1 release.
Looking in the log we see:
2010-07-20 23:52:15,893 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Environment@97] - Server environment:zookeeper.version=3.3.1-942149, built on 05/07/2010 17:14 GMT
Should that say built this afternoon? I've double & tripled checked and believe this is a newly built jar. Looking in the tarball we don't see zookeeper-3.3.2-dev.jar until after building.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Junqueira updated ZOOKEEPER-790:
---------------------------------------
Attachment: ZOOKEEPER-790.v2.patch
Thanks for providing a code base for the test, Sergey. I liked QuorumUtil so much that I have reimplemented the previous test to use it. This is in fact aligned with a discussion Ben and I had the other day about refactoring QuorumBase. You have introduced pretty much all functionality I was looking for, which simplified the test code.
I hope you don't mind that I have made some modifications to your original test. My proposed modifications are to make sure that we induce the right set of events. In the modified version, I have made sure that we have a client connecting to a follower and that we kill the leader so that we force a new election. In fact, the test was not always reliable for me in its original form.
The patch works for me.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Patrick Hunt (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888409#action_12888409 ]
Patrick Hunt commented on ZOOKEEPER-790:
----------------------------------------
Vishal, you might add some sort of log message to the code (in addition to the patch) to verify that the code you're running is the patched version.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Vishal K (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888330#action_12888330 ]
Vishal K commented on ZOOKEEPER-790:
------------------------------------
Hi Flavio,
I am going to retry again with the patch. Thanks.
-Vishal
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Travis Crawford (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888842#action_12888842 ]
Travis Crawford commented on ZOOKEEPER-790:
-------------------------------------------
Good find! I can certainly help test a patch, or collect more info if needed.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Vishal K (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12893776#action_12893776 ]
Vishal K commented on ZOOKEEPER-790:
------------------------------------
Hi,
I tested the patch and it works really well. I have a test that fails and restarts zookeeper server in a loop. I kept it going for 150 rounds and found no issues.
Thanks a lot.
-Vishal
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.v2.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Benjamin Reed (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Benjamin Reed updated ZOOKEEPER-790:
------------------------------------
Hadoop Flags: [Reviewed]
+1 great job flavio! thanx for your help travis and vishal.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Paiva Junqueira updated ZOOKEEPER-790:
---------------------------------------------
Attachment: ZOOKEEPER-790-3.3.patch
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Junqueira updated ZOOKEEPER-790:
---------------------------------------
Status: Patch Available (was: Open)
Need to generate a version for 3.3, but the one uploaded is ready to be reviewed for me.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Travis Crawford (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888688#action_12888688 ]
Travis Crawford commented on ZOOKEEPER-790:
-------------------------------------------
I accidentally posted this in ZOOKEEPER-335 -- reposting here. Sorry for the posting mixup -- the content is correct though :)
Unfortunately I still observed the "Leader epoch" issue and needed to manually force a leader election for the cluster to recover. This test was performed with the following base+patches, applied in the order listed.
Zookeeper 3.3.1
ZOOKEEPER-744
ZOOKEEPER-790
{code}
2010-07-15 02:43:57,181 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FileSnap@82] - Reading snapshot /data/zookeeper/version-2/snapshot.2300001ac2
2010-07-15 02:43:57,384 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FastLeaderElection@649] - New election. My id = 1, Proposed zxid = 154618826848
2010-07-15 02:43:57,385 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FastLeaderElection@689] - Notification: 1, 154618826848, 4, 1, LOOKING, LOOKING, 1
2010-07-15 02:43:57,385 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FastLeaderElection@799] - Notification: 2, 146030952153, 3, 1, LOOKING, LEADING, 2
2010-07-15 02:43:57,385 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:FastLeaderElection@799] - Notification: 2, 146030952153, 3, 1, LOOKING, FOLLOWING, 3
2010-07-15 02:43:57,385 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:QuorumPeer@642] - FOLLOWING
2010-07-15 02:43:57,385 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:ZooKeeperServer@151] - Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /data/zookeeper/txlog/version-2 snapdir /data/zookeeper/version-2
2010-07-15 02:43:57,387 - FATAL [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Follower@71] - Leader epoch 23 is less than our epoch 24
2010-07-15 02:43:57,387 - WARN [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Follower@82] - Exception when following the leader
java.io.IOException: Error: Epoch of leader is lower
at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:73)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:644)
2010-07-15 02:43:57,387 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181: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:648)
{code}
I followed the recipe @vishal provided for recreating.
(a) Stop one follower in a three node cluster
(b) Get some tea while it falls behind
(c) Start the node stopped in (a).
These timestamps show where the follower was stopped. It also shows when it was turned back on.
{code}
2010-07-15 02:35:36,398 - INFO [QuorumPeer:/0:0:0:0:0:0:0:0:2181:NIOServerCnxn@1661] - Established session 0x229aa13cfc6276b with negotiated timeout 10000 for client /10.209.45.114:34562
2010-07-15 02:39:18,907 - INFO [main:QuorumPeerConfig@90] - Reading configuration from: /etc/zookeeper/conf/zoo.cfg
{code}
This timestamp is the first ``Leader epoch`` line. Everything between these two points will be the interesting bits.
{code}
2010-07-15 02:39:43,339 - FATAL [QuorumPeer:/0:0:0:0:0:0:0:0:2181:Follower@71] - Leader epoch 23 is less than our epoch 24
{code}
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Patrick Hunt (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12891332#action_12891332 ]
Patrick Hunt commented on ZOOKEEPER-790:
----------------------------------------
I believe the problem found by Travis is a bug in the build for 3.3.1. If you d/l the latest release, patch it, and run "ant jar" this is included into the output:
version-info:
[java] All version-related parameters must be valid integers!
[java] Exception in thread "main" java.lang.NumberFormatException: For input string: "2-dev"
[java] at java.lang.NumberFormatException.forInputString(NumberFormatException.java:48)
[java] at java.lang.Integer.parseInt(Integer.java:458)
[java] at java.lang.Integer.parseInt(Integer.java:499)
[java] at org.apache.zookeeper.version.util.VerGen.main(VerGen.java:131)
[java] Java Result: 1
the build doesn't fail as the generated Version.java exists in the release, as a result you get the original Version.java, and therefore the old date.
You can see this better by doing a "ant clean jar", which will fail as the Version.java is cleaned by running ant clean. You can get around this
problem by running "ant -Dversion=3.3.2 clean jar" (a valid version string), after which you should see the current date in the log.
I'll fix this in the next rel.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Paiva Junqueira updated ZOOKEEPER-790:
---------------------------------------------
Attachment: ZOOKEEPER-790-3.3.patch
Uploading patch for the 3.3 branch. I have also checked the results of Hudson, and I couldn't find any java test failure. The -1 on core tests seems to be unrelated to this patch.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Hudson (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12891559#action_12891559 ]
Hudson commented on ZOOKEEPER-790:
----------------------------------
Integrated in ZooKeeper-trunk #884 (See [http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/884/])
ZOOKEEPER-790. Last processed zxid set prematurely while establishing leadership (fpj via breed)
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Patrick Hunt (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Patrick Hunt updated ZOOKEEPER-790:
-----------------------------------
Assignee: Flavio Paiva Junqueira
Fix Version/s: 3.4.0
Priority: Blocker (was: Major)
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Vishal K (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888122#action_12888122 ]
Vishal K commented on ZOOKEEPER-790:
------------------------------------
>From ZOOKEEPER-335..
Hi,
I enabled tracing and did some more debugging. Looks like the restarted peer (and trying to join the cluster) determines that it is a leader and increments its epoch. However, rest of the nodes don't acknowledge this node as the leader, and hence, have an older epoch. I will attache the log. Unfortunately, I don't have traces from other nodes. I will repeat the experiment later and attache logs from other nodes.
Scenario:
* Form a 3 node cluster. This is not just ZK cluster. It also involves our application cluster that uses ZK.
* Kill one of the follower
* After a minute or so restart follower
* Follower rejects leader with "Leader epoch y is less than our epoch y + 1"
>From logs:
a) Peer X restarts and starts leader election.
a) For a small window of time, X thinks that it is the new leader! During this window, for some reason, rest of the nodes tell X that they are also trying to find a leader. I.e., all 3 nodes are in LOOKING state. After seeing that all 3 nodes are in LOOKING state, X decides to be a leader?
155 2010-06-20 23:22:46,421 - DEBUG [WorkerSender Thread:QuorumCnxManager@346] - Opening channel to server 1
156 2010-06-20 23:22:46,423 - DEBUG [WorkerReceiver Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new notification message. My id = 0
157 2010-06-20 23:22:46,424 - INFO [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@689] - Notification: 0, 77309411393, 1, 0, LOOKING, LOOKING, 0
158 2010-06-20 23:22:46,424 - DEBUG [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@495] - id: 0, proposed id: 0, zxid: 77309411393, proposed zxid: 77309411393
159 2010-06-20 23:22:46,424 - DEBUG [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@717] - Adding vote: From = 0, Proposed leader = 0, Porposed zxid = 77309411393, Proposed epoch = 1
160 2010-06-20 23:22:46,426 - INFO [WorkerSender Thread:QuorumCnxManager@162] - Have smaller server identifier, so dropping the connection: (1, 0)
161 2010-06-20 23:22:46,426 - DEBUG [WorkerSender Thread:QuorumCnxManager@346] - Opening channel to server 2
162 2010-06-20 23:22:46,427 - DEBUG [Thread-1:QuorumCnxManager$Listener@445] - Connection request /192.168.1.182:46701
163 2010-06-20 23:22:46,427 - DEBUG [Thread-1:QuorumCnxManager$Listener@448] - Connection request: 0
164 2010-06-20 23:22:46,428 - DEBUG [Thread-1:QuorumCnxManager$SendWorker@504] - Address of remote peer: 1
165 2010-06-20 23:22:46,428 - INFO [WorkerSender Thread:QuorumCnxManager@162] - Have smaller server identifier, so dropping the connection: (2, 0)
166 2010-06-20 23:22:46,431 - DEBUG [WorkerReceiver Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new notification message. My id = 0
167 2010-06-20 23:22:46,432 - INFO [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@689] - Notification: 1, 77309411372, 1, 0, LOOKING, LOOKING, 1
168 2010-06-20 23:22:46,432 - DEBUG [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@495] - id: 1, proposed id: 0, zxid: 77309411372, proposed zxid: 77309411393
169 2010-06-20 23:22:46,432 - DEBUG [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@717] - Adding vote: From = 1, Proposed leader = 1, Porposed zxid = 77309411372, Proposed epoch = 1
170 2010-06-20 23:22:46,436 - DEBUG [Thread-1:QuorumCnxManager$Listener@445] - Connection request /192.168.1.183:44310
171 2010-06-20 23:22:46,436 - DEBUG [Thread-1:QuorumCnxManager$Listener@448] - Connection request: 0
172 2010-06-20 23:22:46,436 - DEBUG [Thread-1:QuorumCnxManager$SendWorker@504] - Address of remote peer: 2
173 2010-06-20 23:22:46,440 - DEBUG [WorkerReceiver Thread:FastLeaderElection$Messenger$WorkerReceiver@214] - Receive new notification message. My id = 0
174 2010-06-20 23:22:46,440 - INFO [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@689] - Notification: 2, 73014444097, 1, 0, LOOKING, LOOKING, 2
175 2010-06-20 23:22:46,440 - DEBUG [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@495] - id: 2, proposed id: 0, zxid: 73014444097, proposed zxid: 77309411393
176 2010-06-20 23:22:46,441 - DEBUG [QuorumPeer:/0.0.0.0:2181:FastLeaderElection@717] - Adding vote: From = 2, Proposed leader = 2, Porposed zxid = 73014444097, Proposed epoch = 1
177 2010-06-20 23:22:46,441 - INFO [QuorumPeer:/0.0.0.0:2181:QuorumPeer@647] - LEADING
b) As a result X increments its epoch. Worse, since this node decided to be a leader, it starts doing transactions. The first set of transactions start removing all ephemeral nodes. But these transactions are only done locally. Other peers do not ack these transactions since they know that this peer is not the leader.
c) After a few seconds (8 secs), X relinquishes leadership since it does not receive any ack from rest of the peers
d) It starts leader election again. This time, rests of the peers respond correctly informing X that a leader already exists.
e) X determines that it should now follow the leader and starts handshake with the leader. However, X has incremented its epoch in the mean time. X thinks that the epoch sent by the leader during handshake is older than the epoch it has noticed before. X aborts connection with the leader.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888834#action_12888834 ]
Flavio Paiva Junqueira commented on ZOOKEEPER-790:
--------------------------------------------------
Thank you both for all the information. I have been able to reproduce and find the source of the bug, but I don't have a patch yet. The problem is deeper than I thought originally. Let me show you what is going on:
I'm including an excerpt of logs from two runs: one good and one bad. The first run is good (see the excerpt below). I have killed the follower and restarted it as Vishal suggested. When it comes back, it declares itself as leader, also as Vishal and Travis observed. However, different from what Vishal and Travis observed, it drops leadership and follows happily the leader right after.
{noformat}
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:QuorumPeer@654] - LEADING
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), LEADING (n.state), 3 (n.sid), LOOKING (my state)
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), LEADING (n.state), 3 (n.sid), LEADING (my state)
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Leader@54] - TCP NoDelay set to: true
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:zookeeper.version=3.4.0--1, built on 07/15/2010 10:36 GMT
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:host.name=XXXXXXXXXX.com
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.version=1.6.0_04
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.vendor=Sun Microsystems Inc.
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.home=/usr/java/jdk1.6.0_04/jre
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.class.path=.XXXXXXXXX
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.library.path= XXXXXXXXX
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.io.tmpdir=/tmp
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.compiler=<NA>
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:os.name=Linux
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:os.arch=amd64
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:os.version=2.6.18-53.1.21.el5
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:user.name=XXXXXXXXX
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:user.home=XXXXXXXXX
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:user.dir=XXXXXXXXX
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:ZooKeeperServer@151] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /XXXXXXXXX/zookeeper/version-2 snapdir /XXXXXXXX/zookeeper/version-2
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FileSnap@82] - Reading snapshot /XXXXXXXX/zookeeper/version-2/snapshot.100113340
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FileSnap@82] - Reading snapshot /XXXXXXXX/zookeeper/version-2/snapshot.100113340
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FileTxnSnapLog@208] - Snapshotting: 10011f748
INFO - [SessionTracker:ZooKeeperServer@315] - Expiring session 0x229d6a9e0ca0000, timeout of 10000ms exceeded
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Leader@394] - Shutdown called
java.lang.Exception: shutdown Leader! reason: Waiting for a quorum of followers, only synced with: 2:
at org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:394)
at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:317)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:657)
INFO - [Thread-10:Leader$LearnerCnxAcceptor@243] - exception while shutting down acceptor: java.net.SocketException: Socket closed
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FinalRequestProcessor@378] - shutdown of request processor complete
INFO - [SyncThread:2:SyncRequestProcessor@151] - SyncRequestProcessor exited!
INFO - [CommitProcessor:2:CommitProcessor@148] - CommitProcessor exited loop!
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:QuorumPeer@620] - LOOKING
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FileSnap@82] - Reading snapshot /XXXXXXXXX/zookeeper/version-2/snapshot.10011f748
INFO - [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop!
INFO - [ProcessThread:-1:PrepRequestProcessor@385] - Processed session termination for sessionid: 0x229d6a9e0ca0000
ERROR - [ProcessThread:-1:NIOServerCnxn$Factory$1@87] - Thread Thread[ProcessThread:-1,5,main] died
java.lang.NullPointerException
at org.apache.zookeeper.server.quorum.ProposalRequestProcessor.processRequest(ProposalRequestProcessor.java:71)
at org.apache.zookeeper.server.PrepRequestProcessor.pRequest(PrepRequestProcessor.java:435)
at org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:114)
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FastLeaderElection@663] - New election. My id = 2, Proposed zxid = 4296144712
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 2 (n.leader), 4296144712 (n.zxid), 2 (n.round), LOOKING (n.state), 2 (n.sid), LOOKING (my state)
INFO - [WorkerSender Thread:QuorumCnxManager@162] - Have smaller server identifier, so dropping the connection: (3, 2)
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), LEADING (n.state), 3 (n.sid), LOOKING (my state)
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), FOLLOWING (n.state), 1 (n.sid), LOOKING (my state)
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), FOLLOWING (n.state), 1 (n.sid), LOOKING (my state)
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), FOLLOWING (n.state), 1 (n.sid), LOOKING (my state)
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), LEADING (n.state), 3 (n.sid), LOOKING (my state)
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), LEADING (n.state), 3 (n.sid), LOOKING (my state)
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:QuorumPeer@642] - FOLLOWING
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Learner@72] - TCP NoDelay set to: true
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:ZooKeeperServer@151] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /XXXXXXXXX/zookeeper/version-2 snapdir /XXXXXXXXX/zookeeper/version-2
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Learner@285] - Getting a snapshot from leader
FATAL - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Learner@314] - Setting leader epoch 1
WARN - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Follower@116] - Got zxid 0x100162711 expected 0x1
WARN - [SyncThread:2:FileTxnLog@196] - Creating new log file: 100162711
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FileTxnSnapLog@208] - Snapshotting: 100164c43
{noformat}
Now, the following run is bad. I followed the same procedure, but this time we get the epoch problem. Looking carefully at the logs, you'll see that the main difference is that this time the zookeeper server created a new log file: log.200000001. This is bad because the zookeeper server will use the zxid in the latest txn log file to determine its last epoch. Given that the current leader is in epoch 1, it will correctly refuse to talk to the leader as we observe below.
{noformat}
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:QuorumPeer@654] - LEADING
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Leader@54] - TCP NoDelay set to: true
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:zookeeper.version=3.4.0--1, built on 07/15/2010 10:36 GMT
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:host.name=XXXXXXXX.com
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.version=1.6.0_05
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.vendor=Sun Microsystems Inc.
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.home=/usr/java/jdk1.6.0_05/jre
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.class.path=XXXXXXXXX
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.library.path=XXXXXXXXX
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.io.tmpdir=/tmp
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:java.compiler=<NA>
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:os.name=Linux
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:os.arch= amd64
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:os.version=2.6.18-92.1.13.el5.perfctr.2.6.36
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:user.name=XXXXXXXXX
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:user.home=XXXXXXXX
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Environment@97] - Server environment:user.dir=XXXXXXXXX
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:ZooKeeperServer@151] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /xxxxxxx/zookeeper/version-2 snapdir /XXXXXXX/zookeeper/version-2
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FileSnap@82] - Reading snapshot /XXXXXXX/zookeeper/version-2/snapshot.1000469b4
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FileSnap@82] - Reading snapshot /XXXXXXX/zookeeper/version-2/snapshot.1000469b4
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FileTxnSnapLog@208] - Snapshotting: 100055cec
INFO - [SessionTracker:ZooKeeperServer@315] - Expiring session 0x129d6b61b5b0000, timeout of 10000ms exceeded
INFO - [ProcessThread:-1:PrepRequestProcessor@385] - Processed session termination for sessionid: 0x129d6b61b5b0000
WARN - [SyncThread:1:FileTxnLog@196] - Creating new log file: log.200000001
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Leader@394] - Shutdown called
java.lang.Exception: shutdown Leader! reason: Waiting for a quorum of followers, only synced with: 1:
at org.apache.zookeeper.server.quorum.Leader.shutdown(Leader.java:394)
at org.apache.zookeeper.server.quorum.Leader.lead(Leader.java:317)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:657)
INFO - [ProcessThread:-1:PrepRequestProcessor@119] - PrepRequestProcessor exited loop!
INFO - [CommitProcessor:1:CommitProcessor@148] - CommitProcessor exited loop!
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FinalRequestProcessor@378] - shutdown of request processor complete
INFO - [SyncThread:1:SyncRequestProcessor@151] - SyncRequestProcessor exited!
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:QuorumPeer@620] - LOOKING
INFO - [Thread-8:Leader$LearnerCnxAcceptor@243] - exception while shutting down acceptor: java.net.SocketException: Socket closed
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FileSnap@82] - Reading snapshot /XXXXXXXX/zookeeper/version-2/snapshot.100055cec
INFO - [SessionTracker:SessionTrackerImpl@158] - SessionTrackerImpl exited loop!
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:FastLeaderElection@663] - New election. My id = 1, Proposed zxid = 8589934593
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 1 (n.leader), 8589934593 (n.zxid), 2 (n.round), LOOKING (n.state), 1 (n.sid), LOOKING (my state)
INFO - [WorkerSender Thread:QuorumCnxManager@162] - Have smaller server identifier, so dropping the connection: (2, 1)
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), FOLLOWING (n.state), 2 (n.sid), LOOKING (my state)
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), LEADING (n.state), 3 (n.sid), LOOKING (my state)
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), FOLLOWING (n.state), 2 (n.sid), LOOKING (my state)
INFO - [WorkerReceiver Thread:FastLeaderElection@496] - Notification: 3 (n.leader), 0 (n.zxid), 1 (n.round), FOLLOWING (n.state), 2 (n.sid), LOOKING (my state)
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:QuorumPeer@642] - FOLLOWING
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Learner@72] - TCP NoDelay set to: true
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:ZooKeeperServer@151] - Created server with tickTime 3000 minSessionTimeout 6000 maxSessionTimeout 60000 datadir /xxxxxxx/zookeeper/version-2 snapdir /xxxxxxx/zookeeper/version-2
FATAL - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Follower@71] - Leader epoch 1 is less than our epoch 2
WARN - [QuorumPeer:/0:0:0:0:0:0:0:0:10218:Follower@82] - Exception when following the leader
java.io.IOException: Error: Epoch of leader is lower
at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:73)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:644)
INFO - [QuorumPeer:/0:0:0:0:0:0:0:0:10218: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:648)
{noformat}
Fixing it is not as simple as setting the current zxid to 200000001 after we hear from a quorum because the request processor pipeline starts complaining about an attempt to commit a future proposal.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12887969#action_12887969 ]
Flavio Paiva Junqueira commented on ZOOKEEPER-790:
--------------------------------------------------
Vishal, What exactly didn't work? Do you get the same error messages with the patch? Do you have a reliable way of reproducing it? In general, it would be useful if you could provide more detail.
Thanks!
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Mahadev konar (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Mahadev konar updated ZOOKEEPER-790:
------------------------------------
Status: Resolved (was: Patch Available)
Resolution: Fixed
I just committed this. thanks flavio and others!
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.v2.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Benjamin Reed (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Benjamin Reed updated ZOOKEEPER-790:
------------------------------------
Status: Resolved (was: Patch Available)
Resolution: Fixed
Committed revision 966960.
Committed revision 966984.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Reopened: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Flavio Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Junqueira reopened ZOOKEEPER-790:
----------------------------------------
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Junqueira updated ZOOKEEPER-790:
---------------------------------------
Attachment: ZOOKEEPER-790.v2.patch
Thanks for pointing this issue out, Sergei. It sounds like the previous patch solved the issue discussed without making sure that the leader was ready to process messages when learner handlers started to read them in. This v2 patch does a number of things:
# It moves the startup method to processAck. This way we make sure that start up the leader as soon as we have a quorum of acks for the newleader message;
# It moves the initialization of the database in startup to a method startdata. There are two reasons for doing it. First, it didn't sound like a good idea to throw exceptions or catch exceptions in processAck, and they were only necessary because of the call to startup(). Second, the method startup() in ZooKeeperServer throws these exceptions because of loadData(), which is called separately in Leader.lead(), so it is not necessary to call it in processAck after hearing from a quorum;
# It waits in LearnerHandler.run() until the leader ready before it starts the while(true) loop. I also had to receive an ack before executing the code to wait, otherwise the leader would never receive acks and form a quorum, thus causing the system to halt.
To get some feedback on the changes implemented in this patch, I have discussed them with Ben. Thanks, Ben!
Sergei, I would appreciate if you could give it a try, and if you could tell me if it works for you.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Vishal K (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12888843#action_12888843 ]
Vishal K commented on ZOOKEEPER-790:
------------------------------------
Likewise.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Junqueira updated ZOOKEEPER-790:
---------------------------------------
Attachment: ZOOKEEPER-790.v2.patch
Now uploading trunk version.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.v2.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Junqueira updated ZOOKEEPER-790:
---------------------------------------
Status: Open (was: Patch Available)
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.v2.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Patrick Hunt (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12892526#action_12892526 ]
Patrick Hunt commented on ZOOKEEPER-790:
----------------------------------------
Great catch Sergei, thanks!
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Flavio Paiva Junqueira updated ZOOKEEPER-790:
---------------------------------------------
Attachment: ZOOKEEPER-790.patch
I realized that while working on the patch I removed a private modifier and forgot to add it back for the trunk patch, so I'm uploading an new patch. There is no other significant modification to the patch.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Mahadev konar (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12893816#action_12893816 ]
Mahadev konar commented on ZOOKEEPER-790:
-----------------------------------------
+1 the patch looks good. I will go ahead and commit it.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.v2.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-790) Last processed zxid set prematurely
while establishing leadership
Posted by "Benjamin Reed (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Benjamin Reed updated ZOOKEEPER-790:
------------------------------------
+1 excellent work you guys. i also like QuorumUtil sergey! thanx for implementing it.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Sergey Doroshenko (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12892721#action_12892721 ]
Sergey Doroshenko commented on ZOOKEEPER-790:
---------------------------------------------
btw, Flavio, there are a few lines with trailing whitespaces in your patch, fix them
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Junqueira
> Assignee: Flavio Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-3.3.patch, ZOOKEEPER-790-follower-request-NPE.log, ZOOKEEPER-790-test.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.patch, ZOOKEEPER-790.travis.log.bz2, ZOOKEEPER-790.v2.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-790) Last processed zxid set
prematurely while establishing leadership
Posted by "Travis Crawford (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12885738#action_12885738 ]
Travis Crawford commented on ZOOKEEPER-790:
-------------------------------------------
@vishal - How did your test go? I came across this issue while investigating an issue and believe this is the root cause.
If your test went well I can also help test.
> Last processed zxid set prematurely while establishing leadership
> -----------------------------------------------------------------
>
> Key: ZOOKEEPER-790
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-790
> Project: Zookeeper
> Issue Type: Bug
> Components: quorum
> Affects Versions: 3.3.1
> Reporter: Flavio Paiva Junqueira
> Assignee: Flavio Paiva Junqueira
> Priority: Blocker
> Fix For: 3.3.2, 3.4.0
>
> Attachments: ZOOKEEPER-790.patch
>
>
> The leader code is setting the last processed zxid to the first of the new epoch even before connecting to a quorum of followers. Because the leader code sets this value before connecting to a quorum of followers (Leader.java:281) and the follower code throws an IOException (Follower.java:73) if the leader epoch is smaller, we have that when the false leader drops leadership and becomes a follower, it finds a smaller epoch and kills itself.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.