ZOOKEEPER-4925: Fix data loss due to propagation of discontinuous committedLog #2254

kezhuw · 2025-05-04T12:27:39Z

There are two variants of ZooKeeperServer::processTxn. Those two variants diverge significantly since ZOOKEEPER-3484. processTxn(Request request) pops outstanding change from outstandingChanges and adds txn to committedLog for follower to sync in addition to what processTxn(TxnHeader hdr, Record txn) does. The Learner uses processTxn(TxnHeader hdr, Record txn) to commit txn to memory after ZOOKEEPER-4394, which means it leaves committedLog untouched in SYNCHRONIZATION phase.

This way, a stale follower will have hole in its committedLog after joining cluster. The stale follower will propagate the in memory hole to other stale nodes after becoming leader. This causes data loss.

The test case fails on master and 3.9.3, and passes on 3.9.2. So only 3.9.3 is affected.

This commit drops processTxn(TxnHeader hdr, Record txn) as processTxn(Request request) is capable in SYNCHRONIZATION phase too.

Also, this commit rejects discontinuous proposals in syncWithLeader and committedLog, so to avoid possible data loss.

Refs: ZOOKEEPER-4925, ZOOKEEPER-4394, ZOOKEEPER-3484

…mittedLog There are two variants of `ZooKeeperServer::processTxn`. Those two variants diverge significantly since ZOOKEEPER-3484. `processTxn(Request request)` pops outstanding change from `outstandingChanges` and adds txn to `committedLog` for follower to sync in addition to what `processTxn(TxnHeader hdr, Record txn)` does. The `Learner` uses `processTxn(TxnHeader hdr, Record txn)` to commit txn to memory after ZOOKEEPER-4394, which means it leaves `committedLog` untouched in `SYNCHRONIZATION` phase. This way, a stale follower will have hole in its `committedLog` after joining cluster. The stale follower will propagate the in memory hole to other stale nodes after becoming leader. This causes data loss. The test case fails on master and 3.9.3, and passes on 3.9.2. So only 3.9.3 is affected. This commit drops `processTxn(TxnHeader hdr, Record txn)` as `processTxn(Request request)` is capable in `SYNCHRONIZATION` phase too. Also, this commit rejects discontinuous proposals in `syncWithLeader` and `committedLog`, so to avoid possible data loss. Refs: ZOOKEEPER-4925, ZOOKEEPER-4394, ZOOKEEPER-3484

li4wang · 2025-06-02T18:55:15Z

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

+                assertNotNull(zk.exists(path, false), path + " not found");
+            }
+
+            for (int i = 0; i < 10; i++) {


How about adding the JIRA ticket to help people understand the issue and fix? Basically all the /boo related txns are synced via DIFF and added to the committed logs with the fix.

ZOOKEEPER-4925 ?

li4wang · 2025-06-02T19:09:26Z

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

-                            fzk.appendRequest(pif.hdr, pif.rec, pif.digest);
-                            fzk.processTxn(pif.hdr, pif.rec);
+                            fzk.appendRequest(pif.toRequest());
+                            fzk.processTxn(pif.toRequest());


nitpick

How about create the request object and reuse it instead of converting twice?

Request request = pif.toRequest() fzk.appendRequest(request) fzk.processTxn（request)

li4wang · 2025-06-02T19:22:55Z

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

+                            // log at warn should not be too verbose.
+                            LOG.warn("DIFF sync got new epoch proposal 0x{}, last proposal 0x{}",
+                                    Long.toHexString(packet.hdr.getZxid()),
+                                    Long.toHexString(lastQueued));


This is the same code as line 637-651. How about creating a common method to check if proposal is out of order so it can be used in both places?

Move them to enforceContinuousProposal.

li4wang · 2025-06-02T19:34:38Z

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

+                        }
+                        // We can't tell whether it is a data loss. Given that new epoch is rare,
+                        // log at warn should not be too verbose.
+                        LOG.warn("DIFF sync got new epoch proposal 0x{}, last proposal 0x{}",


How about keeping the original WARN statement, so it's very clear what is the actual and what is the expected?

Add expected zxid in newly introduced method enforceContinuousProposal.

li4wang · 2025-06-02T19:59:12Z

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

+                    ZxidUtils.zxidToString(request.zxid),
+                    ZxidUtils.zxidToString(maxCommittedLog));
+                LOG.error(msg);
+                throw new IllegalStateException(msg);


Do we have a test case for it?

I think it is already covered by existing tests. allowDiscontinuousProposals(used by ZxidRolloverTest, TxnLogDigestTest, both introduce discontinuous proposals on purpose) was introduced to bypass this restriction.

Also this path will fail newly introduced test if we rollback changes involed in sync phase.

git checkout HEAD^ -- zookeeper-server/src/main/java/org/apache/zookeeper/server/quorum/ git checkout HEAD^ -- zookeeper-server/src/main/java/org/apache/zookeeper/server/ZooKeeperServer.java

So, I think it is covered, though not for successful tests.

Besides, this is what I state in commit message.

Also, this commit rejects discontinuous proposals in syncWithLeader and committedLog, so to avoid possible data loss.

li4wang · 2025-06-02T20:00:26Z

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

            if (committedLog.isEmpty()) {
                minCommittedLog = request.zxid;
                maxCommittedLog = request.zxid;
+            } else if (request.zxid <= maxCommittedLog) {
+                // This could happen if lastProcessedZxid is rewinded and database is re-synced.
+                // Currently, it only happens in test codes, but it should also be safe for production path.


How about adding a test case for the scenario?

LoadFromLogTest::testRestore fails without this. Here is the javadoc of the test.

/** * Test we can restore the snapshot that has data ahead of the zxid * of the snapshot file. */

zookeeper/zookeeper-server/src/test/java/org/apache/zookeeper/test/LoadFromLogTest.java

Lines 178 to 182 in aeadf57

ZooKeeperServer zks = serverFactory.getZooKeeperServer();

long eZxid = zks.getZKDatabase().getDataTreeLastProcessedZxid();

// force the zxid to be behind the content

zks.getZKDatabase().setlastProcessedZxid(zks.getZKDatabase().getDataTreeLastProcessedZxid() - 10);

LOG.info("Set lastProcessedZxid to {}", zks.getZKDatabase().getDataTreeLastProcessedZxid());

li4wang · 2025-06-02T20:27:51Z

The changes for fixing the data loss issue looks good. It's a very critical issue. Thanks for fixing it.

The changes for blocking proposal and commit requests being out of order looks good in general. We need to make sure it doesn't introduce any unexpected issue.

kezhuw · 2025-06-03T04:35:22Z

Hi @li4wang, thank for for reviewing this! I have pushed a new commit. Please take another to look and let me know whether it solves your concerns.

kezhuw requested review from cnauroth, anmolnar, eolivelli, tisonkun and li4wang May 6, 2025 16:35

li4wang reviewed Jun 2, 2025

View reviewed changes

Add separated code to enforce continuous proposals

8c2f5db

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

ZOOKEEPER-4925: Fix data loss due to propagation of discontinuous committedLog #2254

ZOOKEEPER-4925: Fix data loss due to propagation of discontinuous committedLog #2254

kezhuw commented May 4, 2025

Uh oh!

li4wang Jun 2, 2025

Uh oh!

kezhuw Jun 3, 2025

Uh oh!

li4wang Jun 2, 2025 •

edited

Loading

Uh oh!

kezhuw Jun 3, 2025

Uh oh!

li4wang Jun 2, 2025

Uh oh!

kezhuw Jun 3, 2025

Uh oh!

li4wang Jun 2, 2025 •

edited

Loading

Uh oh!

kezhuw Jun 3, 2025

Uh oh!

li4wang Jun 2, 2025

Uh oh!

kezhuw Jun 3, 2025

Uh oh!

li4wang Jun 2, 2025 •

edited

Loading

Uh oh!

kezhuw Jun 3, 2025

Uh oh!

li4wang commented Jun 2, 2025 •

edited

Loading

Uh oh!

kezhuw commented Jun 3, 2025

Uh oh!

Uh oh!

	ZooKeeperServer zks = serverFactory.getZooKeeperServer();
	long eZxid = zks.getZKDatabase().getDataTreeLastProcessedZxid();
	// force the zxid to be behind the content
	zks.getZKDatabase().setlastProcessedZxid(zks.getZKDatabase().getDataTreeLastProcessedZxid() - 10);
	LOG.info("Set lastProcessedZxid to {}", zks.getZKDatabase().getDataTreeLastProcessedZxid());

ZOOKEEPER-4925: Fix data loss due to propagation of discontinuous committedLog #2254

Are you sure you want to change the base?

ZOOKEEPER-4925: Fix data loss due to propagation of discontinuous committedLog #2254

Conversation

kezhuw commented May 4, 2025

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

li4wang Jun 2, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

li4wang Jun 2, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

li4wang Jun 2, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

li4wang commented Jun 2, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

kezhuw commented Jun 3, 2025

Uh oh!

Uh oh!

li4wang Jun 2, 2025 •

edited

Loading

li4wang Jun 2, 2025 •

edited

Loading

li4wang Jun 2, 2025 •

edited

Loading

li4wang commented Jun 2, 2025 •

edited

Loading