apache / apache/pulsar

[Bug] Topic cannot be accessed for "Failed to load topic within timeout" unless unloading the namespace

Open
#24,497 2 comments 0 reactions 1 assignee Claimed by @BewareMyPower View on GitHub
type/bug
Dominant language
Java
Stars
15.3k
Forks
3.8k
Avg merge
1d 14h
Merged PRs (30d)
160

Description

### 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

StreamNative Pulsar 4.0.5.2, which is based on https://github.com/apache/pulsar/commit/6b5fdbf2282efcfed30badab2c79bab3a6f92393

### Issue Description

This issue happens when we restarted brokers for an upgrade. There were two partitions (10 and 23 of a partitioned topic) owned by a broker stuck at initializing the `PersistentTopic`. Here are the info from the heap dump:

```yaml
topic:
- name: "-partition-23"
messageDeduplication:
snapshotCounter: 21
managedCursor:
entriesReadCount: 42
lastMarkDeleteEntry:
newPosition: "860608:298"
pendingReadOps: 0
readPosition: "861217:3"
managedLedger:
config:
readEntryTimeoutSeconds: 0
executor:
runner: "BookKeeperClientWorker-OrderedExecutor-0-0"
tasksFailed: 1
lastConfirmedEntry: "861217:2"
ledgers:
- key: 860608
value: {"entries": 338}
- key: 861217
value: {"entries": 3}
- key: 861315
value: {"entries": 0}
- name: "-partition-10"
messageDeduplication:
snapshotCounter: 0
managedCursor:
entriesReadCount: 84
lastMarkDeleteEntry:
newPosition: "860650:231"
pendingReadOps: 1
readPosition: "861214:0"
managedLedger:
currentLedger:
ledgerId: 861295
lastConfirmedEntry: "861214:1"
ledgers:
- key: 860650
value: {"entries": 314}
- key: 861214
value: {"entries": 2}
- key: 861295
value: {"entries": 0}
state: LedgerOpened
```

The key is the `MessageDeduplication` field:
- `status` is `Initialized`
- `managedCursor` is not null
- `snapshotCounter` is non-zero

From https://github.com/apache/pulsar/blob/ce102dac32978740b8dd7ddb1598ce3263ef6202/pulsar-broker/src/main/java/org/apache/pulsar/broker/service/persistent/MessageDeduplication.java#L292-L298

we can get a conclusion that the future of `recoverSequenceIdsMap` never completed.

The difference between partition 10 and 23 is:
- Partition 10's cursor read position didn't reach the last confirmed entry, and there was a pending read operation. It seems that a read operation was somehow stuck forever.
- Partition 23's cursor read position exceeds the last confirmed entry, the future should have been completed. There is another suspicious point that `snapshotCounter` is 21 while `entriesReadCount` is 42.

The most possible reason is that exceptions were thrown in a callback like https://github.com/apache/pulsar/blob/ce102dac32978740b8dd7ddb1598ce3263ef6202/pulsar-broker/src/main/java/org/apache/pulsar/broker/service/persistent/MessageDeduplication.java#L178

There was something wrong with our log collection, the key logs of `SingleThreadExecutor#run` have been lost. But we can check the `taskFailed` field is 1 from the heap dump.

### Error messages

```text

```

### Reproducing the issue

Currently I cannot reproduce it.

### Additional information

Currently Pulsar's topic caching mechanism is bad. There is a timeout configured by `topicLoadTimeoutSeconds` (default: 60). 1 minute is usually long enough in most cases. However, when the timeout happens, the topic cache won't be removed from `BrokerService#topics` until the pending `PersistentTopic` initialization completes. See https://github.com/apache/pulsar/blob/ce102dac32978740b8dd7ddb1598ce3263ef6202/pulsar-broker/src/main/java/org/apache/pulsar/broker/service/BrokerService.java#L1849-L1855

`initialize()`:
1. Create a compaction service and set `topicCompactionService` with it.
2. Create subscriptions for all cursors in the managed ledger.
3. Get namespace policies for this topic from the metadata store.
4. Initialize some fields according to the namespace policies.
5. Register itself to the topic policies service.
6. Get topic policies and update some fields.
7. Remove orphan replication cursors.

`preCreateSubscriptionForCompactionIfNeeded()`: Create `__compaction` subscription, which might open the durable cursor.

`checkReplication()`:
1. Get allowed clusters from the metadata store.
2. Start replicators if necessary.

`checkDeduplicationStatus()`: Perform the topic replay.

**If there is a bug that makes `PersistentTopic` stuck at initialization, e.g. `checkDeduplicationStatus()`, the topic will be unavailable until manual intervention.**

### Are you willing to submit a PR?

- [x] I'm willing to submit a PR!

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.