You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@pulsar.apache.org by "lhotari (via GitHub)" <gi...@apache.org> on 2026/10/12 07:23:50 UTC
[I] [Bug][meta] SessionReestablished is lost when recreating ZKMetadataStore's persistent watch fails, so the broker never revalidates its locks [pulsar]
lhotari opened a new issue, #26860:
URL: https://github.com/apache/pulsar/issues/26860
### Search before reporting
- [x] I searched in the [issues](https://github.com/apache/pulsar/issues) and found nothing similar.
### Read release policy
- [x] I understand that [unsupported versions](https://pulsar.apache.org/contribute/release-policy/#supported-versions) don't get bug fixes. I will attempt to reproduce the issue on a supported version of Pulsar client and Pulsar broker.
### User environment
- Broker: master at f2f026c7db79 (5.1.0-SNAPSHOT), in Docker containers of the test image; the code involved is the same on master at ab02bd9a402f
- Cluster: 2 brokers, 4 bookies, ZooKeeper with the default 30 s session timeout and `zookeeperSessionExpiredPolicy=reconnect`
- Found with the network conditions of the Pulsar Performance Testing Framework, #26859, in a run of `network/metadata-takeover`
### Issue Description
When a broker's ZooKeeper session is lost and a new session is established, `ZKMetadataStore` recreates its persistent watch on `/` before it forwards `SessionReestablished` to the other listeners, such as `LockManagerImpl`, which then revalidates the broker's locks: its bundle ownerships among them. If recreating the watch fails, the store marks the session invalid and expires the client so that it reconnects and tries again.
That retry never happens when the watch fails while the session watcher is still notifying the listeners, because `ZKSessionWatcher.checkState` overwrites the invalid status after the listeners return:
```java
default:
if (currentStatus != SessionEvent.SessionReestablished) {
...
sessionListener.accept(SessionEvent.Reconnected);
if (currentStatus == SessionEvent.SessionLost) {
// ZKMetadataStore.receivedSessionEvent -> addWatch fails -> sessionWatcher.setSessionInvalid()
// sets currentStatus = SessionLost
sessionListener.accept(SessionEvent.SessionReestablished);
}
currentStatus = SessionEvent.SessionReestablished; // overwrites the SessionLost set above
}
```
([ZKSessionWatcher.java:187-198](https://github.com/apache/pulsar/blob/ab02bd9a402f/pulsar-metadata/src/main/java/org/apache/pulsar/metadata/impl/ZKSessionWatcher.java#L187-L198), [ZKMetadataStore.java:164-188](https://github.com/apache/pulsar/blob/ab02bd9a402f/pulsar-metadata/src/main/java/org/apache/pulsar/metadata/impl/ZKMetadataStore.java#L164-L188))
`setSessionInvalid()` is synchronized, but `checkState` already holds the monitor on the same thread, so it doesn't wait. The `Expired` event that the store then injects into `PulsarZooKeeperClient` only makes the client replace the session; it isn't forwarded to the session watcher, which gets the previous handle's `Closed` event and the new session's `SyncConnected`. With the status already `SessionReestablished`, both are ignored. `SessionReestablished` never reaches `LockManagerImpl` ([LockManagerImpl.java:123-128](https://github.com/apache/pulsar/blob/ab02bd9a402f/pulsar-metadata/src/main/java/org/apache/pulsar/metadata/coordination/impl/LockManagerImpl.java#L123-L128)), so the broker never revalidates its locks after the session loss.
In the run, broker-1 had been cut off from ZooKeeper for 90 s; broker-0 had taken over broker-1's bundles after its session expired. Broker-1's log when ZooKeeper became reachable again (UTC):
```text
18:21:16,041 [metadata-store-event-10-1] INFO ZKSessionWatcher - Got ZK session watch event {event=WatchedEvent state:SyncConnected ...}
18:21:16,041 [metadata-store-event-10-1] INFO ZKSessionWatcher - ZooKeeper client reconnection with server quorum {currentStatus=SessionLost}
18:21:16,140 [metadata-store-event-10-1] ERROR ZKMetadataStore - Failed to recreate persistent watch on ZooKeeper {code=SESSIONEXPIRED}
18:21:16,140 [metadata-store-event-10-1] INFO PulsarService - Received metadata service session event {event=Reconnected}
18:21:16,141 [metadata-store-coordination-service-27-1] INFO LockManagerImpl - Metadata store connection has been re-established. Revalidating locks that were pending.
18:21:16,142 [metadata-store-event-10-1] INFO ZKSessionWatcher - Got ZK session watch event {event=WatchedEvent state:Closed ...}
18:21:16,145 [metadata-store-event-10-1] INFO ZKSessionWatcher - Got ZK session watch event {event=WatchedEvent state:SyncConnected ...}
```
The watch failure is logged on the same thread as the reconnection, inside `checkState`. The second `SyncConnected`, of the session created after the expiry, logs no "reconnection with server quorum", since the status was already `SessionReestablished`. `LockManagerImpl` never logged "Metadata store session has been re-established. Revalidating all the existing locks" for the rest of the run, about 3.5 minutes until the broker was stopped.
The consequences in that run:
- Broker-1 kept its bundle ownerships in its local cache although broker-0 held the locks, and served the bundles' topics alongside broker-0.
- Each broker's topic loads recovered, and so fenced, the other broker's ledgers; broker-0 failed writes with `LedgerFencedException`, and broker-1 looped on ledger metadata conflicts (`MetadataUpdateLoop`, about 370,000 log lines).
- About 16,000 sends were never acknowledged, and the consumers stopped at 91 % of the messages with 139,000 duplicates.
In a repeat of the same scenario, the first attempt to recreate the watch failed the same way, but the state happened to recover: a second reconnection delivered `SessionReestablished`, broker-1 revalidated its locks, marked seven of them expired and dropped the bundles. So the outcome depends on timing.
**Expected:** when a listener marks the reestablished session invalid while it's notified, the next reconnection sends `SessionReestablished` again, and the broker revalidates its locks.
### Error messages
```text
ERROR org.apache.pulsar.metadata.impl.ZKMetadataStore - Failed to recreate persistent watch on ZooKeeper {code=SESSIONEXPIRED}
```
### Reproducing the issue
A unit test: create a `ZKSessionWatcher` with a mocked `ZooKeeper` and a listener that calls `setSessionInvalid()` when it gets `SessionReestablished`, as `ZKMetadataStore` does when it fails to recreate the watch. Deliver `Expired`, `SyncConnected`, `Closed`, `SyncConnected` through `process`, the events of the log above. The listener gets `SessionLost, Reconnected, SessionReestablished` and nothing for the second session.
In a cluster, it takes a ZooKeeper session expiry followed by a reconnection whose new session expires before the watch is recreated, as can happen when a broker's connectivity to ZooKeeper comes back while ZooKeeper still expires its old sessions. The network conditions of the Pulsar Performance Testing Framework in #26859 produced it with:
```bash
./gradlew :tests:performance:launcher:run -Pperformance.keepLauncherLog \
--args='--scenario tests/performance/scenarios/iot-telemetry-small.yaml --extends network/metadata-takeover'
```
It doesn't happen in every run.
### Additional information
A possible fix: in `checkState`, set `currentStatus = SessionEvent.SessionReestablished` before notifying the listener, remembering the previous status to decide whether to send `SessionReestablished`, so that a `setSessionInvalid()` during the notification stays in effect. `checkState` then also needs to ignore `Closed` events, which its `default` branch now takes as a reconnection: after an invalidated session, the replaced handle's `Closed` event would send `SessionReestablished` before the new session is connected.
In the run above, this made a broker that had lost its metadata session keep serving bundles that another broker had taken over.
### Are you willing to submit a PR?
- [x] I'm willing to submit a PR!
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
Re: [I] [Bug][meta] SessionReestablished is lost when recreating ZKMetadataStore's persistent watch fails, so the broker never revalidates its locks [pulsar]
Posted by "merlimat (via GitHub)" <gi...@apache.org>.
merlimat closed issue #26860: [Bug][meta] SessionReestablished is lost when recreating ZKMetadataStore's persistent watch fails, so the broker never revalidates its locks
URL: https://github.com/apache/pulsar/issues/26860
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org