yapxue opened a new issue, #16661:
URL: https://github.com/apache/pulsar/issues/16661
**Describe the bug**
use pulsar admin tool stats-internal with option -m can cause active ledger
recover then close.
**To Reproduce**
Steps to reproduce the behavior:
1. start pulsar and sample prodcuer, consumer
2. execute `./pulsar-admin topics stats-internal {topicName} -m`, example
result may be
<img width="1680" alt="Screen_Shot_2022-07-19_at_8_49_12_AM"
src="https://user-images.githubusercontent.com/20301740/179642429-c3871a3b-955a-41ba-af29-3097bfd8147d.png";>
4. check the log, broker recover and close ledgers every time you execute
the stats-internal command.
```
2022-07-18T13:37:46,130+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
INFO org.apache.bookkeeper.client.ReadOnlyLedgerHandle - Closing recovered
ledger 424 at entry 18
2022-07-18T13:37:57,659+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
WARN org.apache.bookkeeper.client.PendingAddOp - Fencing exception on write:
L424 E19 on
pulsar-poc-bookie-2.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181
2022-07-18T13:37:57,659+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
ERROR org.apache.bookkeeper.client.LedgerHandle - Closing ledger 424 due to
LedgerFencedException: Ledger has been fenced off. Some other client must have
opened it to read
2022-07-18T13:37:57,660+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
WARN org.apache.bookkeeper.client.PendingAddOp - Fencing exception on write:
L424 E19 on
pulsar-poc-bookie-4.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181
2022-07-18T13:37:57,660+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
ERROR org.apache.bookkeeper.client.LedgerHandle - Closing ledger 424 due to
LedgerFencedException: Ledger has been fenced off. Some other client must have
opened it to read
2022-07-18T13:37:57,660+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
ERROR org.apache.bookkeeper.client.PendingAddOp - Write of ledger entry to
quorum failed: L424 E19
2022-07-18T13:37:57,661+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2] Creating a new
ledger after closed
2022-07-18T13:37:57,661+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2] Creating ledger,
metadata: {component=[109, 97, 110, 97, 103, 101, 100, 45, 108, 101, 100, 103,
101, 114], pulsar/managed-ledger=[112, 117, 98, 108, 105, 99, 47, 100, 101,
102, 97, 117, 108, 116, 47, 112, 101, 114, 115, 105, 115, 116, 101, 110, 116,
47, 66, 69, 83, 50, 45, 89, 65, 80, 88, 85, 69, 45, 49, 49, 49, 56, 45, 69, 86,
69, 78, 84, 45, 112, 97, 114, 116, 105, 116, 105, 111, 110, 45, 50],
application=[112, 117, 108, 115, 97, 114]} - metadata ops timeout : 60 seconds
2022-07-18T13:37:57,661+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
WARN org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble:
[pulsar-poc-bookie-1.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181,
pulsar-poc-bookie-3.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181]
is not adhering to Placement Policy. quarantinedBookies: []
2022-07-18T13:37:57,674+0000 [main-EventThread] INFO
org.apache.bookkeeper.client.MetadataUpdateLoop -
UpdateLoop(ledgerId=424,loopId=1ca7e34c) conflict writing metadata to store,
update local value and try again
2022-07-18T13:37:57,717+0000 [main-EventThread] INFO
org.apache.bookkeeper.client.LedgerCreateOp - Ensemble:
[pulsar-poc-bookie-1.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181,
pulsar-poc-bookie-3.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181]
for ledger: 434
2022-07-18T13:37:57,717+0000 [main-EventThread] INFO
org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2] Created new
ledger 434
2022-07-18T13:37:57,720+0000 [bookkeeper-ml-scheduler-OrderedScheduler-0-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - Reset
cursor:ManagedCursorImpl{ledger=public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2,
name=numsgMulti.BES2-BesRaptorioTest-YAPXUE-1118-EVENT, ackPos=424:18,
readPos=424:19} to 434:-1 since ledger consumed completely
2022-07-18T13:37:57,721+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2] Ledger 424
contains the current last confirmed entry 424:18, and it is going to be deleted
2022-07-18T13:37:57,722+0000 [pulsar-io-4-1] INFO
org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to
bookie:
pulsar-poc-bookie-1.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181
[id: 0x55504ede, L:/10.147.251.56:41182 -
R:pulsar-poc-bookie-1.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io/10.147.178.241:3181]
2022-07-18T13:37:57,722+0000 [pulsar-io-4-1] INFO
org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id:
0x55504ede, L:/10.147.251.56:41182 -
R:pulsar-poc-bookie-1.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io/10.147.178.241:3181]
authenticated as BookKeeperPrincipal{ANONYMOUS}
2022-07-18T13:37:57,724+0000 [bookkeeper-ml-scheduler-OrderedScheduler-0-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2] End
TrimConsumedLedgers. ledgers=1 totalSize=0
2022-07-18T13:37:57,724+0000 [bookkeeper-ml-scheduler-OrderedScheduler-0-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2] Removing ledger
424 - size: 31551
2022-07-18T13:38:55,940+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
INFO org.apache.bookkeeper.client.ReadOnlyLedgerHandle - Closing recovered
ledger 434 at entry 3
2022-07-18T13:38:57,784+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
WARN org.apache.bookkeeper.client.PendingAddOp - Fencing exception on write:
L434 E4 on
pulsar-poc-bookie-3.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181
2022-07-18T13:38:57,785+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
ERROR org.apache.bookkeeper.client.LedgerHandle - Closing ledger 434 due to
LedgerFencedException: Ledger has been fenced off. Some other client must have
opened it to read
2022-07-18T13:38:57,785+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
WARN org.apache.bookkeeper.client.PendingAddOp - Fencing exception on write:
L434 E4 on
pulsar-poc-bookie-1.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181
2022-07-18T13:38:57,785+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
ERROR org.apache.bookkeeper.client.LedgerHandle - Closing ledger 434 due to
LedgerFencedException: Ledger has been fenced off. Some other client must have
opened it to read
2022-07-18T13:38:57,785+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
ERROR org.apache.bookkeeper.client.PendingAddOp - Write of ledger entry to
quorum failed: L434 E4
2022-07-18T13:38:57,785+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2] Creating a new
ledger after closed
2022-07-18T13:38:57,785+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2] Creating ledger,
metadata: {component=[109, 97, 110, 97, 103, 101, 100, 45, 108, 101, 100, 103,
101, 114], pulsar/managed-ledger=[112, 117, 98, 108, 105, 99, 47, 100, 101,
102, 97, 117, 108, 116, 47, 112, 101, 114, 115, 105, 115, 116, 101, 110, 116,
47, 66, 69, 83, 50, 45, 89, 65, 80, 88, 85, 69, 45, 49, 49, 49, 56, 45, 69, 86,
69, 78, 84, 45, 112, 97, 114, 116, 105, 116, 105, 111, 110, 45, 50],
application=[112, 117, 108, 115, 97, 114]} - metadata ops timeout : 60 seconds
2022-07-18T13:38:57,785+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
WARN org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble:
[pulsar-poc-bookie-3.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181,
pulsar-poc-bookie-2.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181]
is not adhering to Placement Policy. quarantinedBookies: []
2022-07-18T13:38:57,790+0000 [main-EventThread] INFO
org.apache.bookkeeper.client.MetadataUpdateLoop -
UpdateLoop(ledgerId=434,loopId=2cf06bdf) conflict writing metadata to store,
update local value and try again
2022-07-18T13:38:57,795+0000 [main-EventThread] INFO
org.apache.bookkeeper.client.LedgerCreateOp - Ensemble:
[pulsar-poc-bookie-3.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181,
pulsar-poc-bookie-2.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181]
for ledger: 435
2022-07-18T13:38:57,795+0000 [main-EventThread] INFO
org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2] Created new
ledger 435
2022-07-18T13:38:57,800+0000 [bookkeeper-ml-scheduler-OrderedScheduler-0-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - Reset
cursor:ManagedCursorImpl{ledger=public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2,
name=numsgMulti.BES2-BesRaptorioTest-YAPXUE-1118-EVENT, ackPos=434:3,
readPos=434:4} to 435:-1 since ledger consumed completely
2022-07-18T13:38:57,801+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2] Ledger 434
contains the current last confirmed entry 434:3, and it is going to be deleted
2022-07-18T13:38:57,802+0000 [pulsar-io-4-2] INFO
org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to
bookie:
pulsar-poc-bookie-2.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io:3181
[id: 0xdbe47b42, L:/10.147.251.56:35094 -
R:pulsar-poc-bookie-2.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io/10.147.182.148:3181]
2022-07-18T13:38:57,802+0000 [pulsar-io-4-2] INFO
org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id:
0xdbe47b42, L:/10.147.251.56:35094 -
R:pulsar-poc-bookie-2.pulsar-poc-bookie.rheos-streaming-qa.svc.140.tess.io/10.147.182.148:3181]
authenticated as BookKeeperPrincipal{ANONYMOUS}
2022-07-18T13:38:57,805+0000 [bookkeeper-ml-scheduler-OrderedScheduler-0-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2] End
TrimConsumedLedgers. ledgers=1 totalSize=0
2022-07-18T13:38:57,805+0000 [bookkeeper-ml-scheduler-OrderedScheduler-0-0]
INFO org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[public/default/persistent/BES2-YAPXUE-1118-EVENT-partition-2] Removing ledger
434 - size: 5490
2022-07-18T13:39:19,260+0000 [BookKeeperClientWorker-OrderedExecutor-0-0]
INFO org.apache.bookkeeper.client.ReadOnlyLedgerHandle - Closing recovered
ledger 435 at entry 1
```
**Expected behavior**
Should not close active ledger whn execute stats-internal command.
**Screenshots**
If applicable, add screenshots to help explain your problem.
**Desktop (please complete the following information):**
- OS: mac
**Additional context**
Add any other context about the problem here.
--
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: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
![https://user-images.githubusercontent.com/20301740/179642429-c3871a3b-955a-41ba-af29-3097bfd8147d.png"](https://user-images.githubusercontent.com/20301740/179642429-c3871a3b-955a-41ba-af29-3097bfd8147d.png"){kind=link}