Silent message loss / permanently stuck backlog when producing into an empty head ledger that was fenced+CLOSED by BookKeeper auto-recovery

[Shawyeok]

Search before asking

• I searched in the issues and found nothing similar.

Read release policy

• I understand that unsupported versions don't get bug fixes. I will attempt to reproduce the issue on a supported version of Pulsar if I can.

Version

• Image: apachepulsar/pulsar:4.0.10
• Deployment: 1 ZooKeeper + 1 broker + 3 bookies (Docker, static IPs)
• Related BookKeeper issue: addEntry succeeds on replacement bookies after ensemble recovery, but entry is silently dropped — lh.close() fails with BKMetadataVersionException bookkeeper#4812

Minimal reproduce step

A managed ledger can end up with its empty open head ledger fenced and CLOSED in metadata (length=0, lastEntryId=-1) by BookKeeper auto-recovery — while the broker still holds that same ledger OPEN in memory. This happens when the bookies in the ledger's ensemble are decommissioned and replaced by fresh processes at the same ip:port (the BK-4812 scenario: the fresh bookies have no in-memory fence state).

Normally Pulsar's time-based rollover would heal such a split-brain at managedLedgerMaxLedgerRolloverTimeMinutes. But the background rollover task explicitly skips empty ledgers:

// ManagedLedgerImpl.rollCurrentLedgerIfFull()
if (currentLedgerEntries > 0 && currentLedgerIsFull()
        && STATE_UPDATER.compareAndSet(this, State.LedgerOpened, State.ClosingLedger)) {

So an empty fenced ledger is never auto-rolled and remains a zombie indefinitely. When the first message is finally produced, OpAddEntry writes it into the fenced/CLOSED ledger (the fresh bookies accept the addEntry because they have no fence state), assigns it an entry id (<ledger>:0), and only then rolls over and trims the "empty" ledger. The entry id is past the lastEntryId=-1 recorded in metadata, so it is an orphan and is lost on the next recovery.

Reproduction script

A complete, self-contained script (sets up the whole cluster and runs the scenario) is available here: https://gist.github.com/Shawyeok/e952760e40504f3e59b7e54319487759

curl -sL https://gist.githubusercontent.com/Shawyeok/e952760e40504f3e59b7e54319487759/raw/repro_empty_ledger_loss.sh -o repro_empty_ledger_loss.sh
chmod +x repro_empty_ledger_loss.sh
./repro_empty_ledger_loss.sh

It performs:

1. Start ZK + broker + 3 fresh bookies. Broker config (all via PULSAR_PREFIX_):
   managedLedgerDefaultEnsembleSize=2, WriteQuorum=2, AckQuorum=2,
   managedLedgerMaxLedgerRolloverTimeMinutes=15 (min left at default 10).
2. Subscribe a consumer to a fresh topic — this creates the topic and an empty head ledger. No message is produced.
3. Disconnect the consumer.
4. Decommission both bookies in the empty ledger's ensemble and restart a fresh bookie at each same ip:port (bin/bookkeeper shell decommissionbookie). Auto-recovery fences + closes the empty ledger in metadata.
5. Wait >= managedLedgerMaxLedgerRolloverTimeMinutes. The empty ledger is not rolled.
6. Produce the first message (msg1), consumer still offline.
7. Reconnect the consumer.

Note: the bug does not depend on the exact rollover value. Set ROLL_MIN=2 (and the broker env) for a faster run.

Expected behavior

After producing msg1, the reconnected consumer should receive it (or, if the broker truly could not persist it, the produce should fail rather than ack the producer).

Actual behavior

The producer is told the message was successfully produced, but:

After step 6 (produce), consumer offline:

broker after produce:  state LedgerOpened lastConfirmedEntry 9:0 numberOfEntries 1 ledgers [10]
  msgBacklog 1
ZK durable head ledger 9:  state=CLOSED, length=0, lastEntryId=-1   <-- metadata says ledger 9 is EMPTY

After step 7 (reconnect consumer):

consumer received: []        <-- nothing delivered
  msgBacklog 1               <-- backlog is permanently STUCK at 1

The broker reports 1 message in the backlog (LAC 9:0) but cannot deliver it: reading entry 9:0 is impossible because metadata says ledger 9 holds no entries. The subscription is stuck — the consumer can never receive the message.

After any reconcile (topic unload / broker restart):

durable view after reconcile:  lastConfirmedEntry 11:-1 numberOfEntries 0 ledgers [11]
  msgBacklog 0               <-- backlog silently drops to 0
consumer received post-reconcile: []

The phantom entry is discarded on recovery, the backlog silently drops from 1 to 0, and msg1 is permanently and silently lost — with no error surfaced to producer or consumer.

Broker log (the orphan write + trim)

OpAddEntry - [public/default/persistent/...] Closing ledger 9 for being full
ManagedLedgerImpl - [public/default/persistent/...] Created new ledger 10
ManagedLedgerImpl - [public/default/persistent/...] Delete complete for empty ledger 9. rc=0
...
ManagedCursorImpl - [public/default/persistent/...] Cursor sub recovered to position 11:-1

Summary of impact

• A producer receives a successful-produce ack for a message that is never durably stored.
• The subscription backlog is stuck at 1 and the consumer can never receive the message.
• On the next topic unload / broker restart the backlog silently resets to 0 and the message is gone — silent data loss.

Are you willing to submit a PR?

• I'm willing to submit a PR!