[Bug] Receives topic is temporarily unavailable error when bookies are rolling restart
- Dominant language
- Java
- Stars
- 15.3k
- Forks
- 3.8k
- Avg merge
- 1d 14h
- Merged PRs (30d)
- 160
Description
### Search before asking
- [X] I searched in the [issues](https://github.com/apache/pulsar/issues) and found nothing similar.
### Version
Pulsar 3.1.1
### Minimal reproduce step
broker count: 2
bookie count: 5
broker config:
managedLedgerDefaultAckQuorum: "2"
managedLedgerDefaultEnsembleSize: "4"
managedLedgerDefaultWriteQuorum: "3"
Using pulsar perf the publishing rate is 200000 messages/sec and the total number of messages is 100000000.
Consume it at the same time.
`bin/pulsar-perf produce persistent://pulsar/default/input_test -r 200000 -m 10000000`
`bin/pulsar-perf consume persistent://pulsar/default/input_test -ss sub01`
### What did you expect to see?
Complete the production and consumption of all messages
### What did you see instead?
Consumer receives `topic is temporarily unavailable` errors and is stuck
```java
2024-01-05T18:32:19,950+0800 [pulsar-client-io-1-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-5][subtest04] Subscribing to topic on cnx [id: 0x81eec4ec, L:/11.145.30.236:23196 - R:21.24.16.52/21.24.16.52:6650], consumerId 5
2024-01-05T18:32:19,951+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0xf22ff96d, L:/11.145.30.236:23180 - R:21.24.16.52/21.24.16.52:6650] Received error from server: Topic is temporarily unavailable
2024-01-05T18:32:19,953+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-6][subtest04] Failed to subscribe to topic on 21.24.16.52/21.24.16.52:6650
2024-01-05T18:32:19,953+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-6] [subtest04] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895795, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23180"}
2024-01-05T18:32:19,953+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-6] [subtest04] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895795, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23180"} -- Will try again in 0.1 s
2024-01-05T18:32:19,954+0800 [pulsar-client-io-1-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-2][subtest04] Subscribed to topic on 21.24.16.52/21.24.16.52:6650 -- consumer: 2
2024-01-05T18:32:19,954+0800 [pulsar-client-io-1-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-0][subtest04] Subscribed to topic on 21.24.16.52/21.24.16.52:6650 -- consumer: 0
2024-01-05T18:32:19,955+0800 [pulsar-client-io-1-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-7][subtest04] Subscribed to topic on 21.24.16.52/21.24.16.52:6650 -- consumer: 7
2024-01-05T18:32:19,955+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0xf22ff96d, L:/11.145.30.236:23180 - R:21.24.16.52/21.24.16.52:6650] Received error from server: Topic is temporarily unavailable
2024-01-05T18:32:19,955+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-9][subtest04] Failed to subscribe to topic on 21.24.16.52/21.24.16.52:6650
2024-01-05T18:32:19,955+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-9] [subtest04] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895799, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23180"}
2024-01-05T18:32:19,955+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-9] [subtest04] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895799, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23180"} -- Will try again in 0.1 s
2024-01-05T18:32:19,955+0800 [pulsar-client-io-1-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-8][subtest04] Subscribed to topic on 21.24.16.52/21.24.16.52:6650 -- consumer: 8
2024-01-05T18:32:19,956+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-1] [subtest04] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895802, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23196"}
2024-01-05T18:32:19,956+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-1] [subtest04] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895802, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23196"} -- Will try again in 0.1 s
2024-01-05T18:32:19,956+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x81eec4ec, L:/11.145.30.236:23196 - R:21.24.16.52/21.24.16.52:6650] Received error from server: Topic is temporarily unavailable
2024-01-05T18:32:19,957+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-3][subtest04] Failed to subscribe to topic on 21.24.16.52/21.24.16.52:6650
2024-01-05T18:32:19,957+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-3] [subtest04] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895803, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23196"}
2024-01-05T18:32:19,957+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-3] [subtest04] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895803, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23196"} -- Will try again in 0.1 s
2024-01-05T18:32:19,957+0800 [pulsar-client-io-1-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-5][subtest04] Subscribed to topic on 21.24.16.52/21.24.16.52:6650 -- consumer: 5
2024-01-05T18:32:20,054+0800 [pulsar-timer-6-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-6] [subtest04] Reconnecting after connection was closed
2024-01-05T18:32:20,059+0800 [pulsar-timer-6-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-9] [subtest04] Reconnecting after connection was closed
2024-01-05T18:32:20,059+0800 [pulsar-timer-6-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-1] [subtest04] Reconnecting after connection was closed
2024-01-05T18:32:20,059+0800 [pulsar-timer-6-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-3] [subtest04] Reconnecting after connection was closed
2024-01-05T18:32:20,062+0800 [pulsar-client-io-1-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-6][subtest04] Subscribing to topic on cnx [id: 0xf22ff96d, L:/11.145.30.236:23180 - R:21.24.16.52/21.24.16.52:6650], consumerId 6
2024-01-05T18:32:20,063+0800 [pulsar-client-io-1-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-1][subtest04] Subscribing to topic on cnx [id: 0x81eec4ec, L:/11.145.30.236:23196 - R:21.24.16.52/21.24.16.52:6650], consumerId 1
2024-01-05T18:32:20,064+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0xf22ff96d, L:/11.145.30.236:23180 - R:21.24.16.52/21.24.16.52:6650] Received error from server: Topic is temporarily unavailable
2024-01-05T18:32:20,064+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-6][subtest04] Failed to subscribe to topic on 21.24.16.52/21.24.16.52:6650
2024-01-05T18:32:20,064+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-6] [subtest04] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895809, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23180"}
2024-01-05T18:32:20,064+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-6] [subtest04] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895809, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23180"} -- Will try again in 0.188 s
2024-01-05T18:32:20,066+0800 [pulsar-client-io-1-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-9][subtest04] Subscribing to topic on cnx [id: 0xf22ff96d, L:/11.145.30.236:23180 - R:21.24.16.52/21.24.16.52:6650], consumerId 9
2024-01-05T18:32:20,067+0800 [pulsar-client-io-1-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-3][subtest04] Subscribing to topic on cnx [id: 0x81eec4ec, L:/11.145.30.236:23196 - R:21.24.16.52/21.24.16.52:6650], consumerId 3
2024-01-05T18:32:20,067+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x81eec4ec, L:/11.145.30.236:23196 - R:21.24.16.52/21.24.16.52:6650] Received error from server: Topic is temporarily unavailable
2024-01-05T18:32:20,067+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-1][subtest04] Failed to subscribe to topic on 21.24.16.52/21.24.16.52:6650
2024-01-05T18:32:20,067+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-1] [subtest04] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895810, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23196"}
2024-01-05T18:32:20,067+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-1] [subtest04] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895810, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23196"} -- Will try again in 0.191 s
2024-01-05T18:32:20,068+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0xf22ff96d, L:/11.145.30.236:23180 - R:21.24.16.52/21.24.16.52:6650] Received error from server: Topic is temporarily unavailable
2024-01-05T18:32:20,068+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-9][subtest04] Failed to subscribe to topic on 21.24.16.52/21.24.16.52:6650
2024-01-05T18:32:20,068+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-9] [subtest04] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895811, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23180"}
2024-01-05T18:32:20,068+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-9] [subtest04] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895811, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23180"} -- Will try again in 0.195 s
2024-01-05T18:32:20,070+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x81eec4ec, L:/11.145.30.236:23196 - R:21.24.16.52/21.24.16.52:6650] Received error from server: Topic is temporarily unavailable
2024-01-05T18:32:20,071+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-3][subtest04] Failed to subscribe to topic on 21.24.16.52/21.24.16.52:6650
2024-01-05T18:32:20,071+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-3] [subtest04] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895812, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23196"}
2024-01-05T18:32:20,071+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-3] [subtest04] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895812, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23196"} -- Will try again in 0.19 s
2024-01-05T18:32:20,254+0800 [pulsar-timer-6-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-6] [subtest04] Reconnecting after connection was closed
2024-01-05T18:32:20,260+0800 [pulsar-timer-6-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-1] [subtest04] Reconnecting after connection was closed
2024-01-05T18:32:20,261+0800 [pulsar-client-io-1-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-6][subtest04] Subscribing to topic on cnx [id: 0xf22ff96d, L:/11.145.30.236:23180 - R:21.24.16.52/21.24.16.52:6650], consumerId 6
2024-01-05T18:32:20,262+0800 [pulsar-timer-6-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-3] [subtest04] Reconnecting after connection was closed
2024-01-05T18:32:20,263+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0xf22ff96d, L:/11.145.30.236:23180 - R:21.24.16.52/21.24.16.52:6650] Received error from server: Topic is temporarily unavailable
2024-01-05T18:32:20,263+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/default2/alltables6-partition-6][subtest04] Failed to subscribe to topic on 21.24.16.52/21.24.16.52:6650
2024-01-05T18:32:20,263+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-6] [subtest04] Error connecting to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895815, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23180"}
2024-01-05T18:32:20,263+0800 [pulsar-client-io-1-1] WARN org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-6] [subtest04] Could not get connection to broker: org.apache.pulsar.client.api.PulsarClientException$LookupException: {"errorMsg":"Topic is temporarily unavailable","reqId":1789164940489895815, "remote":"21.24.16.52/21.24.16.52:6650", "local":"/11.145.30.236:23180"} -- Will try again in 0.37 s
2024-01-05T18:32:20,265+0800 [pulsar-timer-6-1] INFO org.apache.pulsar.client.impl.ConnectionHandler - [persistent://pulsar/default2/alltables6-partition-9] [subtest04] Reconnecting after connection was closed
```
Producer receives similar errors
```java
2024-01-05T18:30:12,998+0800 [pulsar-client-io-17-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x0a55fe43, L:/9.165.132.169:50214 - R:21.24.16.52/21.24.16.52:6650] Received error from server: org.apache.pulsar.broker.service.BrokerServiceException$TopicFencedException: Topic is temporarily unavailable
2024-01-05T18:30:12,998+0800 [pulsar-client-io-17-1] ERROR org.apache.pulsar.client.impl.ProducerImpl - [persistent://pulsar/default2/input_test5-partition-4] [input_test07-persistent://pulsar/default2/input_test5-persistent://pulsar/default2/input_test-partition-4-0] Failed to create producer: {\"errorMsg\":\"org.apache.pulsar.broker.service.BrokerServiceException$TopicFencedException: Topic is temporarily unavailable\",\"reqId\":2708211058561300994, \"remote\":\"21.24.16.52/21.24.16.52:6650\", \"local\":\"/9.165.132.169:50214\"}
```
### Anything else?
_No response_
### Are you willing to submit a PR?
- [X] I'm willing to submit a PR!
Contributor guide
Assessment
This issue has not been assessed yet.