apache / apache/pulsar

bookie failed to decommission successfully

Open
#15,776 7 comments 1 reaction 0 assignees View on GitHub
Stale type/bug
Dominant language
Java
Stars
15.3k
Forks
3.8k
Avg merge
1d 14h
Merged PRs (30d)
160

Description

**Describe the bug**
I have four bookie , one of the bookie process hangs because the disk is full, so I try to clear the data directory and take the service offline.
In addition, the number of data copies is three, and the cluster can be used normally when the bookie service hangs up

**To Reproduce**
Steps to reproduce the behavior:
1. Delete journalDirectories and ledgerDirectories directory data
2. Execute command:‘ bin/bookkeeper shell listunderreplicated ’
```
2022-05-25 16:40:16.0906 [main] INFO org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=10.101.129.65:2181,10.101.129.68:2181,10.101.129.70:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@6c372fe6
2022-05-25 16:40:16.0911 [main] INFO org.apache.zookeeper.common.X509Util - Setting -D jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated TLS renegotiation
2022-05-25 16:40:16.0917 [main] INFO org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 1048575 Bytes
2022-05-25 16:40:16.0923 [main] INFO org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=false
2022-05-25 16:40:16.0932 [main-SendThread(10.101.129.70:2181)] INFO org.apache.zookeeper.ClientCnxn - Opening socket connection to server kafka-pool-prd-10-101-129-70.v-sz-1.vivo.lan/10.101.129.70:2181.
2022-05-25 16:40:16.0933 [main-SendThread(10.101.129.70:2181)] INFO org.apache.zookeeper.ClientCnxn - SASL config status: Will not attempt to authenticate using SASL (unknown error)
2022-05-25 16:40:16.0937 [main-SendThread(10.101.129.70:2181)] INFO org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /10.101.129.65:35556, server: kafka-pool-prd-10-101-129-70.v-sz-1.vivo.lan/10.101.129.70:2181
2022-05-25 16:40:16.0941 [main-SendThread(10.101.129.70:2181)] INFO org.apache.zookeeper.ClientCnxn - Session establishment complete on server kafka-pool-prd-10-101-129-70.v-sz-1.vivo.lan/10.101.129.70:2181, session id = 0x3063889d93b4263, negotiated timeout = 30000
2022-05-25 16:40:16.0944 [main-EventThread] INFO org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase - ZooKeeper client is connected now.
2022-05-25 16:40:17.0035 [main] INFO org.apache.bookkeeper.tools.cli.commands.autorecovery.ListUnderReplicatedCommand - 396606
2022-05-25 16:40:17.0035 [main] INFO org.apache.bookkeeper.tools.cli.commands.autorecovery.ListUnderReplicatedCommand - Ctime : 1651199961381
2022-05-25 16:40:17.0036 [main] INFO org.apache.bookkeeper.tools.cli.commands.autorecovery.ListUnderReplicatedCommand - 112963
2022-05-25 16:40:17.0036 [main] INFO org.apache.bookkeeper.tools.cli.commands.autorecovery.ListUnderReplicatedCommand - Ctime : 1650363984734
2022-05-25 16:40:17.0037 [main-SendThread(10.101.129.70:2181)] WARN org.apache.zookeeper.ClientCnxn - An exception was thrown while closing send thread for session 0x3063889d93b4263.
org.apache.zookeeper.ClientCnxn$EndOfStreamException: Unable to read additional data from server sessionid 0x3063889d93b4263, likely server has closed socket
at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:77) ~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350) ~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1290) [org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
2022-05-25 16:40:17.0143 [main] INFO org.apache.zookeeper.ZooKeeper - Session: 0x3063889d93b4263 closed
2022-05-25 16:40:17.0143 [main-EventThread] INFO org.apache.zookeeper.ClientCnxn - EventThread shut down for session: 0x3063889d93b4263
```
3. Execute command:‘ bin/bookkeeper shell decommissionbookie’
```
2022-05-25 16:04:09.0574 [main] INFO org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=10.101.129.65:2181,10.101.129.68:2181,10.101.129.70:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@69f1a286
2022-05-25 16:04:09.0579 [main] INFO org.apache.zookeeper.common.X509Util - Setting -D jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated TLS renegotiation
2022-05-25 16:04:09.0585 [main] INFO org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 1048575 Bytes
2022-05-25 16:04:09.0592 [main] INFO org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=false
2022-05-25 16:04:09.0601 [main-SendThread(10.101.129.68:2181)] INFO org.apache.zookeeper.ClientCnxn - Opening socket connection to server kafka-pool-prd-10-101-129-68.v-sz-1.vivo.lan/10.101.129.68:2181.
2022-05-25 16:04:09.0601 [main-SendThread(10.101.129.68:2181)] INFO org.apache.zookeeper.ClientCnxn - SASL config status: Will not attempt to authenticate using SASL (unknown error)
2022-05-25 16:04:09.0605 [main-SendThread(10.101.129.68:2181)] INFO org.apache.zookeeper.ClientCnxn - Socket connection established, initiating session, client: /10.101.129.65:55334, server: kafka-pool-prd-10-101-129-68.v-sz-1.vivo.lan/10.101.129.68:2181
2022-05-25 16:04:09.0609 [main-SendThread(10.101.129.68:2181)] INFO org.apache.zookeeper.ClientCnxn - Session establishment complete on server kafka-pool-prd-10-101-129-68.v-sz-1.vivo.lan/10.101.129.68:2181, session id = 0x10130f8da34426c, negotiated timeout = 30000
2022-05-25 16:04:09.0612 [main-EventThread] INFO org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase - ZooKeeper client is connected now.
2022-05-25 16:04:09.0789 [main] ERROR org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Failed to initialize DNS Resolver org.apache.bookkeeper.net.ScriptBasedMapping, used default subnet resolver
java.lang.RuntimeException: No network topology script is found when using script based DNS resolver.
at org.apache.bookkeeper.net.ScriptBasedMapping$RawScriptBasedMapping.validateConf(ScriptBasedMapping.java:163) ~[bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.net.AbstractDNSToSwitchMapping.setConf(AbstractDNSToSwitchMapping.java:81) ~[bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.net.ScriptBasedMapping.setConf(ScriptBasedMapping.java:123) ~[bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl.initialize(RackawareEnsemblePlacementPolicyImpl.java:265) [bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl.initialize(RackawareEnsemblePlacementPolicyImpl.java:80) [bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.client.BookKeeper.initializeEnsemblePlacementPolicy(BookKeeper.java:581) [bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.client.BookKeeper.(BookKeeper.java:505) [bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.client.BookKeeper.(BookKeeper.java:344) [bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.client.BookKeeperAdmin.(BookKeeperAdmin.java:164) [bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.tools.cli.commands.bookies.DecommissionCommand.decommission(DecommissionCommand.java:91) [bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.tools.cli.commands.bookies.DecommissionCommand.apply(DecommissionCommand.java:82) [bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.bookie.BookieShell$DecommissionBookieCmd.runCmd(BookieShell.java:1956) [bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.bookie.BookieShell$MyCommand.runCmd(BookieShell.java:238) [bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.bookie.BookieShell.run(BookieShell.java:2278) [bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
at org.apache.bookkeeper.bookie.BookieShell.main(BookieShell.java:2369) [bookkeeper-server-4.14.4.1-SNAPSHOT.jar:4.14.4.1-SNAPSHOT]
2022-05-25 16:04:09.0818 [main] INFO org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Initialize rackaware ensemble placement policy @ @ /default-rack : org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy$DefaultResolver.
2022-05-25 16:04:09.0818 [main] INFO org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Not weighted
2022-05-25 16:04:09.0827 [main] INFO org.apache.bookkeeper.client.BookKeeper - Weighted ledger placement is not enabled
2022-05-25 16:04:09.0903 [main-EventThread] INFO org.apache.bookkeeper.discover.ZKRegistrationClient - Update BookieInfoCache (writable bookie) 10.101.129.68:3181 -> BookieServiceInfo{properties={}, endpoints=[EndpointInfo{id=httpserver, port=8070, host=0.0.0.0, protocol=http, auth=[], extensions=[]}, EndpointInfo{id=bookie, port=3181, host=10.101.129.68, protocol=bookie-rpc, auth=[], extensions=[]}]}
2022-05-25 16:04:09.0903 [main-EventThread] INFO org.apache.bookkeeper.discover.ZKRegistrationClient - Update BookieInfoCache (writable bookie) 10.101.129.65:3181 -> BookieServiceInfo{properties={}, endpoints=[EndpointInfo{id=httpserver, port=8070, host=0.0.0.0, protocol=http, auth=[], extensions=[]}, EndpointInfo{id=bookie, port=3181, host=10.101.129.65, protocol=bookie-rpc, auth=[], extensions=[]}]}
2022-05-25 16:04:09.0904 [main-EventThread] INFO org.apache.bookkeeper.discover.ZKRegistrationClient - Update BookieInfoCache (writable bookie) 10.101.129.70:3181 -> BookieServiceInfo{properties={}, endpoints=[EndpointInfo{id=httpserver, port=8070, host=0.0.0.0, protocol=http, auth=[], extensions=[]}, EndpointInfo{id=bookie, port=3181, host=10.101.129.70, protocol=bookie-rpc, auth=[], extensions=[]}]}
2022-05-25 16:04:09.0908 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-rack/10.101.129.68:3181
2022-05-25 16:04:09.0908 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-rack/10.101.129.65:3181
2022-05-25 16:04:09.0908 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-rack/10.101.129.70:3181
2022-05-25 16:04:09.0945 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Resetting LostBookieRecoveryDelay value: 0, to kickstart audit task
2022-05-25 16:05:04.0446 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 10
2022-05-25 16:06:44.0455 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:06:54.0458 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:07:04.0460 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:07:14.0462 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:07:24.0464 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:07:34.0465 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:07:44.0467 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:07:54.0471 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:08:04.0473 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:08:14.0474 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:08:24.0476 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:08:34.0478 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:08:44.0480 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:08:54.0482 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:09:04.0485 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:09:14.0487 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:09:24.0489 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:09:34.0490 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:09:44.0492 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:09:54.0494 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:10:04.0496 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:10:14.0498 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
2022-05-25 16:10:24.0500 [main] INFO org.apache.bookkeeper.client.BookKeeperAdmin - Count of Ledgers which need to be rereplicated: 1
```
Continuously prints "Count of Ledgers which need to be rereplicated: 1" for a whole day without ending

System configuration

Pulsar version: 2.9.2
bookeeper:4.14.4

Contributor guide

Open the contributing guide

Research direction

Start with the `BookieShell` `decommissionbookie` command and the `DecommissionCommand.decommission` and `BookKeeperAdmin` paths shown in the stack trace. Reproduce the commands against a comparable cluster and inspect why rereplication remains pending; done means the failed bookie is decommissioned successfully and the affected ledgers are fully rereplicated.

Written by the indexing model from the issue text.

Assessment

Tech stack
java
Domain
distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.