ZOOKEEPER-3911: Data inconsistency caused by DIFF sync uncommitted log #1445

hanm · 2020-09-02T22:45:25Z

Problem:

During DIFF sync, followers will persist the proposals from leader only after receiving the UPTODATE message. Leader will start serve client requests once receive a quorum of NEWLEADER ACK from followers, and NEWLEADER ACKs are sent from followers before receiving UPTODATE. So it's possible that when leader starting serving, followers might not persistent all of the DIFF sync proposals from leader. If at a certain point in time (e.g. once receiving UPTODATE from leader) all quorum servers crash, then these proposals, where leader they are quorum committed, will lost if the old leader can't come back and the followers form a new quorum. The end result is inconsistent view of the data from client before / after quorum recovers.

Solution:

Make sure follower to persist all DIFF proposals before they ACK NEWLEADER. When leader receives a quorum of NEWLEADER ACK, it's guaranteed that all DIFF sync proposals are quorum persistent and can survive after the recovery.

eolivelli

thank you work creating this reproducer.

I see there are a lot of "Thread.sleep", this could lead to flakes, btw I can't suggest a better way.

@lvfangmin PTAL

zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java

hanm · 2020-09-03T17:01:13Z

I see there are a lot of "Thread.sleep", this could lead to flakes

I think it's fine here as the execution does not depends on timing of the sleep. The functionality these code block is basically the same with the waitForAll/One helpers.

hanm · 2020-09-03T17:07:49Z

One more observation - I think we have the same issue even before ZOOKEEPER-2678 (where it avoids taking snapshot before sending NEWLEADER ACK back during DIFF sync), because even when the snapshot was taken, the data tree at that time still does not have the proposals DIFF sync from leader applied (the commit of all such proposals happen after follower receive UPTODATE).

Specifically, in zab paper, it said:
"Phase 2: Sync with followers:
f The follower syncs with the leader, but doesn't modify its state until it receives the NEWLEADER(e) packet. Once it receives NEWLEADER(e) it atomically applies the new state and sets f.currentEpoch = e. It then sends ACK(e << 32)."
But in our implementation, I don't see we actually "atomically applies the new state" before sends ACK.

@breed might have more context around this.

hanm · 2020-09-03T21:43:46Z

jenkins pre-merge reports one failed test: FileTxnSnapLogMetricsTest#testFileTxnSnapLogMetrics
however, i can't reproduce it locally.

zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/Learner.java

zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServer.java

hanm · 2020-09-13T20:41:08Z

retest maven build

hanm · 2020-09-20T05:27:26Z

requesting more reviews; @lvfangmin @breed

hanm · 2020-10-27T04:06:53Z

Committers - can i get more reviews of this? I'd like to get this merged if no other issues. I hope the test case itself is straightforward to illustrate the problem and the fix itself is fairly simple (test case pass with the fix and fail w/o the fix). More discussions can be found at the ticket https://issues.apache.org/jira/browse/ZOOKEEPER-3911.

cc @eolivelli @symat @anmolnar @nkalmar @arshadmohammad

eolivelli · 2020-10-27T14:22:28Z

zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/Learner.java

-        sock.setSoTimeout(self.tickTime * self.syncLimit);
-        self.setSyncMode(QuorumPeer.SyncMode.NONE);
-        zk.startup();
+        zk.startServing();


One question:

this "startServing" works if you executed 'zk.startupWithoutServing();' in your new code.
but in other code paths we are not calling "startupWithoutServing"
so when we come to this point zk.startServing() will only change the state to RUNNING, and we had not called 'startupWithServerState'

can you please explain ?

but in other code paths we are not calling "startupWithoutServing"

The invariant here is that a call to zk.startServing will always follow a call to zk.startupWithoutServing. This is because the ZAB protocol implementation requires this order of invocation (in syncWithLeader). In other words, there is no other code paths that involve both calls. To finish the sync, the leader and follower must follow these events in order.

First, learner will receive NEWLEADER from leader. This is where we will call zk.startupWithoutServing.

Then, learner will receive UPTODATE from leader. This is where we breaks the outer sync loop, afterwards we call zk.startServing.

Hope this make sense. A more detailed description can be found on phase 2 "Sync with followers" on https://cwiki.apache.org/confluence/display/ZOOKEEPER/Zab1.0.

In other code path the server state is already in running, so this has no effect.

Now thinking about this... it's a bit surprising we never needed this control before, to have a running server "active" or not.

nkalmar

LGTM, PTAL

nkalmar · 2020-11-09T15:31:11Z

Since this has 2 committer's +1 I'm keen on merging this. I'd say to master, 3.6 and even 3.5, hopefully cherry picks clean.
I will wait another day if any reactions comes, and then I'll merge (or ofc others can merge before that).

Problem: During DIFF sync, followers will persist the proposals from leader only after receiving the UPTODATE message. Leader will start serve client requests once receive a quorum of NEWLEADER ACK from followers, and NEWLEADER ACKs are sent from followers before receiving UPTODATE. So it's possible that when leader starting serving, followers might not persistent all of the DIFF sync proposals from leader. If at a certain point in time (e.g. once receiving UPTODATE from leader) all quorum servers crash, then these proposals, where leader they are quorum committed, will lost if the old leader can't come back and the followers form a new quorum. The end result is inconsistent view of the data from client before / after quorum recovers. Solution: Make sure follower to persist all DIFF proposals before they ACK NEWLEADER. When leader receives a quorum of NEWLEADER ACK, it's guaranteed that all DIFF sync proposals are quorum persistent and can survive after the recovery. Author: Michael Han <hanm@apache.org> Reviewers: Enrico Olivelli <eolivelli@apache.org>, Norbert Kalmar <nkalmar@apache.org> Closes #1445 from hanm/ZOOKEEPER-3911 (cherry picked from commit b978dfb) Signed-off-by: Norbert Kalmar <nkalmar@apache.org>

nkalmar · 2020-11-12T15:09:35Z

Merged to master, branch-3.6 and branch-3.5. Thanks @hanm
3.5 did not pick clean, I fixed up manually, I will do some testing.

hanm · 2020-11-14T02:44:38Z

Thanks @nkalmar for taking care of merging this. I'll check out what's the problem with the patch on branch-3.5.

ztzg · 2020-11-14T21:13:21Z

I'm a bit late in reviewing this, but FWIW: LGTM.

I started looking into the issue with 3.5, but haven't had a chance to figure out the inconsistency. In case it helps, here is my current tree:

https://github.com/ztzg/zookeeper/tree/ZOOKEEPER-3911-diff-sync-3.5

li4wang · 2020-11-19T23:31:25Z

@hanm @nkalmar I am getting the following compilation error in branch-3.6. The error started to occur after this commit. I wonder if you ran into the same issue. Can you please take a look at it?

====================
[INFO] Finished at: 2020-11-19T15:07:24-08:00
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal org.apache.maven.plugins:maven-compiler-plugin:3.8.1:testCompile (default-testCompile) on project zookeeper: Compilation failure: Compilation failure:
[ERROR] /Users/liwang/apache/zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java:[22,36] package org.junit.jupiter.api does not exist
[ERROR] /Users/liwang/apache/zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java:[22,1] static import only from classes and interfaces
[ERROR] /Users/liwang/apache/zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java:[23,36] package org.junit.jupiter.api does not exist
[ERROR] /Users/liwang/apache/zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java:[23,1] static import only from classes and interfaces
[ERROR] /Users/liwang/apache/zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java:[24,36] package org.junit.jupiter.api does not exist
[ERROR] /Users/liwang/apache/zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java:[24,1] static import only from classes and interfaces
[ERROR] /Users/liwang/apache/zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java:[25,36] package org.junit.jupiter.api does not exist
[ERROR] /Users/liwang/apache/zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java:[25,1] static import only from classes and interfaces
[ERROR] /Users/liwang/apache/zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java:[42,29] package org.junit.jupiter.api does not exist
[ERROR] /Users/liwang/apache/zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java:[43,29] package org.junit.jupiter.api does not exist
[ERROR] /Users/liwang/apache/zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java:[44,29] package org.junit.jupiter.api does not exist
[ERROR] /Users/liwang/apache/zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java:[51,6] cannot find symbol
[ERROR] symbol: class Test

hanm · 2020-11-20T05:54:31Z

@li4wang thanks for reporting. I think this is because 3.6 had a different junit verison / api usage across unit tests and we didn't backup that commit to 3.6 when upgrades the tests. It should be easier to fix.

Part of the reason this was not caught during commit was because this was a cherry pick so it didn't go through the CI pipeline - also I suspect we lose our apache builds for 3.6 branches (at least my inbox was empty - otherwise the build fail notification would raise an alarm).

huizhilu · 2020-11-20T06:55:14Z

@hanm @li4wang I also noticed this build failure. Are you guys fixing it? If not, I think I could submit a PR for a quick fix by back porting the junit upgrade from the master branch to branch-3.6.

li4wang · 2020-11-20T18:30:58Z

@pkuwm yes, I am fixing it. I am planning to back porting the following commits from master branch to branch-3.6 via cherry-picking.

8da9c72 ZOOKEEPER-3850: Update jUnit to 5.6 in pom.xml files

tamaashu · 2020-11-20T20:39:17Z

@li4wang ZOOKEEPER-3850 won't solve the issue, since it only replaces jUnit4 with jUnit5-vintage (which is just a jUnit 4.13 with a rename). I would advise to fix the testcases in branch 3.6 with the use of jUnit4.
ZooKeeper 3.7 is coming with fully supported jUnit5 testing, there won't be too many backports to 3.6 afterwards.

li4wang · 2020-11-20T20:52:45Z

@tamaashu yeah, I noticed ZOOKEEPER-3850 by itself is not sufficient. I fixed the compilation errors by applying ZOOKEEPER-3850 and some addition changes on pom.xml, but the test case failed too.

@hanm can you please fix the test failure along with the compilation error? I do agree with @tamaashu, it would be better just fix the testcases in branch 3.6 by not using JUnit5 API.

test case error

[INFO] Running org.apache.zookeeper.server.quorum.DIFFSyncConsistencyTest
[ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 30.442 s <<< FAILURE! - in org.apache.zookeeper.server.quorum.DIFFSyncConsistencyTest
[ERROR] testInconsistentDueToUncommittedLog Time elapsed: 30.326 s <<< FAILURE!
org.opentest4j.AssertionFailedError: waiting for server 0 being up ==> expected: but was:
at org.apache.zookeeper.server.quorum.DIFFSyncConsistencyTest.testInconsistentDueToUncommittedLog(DIFFSyncConsistencyTest.java:78)

huizhilu · 2020-11-20T22:03:48Z

@hanm @li4wang @tamaashu Yep, I also tried but since there were commits during those jUnit 5 upgrade, there are conflicts if we cherry-pick those upgrade commits. It's easier to fix it directly if we don't have more backports to branch 3.6.
I have the working code locally. @hanm if you don't have time to fix this minor issue, I could submit a PR :)
A ticket is created here: https://issues.apache.org/jira/browse/ZOOKEEPER-4011

…sistencyTest ### Description Resolves [ZOOKEEPER-4011](https://issues.apache.org/jira/browse/ZOOKEEPER-4011) maven build fails on branch-3.6 because a back ported commit from the branch master uses jUnit 5. ### Solution As discussed in #1445, since cherry-picking jUnit 5 upgrades has conflicts, and there won't be too many back ports to 3.6 afterwards, we can just fix the issue by using jUnit 4 in the test. Author: Huizhi Lu <hulu@linkedin.com> Reviewers: hanm, tamaashu, maoling Closes #1545 from pkuwm/fix-build-branch-3.6

fanyang89 · 2021-03-26T11:55:46Z

I started looking into the issue with 3.5, but haven't had a chance to figure out the inconsistency. In case it helps, here is my current tree:

@ztzg ZOOKEEPER-3911 requires ZOOKEEPER-3240 to pass the unit test. I've created a new PR to backport ZOOKEEPER-3911 to branch-3.5.9.

#1655

anmolnar · 2021-03-27T20:15:03Z

@fanyang89 Thanks for taking care of this. Please open PR against branch-3.5.

ztzg · 2021-04-21T08:40:33Z

Hi @fanyang89,

I started looking into the issue with 3.5, but haven't had a chance to figure out the inconsistency. In case it helps, here is my current tree:

@ztzg ZOOKEEPER-3911 requires ZOOKEEPER-3240 to pass the unit test.

Sorry for the lag, and thank you very much for investigating/clarifying this!

I've created a new PR to backport ZOOKEEPER-3911 to branch-3.5.9.

#1655

Thank you—but as pointed out by @anmolnar in #1655 (comment), branch-3.5.9 is a "release branch," and 3.5.9 has already been released. Could you please submit the same PR against branch-3.5 (the "series" branch)?

(I will hopefully have a bit more time to look into these topics in the coming weeks.)

fanyang89 · 2021-04-21T08:50:19Z

Hi @ztzg, I've created a new PR against branch-3.5 #1657, but I forget to update the link at this thread. Sorry for that.

ztzg · 2021-04-21T17:22:28Z

Hi @ztzg, I've created a new PR against branch-3.5 #1657, but I forget to update the link at this thread. Sorry for that.

No problem. Now merged in branch branch-3.5. Thank you!

Problem: During DIFF sync, followers will persist the proposals from leader only after receiving the UPTODATE message. Leader will start serve client requests once receive a quorum of NEWLEADER ACK from followers, and NEWLEADER ACKs are sent from followers before receiving UPTODATE. So it's possible that when leader starting serving, followers might not persistent all of the DIFF sync proposals from leader. If at a certain point in time (e.g. once receiving UPTODATE from leader) all quorum servers crash, then these proposals, where leader they are quorum committed, will lost if the old leader can't come back and the followers form a new quorum. The end result is inconsistent view of the data from client before / after quorum recovers. Solution: Make sure follower to persist all DIFF proposals before they ACK NEWLEADER. When leader receives a quorum of NEWLEADER ACK, it's guaranteed that all DIFF sync proposals are quorum persistent and can survive after the recovery. Author: Michael Han <hanm@apache.org> Reviewers: Enrico Olivelli <eolivelli@apache.org>, Norbert Kalmar <nkalmar@apache.org> Closes apache#1445 from hanm/ZOOKEEPER-3911

eolivelli reviewed Sep 3, 2020

View reviewed changes

zookeeper-server/src/test/java/org/apache/zookeeper/server/quorum/DIFFSyncConsistencyTest.java Outdated Show resolved Hide resolved

fregatte123 reviewed Sep 4, 2020

View reviewed changes

zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/Learner.java Outdated Show resolved Hide resolved

fregatte123 reviewed Sep 4, 2020

View reviewed changes

zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServer.java Show resolved Hide resolved

hanm closed this Sep 13, 2020

hanm reopened this Sep 13, 2020

hanm closed this Sep 15, 2020

hanm reopened this Sep 15, 2020

ZOOKEEPER-3911: Data inconsistency caused by DIFF sync uncommitted log.

6c8fd1e

hanm force-pushed the ZOOKEEPER-3911 branch from 789cb10 to 6c8fd1e Compare October 27, 2020 01:51

eolivelli reviewed Oct 27, 2020

View reviewed changes

nkalmar approved these changes Oct 30, 2020

View reviewed changes

eolivelli approved these changes Nov 2, 2020

View reviewed changes

asfgit closed this in b978dfb Nov 12, 2020

huizhilu mentioned this pull request Nov 21, 2020

ZOOKEEPER-4011: Fix build failure due to jUnit 5 usage in DIFFSyncConsistencyTest #1545

Closed

kezhuw mentioned this pull request Apr 5, 2022

ZOOKEEPER-3023: Sync and commit diff log entries before NEWLEADER ack #1848

Closed

kezhuw mentioned this pull request May 4, 2023

ZOOKEEPER-4541 Ephemeral znode owned by closed session visible in 1 of 3 servers #1925

Closed

kezhuw mentioned this pull request Aug 26, 2024

ZOOKEEPER-4394: Apply only committed requests in sync with leader before NEWLEADER ACK #2152

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

ZOOKEEPER-3911: Data inconsistency caused by DIFF sync uncommitted log #1445

ZOOKEEPER-3911: Data inconsistency caused by DIFF sync uncommitted log #1445

hanm commented Sep 2, 2020 •

edited

Loading

eolivelli left a comment

hanm commented Sep 3, 2020

hanm commented Sep 3, 2020

hanm commented Sep 3, 2020

hanm commented Sep 13, 2020

hanm commented Sep 20, 2020

hanm commented Oct 27, 2020

eolivelli Oct 27, 2020

hanm Oct 27, 2020

nkalmar Oct 30, 2020

nkalmar Oct 30, 2020

nkalmar left a comment

nkalmar commented Nov 9, 2020

nkalmar commented Nov 12, 2020

hanm commented Nov 14, 2020

ztzg commented Nov 14, 2020

li4wang commented Nov 19, 2020

hanm commented Nov 20, 2020

huizhilu commented Nov 20, 2020

li4wang commented Nov 20, 2020 •

edited

Loading

tamaashu commented Nov 20, 2020

li4wang commented Nov 20, 2020 •

edited

Loading

huizhilu commented Nov 20, 2020 •

edited

Loading

fanyang89 commented Mar 26, 2021

anmolnar commented Mar 27, 2021

ztzg commented Apr 21, 2021

fanyang89 commented Apr 21, 2021

ztzg commented Apr 21, 2021

ZOOKEEPER-3911: Data inconsistency caused by DIFF sync uncommitted log #1445

ZOOKEEPER-3911: Data inconsistency caused by DIFF sync uncommitted log #1445

Conversation

hanm commented Sep 2, 2020 • edited Loading

eolivelli left a comment

Choose a reason for hiding this comment

hanm commented Sep 3, 2020

hanm commented Sep 3, 2020

hanm commented Sep 3, 2020

hanm commented Sep 13, 2020

hanm commented Sep 20, 2020

hanm commented Oct 27, 2020

eolivelli Oct 27, 2020

Choose a reason for hiding this comment

hanm Oct 27, 2020

Choose a reason for hiding this comment

nkalmar Oct 30, 2020

Choose a reason for hiding this comment

nkalmar Oct 30, 2020

Choose a reason for hiding this comment

nkalmar left a comment

Choose a reason for hiding this comment

nkalmar commented Nov 9, 2020

nkalmar commented Nov 12, 2020

hanm commented Nov 14, 2020

ztzg commented Nov 14, 2020

li4wang commented Nov 19, 2020

hanm commented Nov 20, 2020

huizhilu commented Nov 20, 2020

li4wang commented Nov 20, 2020 • edited Loading

tamaashu commented Nov 20, 2020

li4wang commented Nov 20, 2020 • edited Loading

test case error

huizhilu commented Nov 20, 2020 • edited Loading

fanyang89 commented Mar 26, 2021

anmolnar commented Mar 27, 2021

ztzg commented Apr 21, 2021

fanyang89 commented Apr 21, 2021

ztzg commented Apr 21, 2021

hanm commented Sep 2, 2020 •

edited

Loading

li4wang commented Nov 20, 2020 •

edited

Loading

li4wang commented Nov 20, 2020 •

edited

Loading

huizhilu commented Nov 20, 2020 •

edited

Loading