ZhenyuLi created ZOOKEEPER-5088:
-----------------------------------
Summary: ObserverMaster can omit INFORM packets for proposals
received during follower synchronization
Key: ZOOKEEPER-5088
URL: https://issues.apache.org/jira/browse/ZOOKEEPER-5088
Project: ZooKeeper
Issue Type: Bug
Components: quorum
Affects Versions: 3.8.6, 3.9.5
Reporter: ZhenyuLi
h2. Summary
An observer can receive an out-of-order zxid if the follower acting as its
ObserverMaster receives an uncommitted proposal while synchronizing with the
leader. The resulting gap kills the observer's CommitProcessor thread, leaving
the observer permanently unable to apply committed writes.
h2. Background
A follower configured with \{{observerMasterPort}} maintains two related queues:
* \{{FollowerZooKeeperServer.pendingTxns}} -- proposals received by the
follower but not yet committed.
* \{{ObserverMaster.proposedPkts}} -- proposals that must be forwarded to
observers after commit.
During normal broadcasting, each proposal is added to both queues:
{code}
PROPOSAL(Z)
-> fzk.logRequest(...)
-> pendingTxns adds Z
-> om.proposalReceived(...)
-> proposedPkts adds Z
COMMIT(Z)
-> fzk.commit(Z)
-> om.proposalCommitted(Z)
-> INFORM(Z) is sent to downstream observers
{code}
h2. Root cause
Follower synchronization uses a different path:
{code}
syncWithLeader()
-> new ObserverMaster(...)
-> om.start()
-> normal processPacket() loop
{code}
Proposals received *during* \{{syncWithLeader()}} are added directly to
{\{pendingTxns}}. They do not pass through
\{{Follower.processPacket(PROPOSAL)}},
and the ObserverMaster does not exist yet. This leaves the two queues
inconsistent:
{code}
pendingTxns = [Z3]
proposedPkts = []
{code}
When Z3 later commits, the follower finds it in \{{pendingTxns}} and applies it
successfully. However, \{{ObserverMaster.proposalCommitted(Z3)}} cannot find the
corresponding packet in \{{proposedPkts}}:
{\{ObserverMaster.removeProposedPacket(Z3)}} returns \{{null}}, so no INFORM(Z3)
is sent to the downstream observer.
The next proposal received after the ObserverMaster starts follows the normal
path. If that proposal is Z4, the observer receives Z4 directly after Z2.
h2. Impact
The zxid gap causes \{{ZKDatabase.addCommittedProposal()}} to throw:
{code}
IllegalStateException: Committed proposal cached out of order:
0x100000004 is not the next proposal of 0x100000002
{code}
The exception terminates the observer's CommitProcessor -- the critical
request-processing thread responsible for applying committed writes -- which
exits with error code 1. The affected observer can no longer process subsequent
committed requests and must be restarted to recover.
h2. Sequence
{noformat}
Leader Follower / ObserverMaster Observer
syncWithLeader()
PROPOSAL Z3
------------------------> pendingTxns adds Z3
ObserverMaster does not exist
synchronization completes
new ObserverMaster()
proposedPkts is empty
synchronized
through Z2
COMMIT Z3
------------------------> follower commits Z3
proposedPkts has no Z3
no INFORM is sent
PROPOSAL Z4
------------------------> pendingTxns adds Z4
proposedPkts adds Z4
COMMIT Z4
------------------------> follower commits Z4
INFORM Z4 --------------------------> receives Z4
after Z2
IllegalStateException
CommitProcessor exits
{noformat}
h2. Steps to reproduce
# Start three voting participants and one observer.
# Configure one follower with \{{observerMasterPort}}.
# Connect the observer through that follower's ObserverMaster.
# Commit a transaction so the observer's committed proposal cache ends at Z2.
# Stop and restart the follower acting as ObserverMaster.
# Pause the follower while it is synchronizing with the leader.
# Submit a create request assigned zxid Z3.
# Delay the ACKs for Z3 so it remains proposed but uncommitted.
# Allow the leader to forward Z3 to the synchronizing follower.
# Let follower synchronization complete and allow its ObserverMaster to start.
# Wait for the observer to reconnect through the restarted ObserverMaster.
# Release the delayed ACKs so Z3 commits.
# Submit and commit another create request assigned zxid Z4.
h2. Expected result
The observer receives INFORM(Z3) followed by INFORM(Z4) and applies both
transactions in zxid order.
h2. Actual result
The follower applies both Z3 and Z4. The observer misses INFORM(Z3), receives
INFORM(Z4) after Z2, throws IllegalStateException, and its CommitProcessor
exits with error code 1.
h2. Possible fix directions
For discussion, not yet verified:
* Seed \{{ObserverMaster.proposedPkts}} from the follower's \{{pendingTxns}} at
ObserverMaster construction/start time, so the two queues are consistent before
the normal broadcast loop begins.
* Alternatively, route proposals received during \{{syncWithLeader()}} through
the same bookkeeping as \{{Follower.processPacket(PROPOSAL)}}, or buffer them
until the ObserverMaster exists.
* Consider whether \{{removeProposedPacket()}} returning \{{null}} should be
logged as a warning rather than silently skipping the INFORM, to make this
class of inconsistency observable.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
