pulsar icon indicating copy to clipboard operation
pulsar copied to clipboard

Incorrect msgBacklog value

Open shustsud opened this issue 6 years ago • 9 comments

Describe the bug Despite there are no messages in the backlog, positive value was set to "msgBacklog" in the response of partitioned-stats(API).

I think "msgBacklog" is calculated from "ManagedLedgerImpl.ENTRIES_ADDED_COUNTER_UPDATER" and "ManagedCursorImpl.messagesConsumedCounter". https://github.com/apache/pulsar/blob/dc7d01efc6cf2df5631bc509758f2212bede35ce/managed-ledger/src/main/java/org/apache/bookkeeper/mledger/impl/ManagedCursorImpl.java#L736

Looking at the debug log, [subscriptionName1] appears to have the wrong "ManagedCursorImpl.messagesConsumedCounter" value. In contrast, [subscriptionName2] looks correct.

Log:

12:08:44.575 [prometheus-stats-33-1] DEBUG o.a.b.mledger.impl.ManagedCursorImpl - [<topicName1>] Consumer <subscriptionName1> cursor ml-entries: 554102 -- deleted-counter: 549461 other counters: mdPos 27058740:10 rdPos 27058740:11
12:08:44.575 [prometheus-stats-33-1] DEBUG o.a.b.mledger.impl.ManagedCursorImpl - [<topicName1>] Consumer <subscriptionName2(replication)> cursor ml-entries: 554102 -- deleted-counter: 554102 other counters: mdPos 27058740:10 rdPos 27058740:11

Stats:

{
  "msgRateIn" : 3.283531005730665,
  "msgThroughputIn" : 1657.249768369514,
  "msgRateOut" : 3.2835310293187825,
  "msgThroughputOut" : 1657.2497802748082,
  "averageMsgSize" : 504.7157360406091,
  "storageSize" : 142581,
  "publishers" : [ ],
  "subscriptions" : {
    "<subscriptionName1>" : {
      "msgRateOut" : 3.2835310293187825,
      "msgThroughputOut" : 1657.2497802748082,
      "msgRateRedeliver" : 0.0,
      "msgBacklog" : 4677,
      "blockedSubscriptionOnUnackedMsgs" : false,
      "unackedMessages" : 0,
      "type" : "Exclusive",
      "activeConsumerName" : "4efd5",
      "msgRateExpired" : 0.0,
      "consumers" : [ {
        "msgRateOut" : 3.2835310293187825,
        "msgThroughputOut" : 1657.2497802748082,
        "msgRateRedeliver" : 0.0,
        "consumerName" : "4efd5",
        "availablePermits" : 946,
        "unackedMessages" : 0,
        "blockedConsumerOnUnackedMsgs" : false,
        "metadata" : { },
        "connectedSince" : "2019-09-02T13:29:21.891+09:00",
        "clientVersion" : "2.1.1-incubating",
        "address" : "/<ip1>:55920"
      } ]
    }
  },
  "replication" : {
    "<name>" : {
      "msgRateIn" : 3.283531005730665,
      "msgThroughputIn" : 1657.249768369514,
      "msgRateOut" : 0.0,
      "msgThroughputOut" : 0.0,
      "msgRateExpired" : 0.0,
      "replicationBacklog" : 0,
      "connected" : true,
      "replicationDelayInSeconds" : 0,
      "inboundConnection" : "/<ip2>:36792",
      "inboundConnectedSince" : "2019-08-29T11:36:48.612+09:00",
      "outboundConnection" : "[id: 0xb6500383, L:/<ip3>:50306 - R:<host2>/<ip2>:6651]",
      "outboundConnectedSince" : "2019-08-29T11:36:48.64+09:00"
    }
  },
  "deduplicationStatus" : "Disabled"
}

Stats-internal:

{
  "entriesAddedCounter" : 552514,
  "numberOfEntries" : 611632,
  "totalSize" : 1007353769,
  "currentLedgerEntries" : 15460,
  "currentLedgerSize" : 57848652,
  "lastLedgerCreatedTimestamp" : "2019-09-03T08:04:37.87+09:00",
  "waitingCursorsCount" : 2,
  "pendingAddEntriesCount" : 0,
  "lastConfirmedEntry" : "27010835:15459",
  "state" : "LedgerOpened",
  "ledgers" : [ {
    "ledgerId" : 25679299,
    "entries" : 2544,
    "size" : 11803597,
    "offloaded" : false
  }, {
    "ledgerId" : 25711440,
    "entries" : 11923,
    "size" : 42865506,
    "offloaded" : false
  ...(Omitted...)
  }, {
    "ledgerId" : 26992239,
    "entries" : 143,
    "size" : 658467,
    "offloaded" : false
  }, {
    "ledgerId" : 27010835,
    "entries" : 0,
    "size" : 0,
    "offloaded" : false
  } ],
  "cursors" : {
    "<subscriptionName1>" : {
      "markDeletePosition" : "27010835:15409",
      "readPosition" : "27010835:15460",
      "waitingReadOp" : true,
      "pendingReadOps" : 0,
      "messagesConsumedCounter" : 547823,
      "cursorLedger" : 27014015,
      "cursorLedgerLastEntry" : 426,
      "individuallyDeletedMessages" : "[]",
      "lastLedgerSwitchTimestamp" : "2019-09-03T09:34:14.211+09:00",
      "state" : "Open",
      "numberOfEntriesSinceFirstNotAckedMessage" : 51,
      "totalNonContiguousDeletedMessagesRange" : 0,
      "properties" : { }
    },
    "<subscriptionName2(replication)>" : {
      "markDeletePosition" : "27010835:15459",
      "readPosition" : "27010835:15460",
      "waitingReadOp" : true,
      "pendingReadOps" : 0,
      "messagesConsumedCounter" : 552514,
      "cursorLedger" : 26992238,
      "cursorLedgerLastEntry" : 848,
      "individuallyDeletedMessages" : "[]",
      "lastLedgerSwitchTimestamp" : "2019-09-03T04:00:02.255+09:00",
      "state" : "Open",
      "numberOfEntriesSinceFirstNotAckedMessage" : 1,
      "totalNonContiguousDeletedMessagesRange" : 0,
      "properties" : { }
    }
  }
}

To Reproduce We suspect that reset-cursor operations which were executed right before caused the problem.

11:08 "reset-cursor (API)" was called. (11 days ago)
11:11 "reset-cursor (API)" was called. (1 minute ago)

The log at the time of operations is as follows.

Log:

11:08:08.171 [pulsar-web-26-32] INFO  o.a.p.b.a.impl.PersistentTopicsBase  - [<serviceName1>] [persistent://<topicName1>] Received reset cursor on subscription <subscriptionName1> to time 1566439687935
11:08:08.199 [bookkeeper-ml-workers-OrderedExecutor-22-0] INFO  o.a.p.b.s.p.PersistentSubscription   - [persistent://<topicName1>][<subscriptionName1>] Unable to find position for timestamp 1566439687935. Resetting cursor to first position 25488301:0 in ledger
11:08:08.200 [bookkeeper-ml-workers-OrderedExecutor-22-0] INFO  o.a.pulsar.broker.service.Consumer   - Disconnecting consumer: Consumer{subscription=PersistentSubscription{topic=persistent://<topicName1>, name=<subscriptionName1>}, consumerId=4, consumerName=7740a, address=/<IP>:50796}
11:08:08.200 [bookkeeper-ml-workers-OrderedExecutor-22-0] INFO  o.a.p.b.s.AbstractDispatcherSingleActiveConsumer - Removing consumer Consumer{subscription=PersistentSubscription{topic=persistent://<topicName1>, name=<subscriptionName1>}, consumerId=4, consumerName=7740a, address=/<IP>:50796}
11:08:08.200 [bookkeeper-ml-workers-OrderedExecutor-22-0] INFO  o.a.p.b.s.p.PersistentSubscription   - [persistent://<topicName1>][<subscriptionName1>] Successfully disconnected consumers from subscription, proceeding with cursor reset
11:08:08.200 [bookkeeper-ml-workers-OrderedExecutor-22-0] INFO  o.a.b.mledger.impl.ManagedCursorImpl - [<topicName1>] Initiate reset position to 25488301:0 on cursor <subscriptionName1>
11:08:08.202 [BookKeeperClientWorker-OrderedExecutor-5-0] INFO  o.a.b.mledger.impl.ManagedCursorImpl - [<topicName1>] reset position to 25488301:0 before current read position 26825736:4099 on cursor <subscriptionName1>
11:08:08.202 [pulsar-web-26-32] INFO  o.a.p.b.a.impl.PersistentTopicsBase  - [serviceName1] [persistent://<topicName1>] Reset cursor on subscription <subscriptionName1> to time 1566439687935
11:08:08.301 [ForkJoinPool.commonPool-worker-16] INFO  o.a.pulsar.broker.service.ServerCnx  - [/<IP>:50796] Subscribing on topic persistent://<topicName1> / <subscriptionName1>
11:08:08.301 [ForkJoinPool.commonPool-worker-16] INFO  o.a.b.mledger.impl.ManagedCursorImpl - [<topicName1>-<subscriptionName1>] Rewind from 25488301:0 to 25488301:0
11:08:08.301 [ForkJoinPool.commonPool-worker-16] INFO  o.a.p.b.s.persistent.PersistentTopic - [persistent://<topicName1>][<subscriptionName1>] Created new subscription for 4
11:08:08.301 [ForkJoinPool.commonPool-worker-16] INFO  o.a.pulsar.broker.service.ServerCnx  - [/<IP>:50796] Created subscription on topic persistent://<topicName1> / <subscriptionName1>

11:11:28.788 [pulsar-web-26-14] INFO  o.a.p.b.a.impl.PersistentTopicsBase  - [serviceName1] [persistent://<topicName1>] Received reset cursor on subscription <subscriptionName1> to time 1567390228536
11:11:29.261 [bookkeeper-ml-workers-OrderedExecutor-22-0] INFO  o.a.p.b.s.p.PersistentMessageFinder  - [persistent://<topicName1>][<subscriptionName1>] Found position 26825736:4100 closest to provided timestamp 1567390228536
11:11:29.261 [bookkeeper-ml-workers-OrderedExecutor-22-0] INFO  o.a.pulsar.broker.service.Consumer   - Disconnecting consumer: Consumer{subscription=PersistentSubscription{topic=persistent://<topicName1>, name=<subscriptionName1>}, consumerId=4, consumerName=7740a, address=/<IP>:50796}
11:11:29.261 [bookkeeper-ml-workers-OrderedExecutor-22-0] INFO  o.a.p.b.s.AbstractDispatcherSingleActiveConsumer - Removing consumer Consumer{subscription=PersistentSubscription{topic=persistent://<topicName1>, name=<subscriptionName1>}, consumerId=4, consumerName=7740a, address=/<IP>:50796}
11:11:29.261 [bookkeeper-ml-workers-OrderedExecutor-22-0] INFO  o.a.p.b.s.p.PersistentSubscription   - [persistent://<topicName1>][<subscriptionName1>] Successfully disconnected consumers from subscription, proceeding with cursor reset
11:11:29.261 [bookkeeper-ml-workers-OrderedExecutor-22-0] INFO  o.a.b.mledger.impl.ManagedCursorImpl - [<topicName1>] Initiate reset position to 26825736:4100 on cursor <subscriptionName1>
11:11:29.263 [BookKeeperClientWorker-OrderedExecutor-5-0] INFO  o.a.b.mledger.impl.ManagedCursorImpl - [<topicName1>] reset position to 26825736:4100 skipping from current read position 25488301:7000 on cursor <subscriptionName1>
11:11:29.263 [pulsar-web-26-14] INFO  o.a.p.b.a.impl.PersistentTopicsBase  - [serviceName1] [persistent://<topicName1>] Reset cursor on subscription <subscriptionName1> to time 1567390228536
11:11:29.264 [bookkeeper-ml-workers-OrderedExecutor-22-0] INFO  o.a.b.mledger.impl.ManagedLedgerImpl - [<topicName1>] End TrimConsumedLedgers. ledgers=46 totalSize=925996468
11:11:29.264 [bookkeeper-ml-workers-OrderedExecutor-22-0] INFO  o.a.b.mledger.impl.ManagedLedgerImpl - [<topicName1>] Removing ledger 25488301 - size: 37740040
11:11:29.363 [ForkJoinPool.commonPool-worker-32] INFO  o.a.pulsar.broker.service.ServerCnx  - [/<IP>:50796] Subscribing on topic persistent://<topicName1> / <subscriptionName1>
11:11:29.363 [ForkJoinPool.commonPool-worker-32] INFO  o.a.b.mledger.impl.ManagedCursorImpl - [<topicName1>-<subscriptionName1>] Rewind from 26825736:4100 to 26825736:4100
11:11:29.363 [ForkJoinPool.commonPool-worker-32] INFO  o.a.p.b.s.persistent.PersistentTopic - [persistent://<topicName1>][<subscriptionName1>] Created new subscription for 4
11:11:29.363 [ForkJoinPool.commonPool-worker-32] INFO  o.a.pulsar.broker.service.ServerCnx  - [/<IP>:50796] Created subscription on topic persistent://<topicName1> / <subscriptionName1>

The partitioned topic has 16 partitions, but only one partition has a problem.

Pulsar version broker: 2.3.2

shustsud avatar Sep 17 '19 08:09 shustsud

Seems like a bug which i see different subscription with same mark delete position but different delete count.

@shustsud If you are interested in fixing it, welcome!

codelipenghui avatar Sep 17 '19 11:09 codelipenghui

@codelipenghui thank you for your comment.

Add comments to the ticket if there is additional information.

shustsud avatar Sep 19 '19 02:09 shustsud

I have this issue as well... one of my subscriptions to a partitioned topic is showing a backlog of 1 message, but that is incorrect -- the backlog is actually 0.

Partitioned stats:

{
  "msgRateIn" : 0.0,
  "msgThroughputIn" : 0.0,
  "msgRateOut" : 0.0,
  "msgThroughputOut" : 0.0,
  "averageMsgSize" : 0.0,
  "storageSize" : 2189,
  "publishers" : [ {
    "msgRateIn" : 0.0,
    "msgThroughputIn" : 0.0,
    "averageMsgSize" : 0.0,
    "producerId" : 0
  } ],
  "subscriptions" : {
    "__compaction" : {
      "msgRateOut" : 0.0,
      "msgThroughputOut" : 0.0,
      "msgRateRedeliver" : 0.0,
      "msgBacklog" : 0,
      "blockedSubscriptionOnUnackedMsgs" : false,
      "msgDelayed" : 0,
      "unackedMessages" : 0,
      "msgRateExpired" : 0.0,
      "consumers" : [ ],
      "isReplicated" : false
    },
    "test-xxx" : {
      "msgRateOut" : 0.0,
      "msgThroughputOut" : 0.0,
      "msgRateRedeliver" : 0.0,
      "msgBacklog" : 1,
      "blockedSubscriptionOnUnackedMsgs" : false,
      "msgDelayed" : 0,
      "unackedMessages" : 1,
      "msgRateExpired" : 0.0,
      "consumers" : [ {
        "msgRateOut" : 0.0,
        "msgThroughputOut" : 0.0,
        "msgRateRedeliver" : 0.0,
        "availablePermits" : 998,
        "unackedMessages" : 1,
        "blockedConsumerOnUnackedMsgs" : false
      } ],
      "isReplicated" : false
    }
  },
  "replication" : { },
  "metadata" : {
    "partitions" : 1
  },
  "partitions" : { }
}

and internal stats:

{
  "entriesAddedCounter" : 28,
  "numberOfEntries" : 8,
  "totalSize" : 19297,
  "currentLedgerEntries" : 7,
  "currentLedgerSize" : 17114,
  "lastLedgerCreatedTimestamp" : "2019-10-14T14:46:51.57Z",
  "waitingCursorsCount" : 268,
  "pendingAddEntriesCount" : 0,
  "lastConfirmedEntry" : "81:6",
  "state" : "LedgerOpened",
  "ledgers" : [ {
    "ledgerId" : 81,
    "entries" : 0,
    "size" : 0,
    "offloaded" : false
  } ],
  "cursors" : {
    "__compaction" : {
      "markDeletePosition" : "81:6",
      "readPosition" : "81:7",
      "waitingReadOp" : false,
      "pendingReadOps" : 0,
      "messagesConsumedCounter" : 28,
      "cursorLedger" : 85,
      "cursorLedgerLastEntry" : 3,
      "individuallyDeletedMessages" : "[]",
      "lastLedgerSwitchTimestamp" : "2019-10-15T05:22:53.273Z",
      "state" : "Open",
      "numberOfEntriesSinceFirstNotAckedMessage" : 1,
      "totalNonContiguousDeletedMessagesRange" : 0,
      "properties" : {
        "CompactedTopicLedger" : 86
      }
    },
    "test-xxx" : {
      "markDeletePosition" : "81:6",
      "readPosition" : "81:7",
      "waitingReadOp" : true,
      "pendingReadOps" : 0,
      "messagesConsumedCounter" : 27,
      "cursorLedger" : 84,
      "cursorLedgerLastEntry" : 5,
      "individuallyDeletedMessages" : "[]",
      "lastLedgerSwitchTimestamp" : "2019-10-15T05:19:49.576Z",
      "state" : "Open",
      "numberOfEntriesSinceFirstNotAckedMessage" : 1,
      "totalNonContiguousDeletedMessagesRange" : 0,
      "properties" : { }
    }
  }
}

rocketraman avatar Oct 15 '19 05:10 rocketraman

We are suffering from same problem here, msgBacklog is 40k+ but real msgBacklog is 0. It is annoying cause it'll trigger alert but there isn't any real backlog.

Stats with preciseBacklog=false

{
  "msgRateIn": 0.0,
  "msgThroughputIn": 0.0,
  "msgRateOut": 0.0,
  "msgThroughputOut": 0.0,
  "bytesInCounter": 335230277,
  "msgInCounter": 1584209,
  "bytesOutCounter": 177108372,
  "msgOutCounter": 789829,
  "averageMsgSize": 0.0,
  "msgChunkPublished": false,
  "storageSize": 305110652,
  "backlogSize": 296556524,
  "offloadedStorageSize": 0,
  "lastOffloadLedgerId": 0,
  "lastOffloadSuccessTimeStamp": 0,
  "lastOffloadFailureTimeStamp": 0,
  "publishers": [ ],
  "waitingPublishers": 0,
  "subscriptions": {
    "sub0": {
      "msgRateOut": 0.0,
      "msgThroughputOut": 0.0,
      "bytesOutCounter": 3064627,
      "msgOutCounter": 16150,
      "msgRateRedeliver": 0.0,
      "chunkedMessageRate": 0,
      "msgBacklog": 44708,
      "backlogSize": 0,
      "msgBacklogNoDelayed": 44708,
      "blockedSubscriptionOnUnackedMsgs": false,
      "msgDelayed": 0,
      "unackedMessages": 0,
      "type": "Shared",
      "msgRateExpired": 0.0,
      "totalMsgExpired": 0,
      "lastExpireTimestamp": 0,
      "lastConsumedFlowTimestamp": 1652265631373,
      "lastConsumedTimestamp": 0,
      "lastAckedTimestamp": 0,
      "lastMarkDeleteAdvancedTimestamp": 1652265631403,
      "consumers": [],
      "isDurable": true,
      "isReplicated": false,
      "consumersAfterMarkDeletePosition": {},
      "nonContiguousDeletedMessagesRanges": 0,
      "nonContiguousDeletedMessagesRangesSerializedSize": 60,
      "durable": true,
      "replicated": false
    },
    "sub1": {
      "msgRateOut": 0.0,
      "msgThroughputOut": 0.0,
      "bytesOutCounter": 171894114,
      "msgOutCounter": 761896,
      "msgRateRedeliver": 0.0,
      "chunkedMessageRate": 0,
      "msgBacklog": 0,
      "backlogSize": 0,
      "msgBacklogNoDelayed": 0,
      "blockedSubscriptionOnUnackedMsgs": false,
      "msgDelayed": 0,
      "unackedMessages": 0,
      "type": "Shared",
      "msgRateExpired": 0.0,
      "totalMsgExpired": 0,
      "lastExpireTimestamp": 0,
      "lastConsumedFlowTimestamp": 1652336505371,
      "lastConsumedTimestamp": 1652336498413,
      "lastAckedTimestamp": 1652336512153,
      "lastMarkDeleteAdvancedTimestamp": 1652336512153,
      "consumers": [ ],
      "isDurable": true,
      "isReplicated": false,
      "consumersAfterMarkDeletePosition": {},
      "nonContiguousDeletedMessagesRanges": 0,
      "nonContiguousDeletedMessagesRangesSerializedSize": 22,
      "durable": true,
      "replicated": false
    }
  },
  "replication": {},
  "deduplicationStatus": "Disabled",
  "nonContiguousDeletedMessagesRanges": 0,
  "nonContiguousDeletedMessagesRangesSerializedSize": 82,
  "compaction": {
    "lastCompactionRemovedEventCount": 0,
    "lastCompactionSucceedTimestamp": 0,
    "lastCompactionFailedTimestamp": 0,
    "lastCompactionDurationTimeInMills": 0
  }
}

internal-stats

{
  "waitingCursorsCount": 1,
  "pendingAddEntriesCount": 0,
  "entriesAddedCounter": 1584209,
  "numberOfEntries": 1413448,
  "totalSize": 305110652,
  "currentLedgerEntries": 0,
  "currentLedgerSize": 0,
  "lastLedgerCreatedTimestamp": "2022-05-12T18:04:59.17+08:00",
  "lastLedgerCreationFailureTimestamp": "",
  "lastConfirmedEntry": "114272945:43409",
  "state": "LedgerOpened",
  "ledgers": [
    {
      "ledgerId": 113999206,
      "entries": 50000,
      "size": 8831300,
      "offloaded": false
    },
    ...
    {
      "ledgerId": 114327876,
      "entries": 0,
      "size": 0,
      "offloaded": false
    }
  ],
  "cursors": {
    "sub0": {
      "markDeletePosition": "114272945:43409",
      "readPosition": "114272945:43410",
      "waitingReadOp": false,
      "pendingReadOps": 0,
      "messagesConsumedCounter": 1539501,
      "cursorLedger": 114594694,
      "cursorLedgerLastEntry": 0,
      "individuallyDeletedMessages": "[]",
      "lastLedgerWitchTimestamp": "",
      "state": "Open",
      "numberOfEntriesSinceFirstNotAckedMessage": 1,
      "totalNonContiguousDeletedMessagesRange": 0,
      "properties": {}
    },
    "sub1": {
      "markDeletePosition": "114272945:43409",
      "readPosition": "114272945:43410",
      "waitingReadOp": true,
      "pendingReadOps": 0,
      "messagesConsumedCounter": 1584421,
      "cursorLedger": 114275529,
      "cursorLedgerLastEntry": 16661,
      "individuallyDeletedMessages": "[]",
      "lastLedgerWitchTimestamp": "",
      "state": "Open",
      "numberOfEntriesSinceFirstNotAckedMessage": 1,
      "totalNonContiguousDeletedMessagesRange": 0,
      "properties": {}
    }
  }
}

Shawyeok avatar May 13 '22 10:05 Shawyeok

image image same problem~ Is there any progress on this issue?

M4zfw avatar Aug 01 '23 09:08 M4zfw

Possible fixed in #19275

Shawyeok avatar Aug 22 '23 09:08 Shawyeok

Noting this still in 3.0.4 "Message expiry failed - mark delete failed" is all I see during this period. It resolved on its own later.

For a period the backlog reported was 30K+. Initially there were a lot of messages that were negative acked due to an error in business logic. During this period, the ledger count was higher and hence the storage use. Once the logic was fixed, and the messages acknowledged, all the acked ledgers were deleted and there was only 1 ledger (apart from a short duration where ledger rollover was happening). But the backlog still showed over 29K messages.

Stats and internal-stats are below:

{
  "msgRateIn" : 102.44011011273342,
  "msgThroughputIn" : 104575.97653959044,
  "msgRateOut" : 93.33330724467397,
  "msgThroughputOut" : 95281.69003323553,
  "bytesInCounter" : 312203304,
  "msgInCounter" : 305803,
  "bytesOutCounter" : 313735454,
  "msgOutCounter" : 307300,
  "averageMsgSize" : 1020.8499036608467,
  "msgChunkPublished" : false,
  "storageSize" : 56962157,
  "backlogSize" : 31135757,
  "publishRateLimitedTimes" : 0,
  "earliestMsgPublishTimeInBacklogs" : 0,
  "offloadedStorageSize" : 0,
  "lastOffloadLedgerId" : 0,
  "lastOffloadSuccessTimeStamp" : 0,
  "lastOffloadFailureTimeStamp" : 0,
  "ongoingTxnCount" : 0,
  "abortedTxnCount" : 0,
  "committedTxnCount" : 0,
  "publishers" : [ {
    "accessMode" : "Shared",
    "msgRateIn" : 17.89013721314165,
    "msgThroughputIn" : 18265.187537704485,
    "averageMsgSize" : 1020.9640831758034,
    "chunkedMessageRate" : 0.0,
    "producerId" : 0,
    "supportsPartialProducer" : false,
    "metadata" : { },
    "address" : "/10.0.110.221:39152",
    "producerName" : "pulsarv3-110-1933300",
    "connectedSince" : "2025-05-14T14:41:56.242403726Z",
    "clientVersion" : "Pulsar-Java-v3.0.4"
  }, {
    "accessMode" : "Shared",
    "msgRateIn" : 11.46666303651226,
    "msgThroughputIn" : 11708.379626655484,
    "averageMsgSize" : 1021.0799418604652,
    "chunkedMessageRate" : 0.0,
    "producerId" : 0,
    "supportsPartialProducer" : false,
    "metadata" : { },
    "address" : "/10.0.113.3:55052",
    "producerName" : "pulsarv3-110-1933405",
    "connectedSince" : "2025-05-14T13:55:14.451931493Z",
    "clientVersion" : "Pulsar-Java-v3.0.4"
  }, {
    "accessMode" : "Shared",
    "msgRateIn" : 12.166662477887554,
    "msgThroughputIn" : 12422.845723021264,
    "averageMsgSize" : 1021.0561643835616,
    "chunkedMessageRate" : 0.0,
    "producerId" : 0,
    "supportsPartialProducer" : false,
    "metadata" : { },
    "address" : "/10.0.113.3:52944",
    "producerName" : "pulsarv3-110-1933792",
    "connectedSince" : "2025-05-14T13:56:45.205322598Z",
    "clientVersion" : "Pulsar-Java-v3.0.4"
  }, {
    "accessMode" : "Shared",
    "msgRateIn" : 17.249995024526434,
    "msgThroughputIn" : 17614.011586198594,
    "averageMsgSize" : 1021.1024154589372,
    "chunkedMessageRate" : 0.0,
    "producerId" : 0,
    "supportsPartialProducer" : false,
    "metadata" : { },
    "address" : "/10.0.115.72:37164",
    "producerName" : "pulsarv3-110-1933795",
    "connectedSince" : "2025-05-14T13:53:12.67418339Z",
    "clientVersion" : "Pulsar-Java-v3.0.4"
  }, {
    "accessMode" : "Shared",
    "msgRateIn" : 15.499994833851723,
    "msgThroughputIn" : 15826.544725012644,
    "averageMsgSize" : 1021.0677419354839,
    "chunkedMessageRate" : 0.0,
    "producerId" : 0,
    "supportsPartialProducer" : false,
    "metadata" : { },
    "address" : "/10.0.104.252:50390",
    "producerName" : "pulsarv3-110-1933857",
    "connectedSince" : "2025-05-14T14:30:18.209601969Z",
    "clientVersion" : "Pulsar-Java-v3.0.4"
  }, {
    "accessMode" : "Shared",
    "msgRateIn" : 7.316664199365555,
    "msgThroughputIn" : 7470.814147383622,
    "averageMsgSize" : 1021.0683371298405,
    "chunkedMessageRate" : 0.0,
    "producerId" : 0,
    "supportsPartialProducer" : false,
    "metadata" : { },
    "address" : "/10.0.113.3:56828",
    "producerName" : "pulsarv3-110-1933907",
    "connectedSince" : "2025-05-14T14:01:24.254640666Z",
    "clientVersion" : "Pulsar-Java-v3.0.4"
  }, {
    "accessMode" : "Shared",
    "msgRateIn" : 11.116662853280753,
    "msgThroughputIn" : 11339.612776801498,
    "averageMsgSize" : 1020.0554722638681,
    "chunkedMessageRate" : 0.0,
    "producerId" : 0,
    "supportsPartialProducer" : false,
    "metadata" : { },
    "address" : "/10.0.110.221:57702",
    "producerName" : "pulsarv3-110-1933919",
    "connectedSince" : "2025-05-14T14:40:23.091462441Z",
    "clientVersion" : "Pulsar-Java-v3.0.4"
  }, {
    "accessMode" : "Shared",
    "msgRateIn" : 9.733330474167508,
    "msgThroughputIn" : 9928.580416812836,
    "averageMsgSize" : 1020.0599315068494,
    "chunkedMessageRate" : 0.0,
    "producerId" : 0,
    "supportsPartialProducer" : false,
    "metadata" : { },
    "address" : "/10.0.113.3:44980",
    "producerName" : "pulsarv3-110-1933976",
    "connectedSince" : "2025-05-14T14:10:19.222079521Z",
    "clientVersion" : "Pulsar-Java-v3.0.4"
  } ],
  "waitingPublishers" : 0,
  "subscriptions" : {
    "some-integration" : {
      "msgRateOut" : 93.33330724467397,
      "msgThroughputOut" : 95281.69003323553,
      "bytesOutCounter" : 313735454,
      "msgOutCounter" : 307300,
      "msgRateRedeliver" : 0.0,
      "messageAckRate" : 93.34997371399047,
      "chunkedMessageRate" : 0,
      "msgBacklog" : 28910,
      "backlogSize" : 31135757,
      "earliestMsgPublishTimeInBacklog" : 0,
      "msgBacklogNoDelayed" : 28910,
      "blockedSubscriptionOnUnackedMsgs" : false,
      "msgDelayed" : 0,
      "unackedMessages" : 2629,
      "type" : "Shared",
      "msgRateExpired" : 0.0,
      "totalMsgExpired" : 0,
      "lastExpireTimestamp" : 1747233685821,
      "lastConsumedFlowTimestamp" : 1747233767601,
      "lastConsumedTimestamp" : 1747233767604,
      "lastAckedTimestamp" : 1747233767815,
      "lastMarkDeleteAdvancedTimestamp" : 1747233767815,
      "consumers" : [ {
        "msgRateOut" : 4.166665486042001,
        "msgThroughputOut" : 4285.482119041974,
        "bytesOutCounter" : 16690589,
        "msgOutCounter" : 16350,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 4.29999879062534,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "29105",
        "availablePermits" : 0,
        "unackedMessages" : 150,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233749609,
        "lastConsumedTimestamp" : 1747233749285,
        "lastConsumedFlowTimestamp" : 1747233749283,
        "metadata" : { },
        "address" : "/10.0.111.162:42804",
        "connectedSince" : "2025-05-14T13:07:14.334543814Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:29.609Z",
        "lastConsumedTime" : "2025-05-14T14:42:29.285Z"
      }, {
        "msgRateOut" : 4.999998597250394,
        "msgThroughputOut" : 5102.1652352542105,
        "bytesOutCounter" : 22146164,
        "msgOutCounter" : 21700,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 4.8666652902926115,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "9b01a",
        "availablePermits" : 0,
        "unackedMessages" : 200,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233761513,
        "lastConsumedTimestamp" : 1747233761367,
        "lastConsumedFlowTimestamp" : 1747233761365,
        "metadata" : { },
        "address" : "/10.0.110.221:34324",
        "connectedSince" : "2025-05-14T13:07:14.33467069Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:41.513Z",
        "lastConsumedTime" : "2025-05-14T14:42:41.367Z"
      }, {
        "msgRateOut" : 5.833331656833815,
        "msgThroughputOut" : 5952.664955870759,
        "bytesOutCounter" : 22265676,
        "msgOutCounter" : 21800,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 5.38333178580489,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "e88e1",
        "availablePermits" : 0,
        "unackedMessages" : 155,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233767802,
        "lastConsumedTimestamp" : 1747233762246,
        "lastConsumedFlowTimestamp" : 1747233762244,
        "metadata" : { },
        "address" : "/10.0.111.162:42804",
        "connectedSince" : "2025-05-14T13:07:14.33471159Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:47.802Z",
        "lastConsumedTime" : "2025-05-14T14:42:42.246Z"
      }, {
        "msgRateOut" : 4.999998627417043,
        "msgThroughputOut" : 5101.781932809163,
        "bytesOutCounter" : 22591131,
        "msgOutCounter" : 22100,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 5.549998484202914,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "df3c0",
        "availablePermits" : 0,
        "unackedMessages" : 200,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233766082,
        "lastConsumedTimestamp" : 1747233765948,
        "lastConsumedFlowTimestamp" : 1747233765946,
        "metadata" : { },
        "address" : "/10.0.115.72:54992",
        "connectedSince" : "2025-05-14T13:07:14.334744147Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:46.082Z",
        "lastConsumedTime" : "2025-05-14T14:42:45.948Z"
      }, {
        "msgRateOut" : 4.166665554305853,
        "msgThroughputOut" : 4251.482198329302,
        "bytesOutCounter" : 16228826,
        "msgOutCounter" : 15900,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 4.149998881644468,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "5d495",
        "availablePermits" : 0,
        "unackedMessages" : 148,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233767747,
        "lastConsumedTimestamp" : 1747233750356,
        "lastConsumedFlowTimestamp" : 1747233750354,
        "metadata" : { },
        "address" : "/10.0.111.162:52204",
        "connectedSince" : "2025-05-14T13:07:14.334805246Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:47.747Z",
        "lastConsumedTime" : "2025-05-14T14:42:30.356Z"
      }, {
        "msgRateOut" : 4.999998666750356,
        "msgThroughputOut" : 5099.648640178691,
        "bytesOutCounter" : 22808357,
        "msgOutCounter" : 22350,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 5.399998560540384,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "671f1",
        "availablePermits" : 0,
        "unackedMessages" : 195,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233767790,
        "lastConsumedTimestamp" : 1747233766487,
        "lastConsumedFlowTimestamp" : 1747233766485,
        "metadata" : { },
        "address" : "/10.0.115.72:47958",
        "connectedSince" : "2025-05-14T13:07:14.334845489Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:47.79Z",
        "lastConsumedTime" : "2025-05-14T14:42:46.487Z"
      }, {
        "msgRateOut" : 3.333332448444679,
        "msgThroughputOut" : 3398.9324310300703,
        "bytesOutCounter" : 16998991,
        "msgOutCounter" : 16650,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 3.566665710324701,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "796a8",
        "availablePermits" : 0,
        "unackedMessages" : 193,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233767681,
        "lastConsumedTimestamp" : 1747233767604,
        "lastConsumedFlowTimestamp" : 1747233767601,
        "metadata" : { },
        "address" : "/10.0.115.72:54992",
        "connectedSince" : "2025-05-14T13:07:14.334880431Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:47.681Z",
        "lastConsumedTime" : "2025-05-14T14:42:47.604Z"
      }, {
        "msgRateOut" : 4.166665552430853,
        "msgThroughputOut" : 4264.415526290881,
        "bytesOutCounter" : 17149360,
        "msgOutCounter" : 16800,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 4.16666555048641,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "5e507",
        "availablePermits" : 0,
        "unackedMessages" : 150,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233757987,
        "lastConsumedTimestamp" : 1747233753115,
        "lastConsumedFlowTimestamp" : 1747233753113,
        "metadata" : { },
        "address" : "/10.0.115.72:47958",
        "connectedSince" : "2025-05-14T13:07:14.334917269Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:37.987Z",
        "lastConsumedTime" : "2025-05-14T14:42:33.115Z"
      }, {
        "msgRateOut" : 5.833331769028197,
        "msgThroughputOut" : 5949.631737840422,
        "bytesOutCounter" : 21649633,
        "msgOutCounter" : 21200,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 5.683331809821519,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "db285",
        "availablePermits" : 0,
        "unackedMessages" : 200,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233767556,
        "lastConsumedTimestamp" : 1747233767368,
        "lastConsumedFlowTimestamp" : 1747233767366,
        "metadata" : { },
        "address" : "/10.0.111.162:52204",
        "connectedSince" : "2025-05-14T13:07:14.334951884Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:47.556Z",
        "lastConsumedTime" : "2025-05-14T14:42:47.368Z"
      }, {
        "msgRateOut" : 3.3333324497780117,
        "msgThroughputOut" : 3401.932431594443,
        "bytesOutCounter" : 16685033,
        "msgOutCounter" : 16350,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 3.3333324479446795,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "c232b",
        "availablePermits" : 0,
        "unackedMessages" : 151,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233767815,
        "lastConsumedTimestamp" : 1747233764609,
        "lastConsumedFlowTimestamp" : 1747233764607,
        "metadata" : { },
        "address" : "/10.0.110.221:34324",
        "connectedSince" : "2025-05-14T13:07:14.334981621Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:47.815Z",
        "lastConsumedTime" : "2025-05-14T14:42:44.609Z"
      }, {
        "msgRateOut" : 4.999998699917005,
        "msgThroughputOut" : 5102.148673356309,
        "bytesOutCounter" : 11687381,
        "msgOutCounter" : 11450,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 4.216665565273621,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "5e9d0",
        "availablePermits" : 0,
        "unackedMessages" : 71,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233767650,
        "lastConsumedTimestamp" : 1747233760566,
        "lastConsumedFlowTimestamp" : 1747233760564,
        "metadata" : { },
        "address" : "/10.0.110.221:46828",
        "connectedSince" : "2025-05-14T13:35:52.143814278Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:47.65Z",
        "lastConsumedTime" : "2025-05-14T14:42:40.566Z"
      }, {
        "msgRateOut" : 4.1666655689586225,
        "msgThroughputOut" : 4251.8155465258615,
        "bytesOutCounter" : 11637211,
        "msgOutCounter" : 11400,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 4.249998884091959,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "52dbd",
        "availablePermits" : 0,
        "unackedMessages" : 100,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233751042,
        "lastConsumedTimestamp" : 1747233750947,
        "lastConsumedFlowTimestamp" : 1747233750944,
        "metadata" : { },
        "address" : "/10.0.110.221:46828",
        "connectedSince" : "2025-05-14T13:35:53.543141003Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:31.042Z",
        "lastConsumedTime" : "2025-05-14T14:42:30.947Z"
      }, {
        "msgRateOut" : 4.166665565347513,
        "msgThroughputOut" : 4252.315542708797,
        "bytesOutCounter" : 12148042,
        "msgOutCounter" : 11900,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 4.0833322320586305,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "d61d3",
        "availablePermits" : 0,
        "unackedMessages" : 72,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233767746,
        "lastConsumedTimestamp" : 1747233754255,
        "lastConsumedFlowTimestamp" : 1747233754253,
        "metadata" : { },
        "address" : "/10.0.110.221:35714",
        "connectedSince" : "2025-05-14T13:36:06.73136924Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:47.746Z",
        "lastConsumedTime" : "2025-05-14T14:42:34.255Z"
      }, {
        "msgRateOut" : 4.999998623333712,
        "msgThroughputOut" : 5101.748595318553,
        "bytesOutCounter" : 12152809,
        "msgOutCounter" : 11900,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 4.999998595417061,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "1ea69",
        "availablePermits" : 0,
        "unackedMessages" : 100,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233764944,
        "lastConsumedTimestamp" : 1747233764793,
        "lastConsumedFlowTimestamp" : 1747233764791,
        "metadata" : { },
        "address" : "/10.0.110.221:35714",
        "connectedSince" : "2025-05-14T13:36:07.427517134Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:44.944Z",
        "lastConsumedTime" : "2025-05-14T14:42:44.793Z"
      }, {
        "msgRateOut" : 4.999998594500394,
        "msgThroughputOut" : 5102.515232349635,
        "bytesOutCounter" : 11736173,
        "msgOutCounter" : 11500,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 4.99999856266708,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "e66b5",
        "availablePermits" : 0,
        "unackedMessages" : 100,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233764681,
        "lastConsumedTimestamp" : 1747233764496,
        "lastConsumedFlowTimestamp" : 1747233764493,
        "metadata" : { },
        "address" : "/10.0.110.221:40046",
        "connectedSince" : "2025-05-14T13:36:28.590397687Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:44.681Z",
        "lastConsumedTime" : "2025-05-14T14:42:44.496Z"
      }, {
        "msgRateOut" : 4.999998552833752,
        "msgThroughputOut" : 5101.781856707605,
        "bytesOutCounter" : 11635910,
        "msgOutCounter" : 11400,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 5.033331857308766,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "5002e",
        "availablePermits" : 0,
        "unackedMessages" : 73,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233767785,
        "lastConsumedTimestamp" : 1747233749651,
        "lastConsumedFlowTimestamp" : 1747233749649,
        "metadata" : { },
        "address" : "/10.0.110.221:40046",
        "connectedSince" : "2025-05-14T13:36:29.282827545Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:47.785Z",
        "lastConsumedTime" : "2025-05-14T14:42:29.651Z"
      }, {
        "msgRateOut" : 4.9999985284171,
        "msgThroughputOut" : 5102.881831470162,
        "bytesOutCounter" : 11744594,
        "msgOutCounter" : 11500,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 4.333332038750386,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "500b4",
        "availablePermits" : 0,
        "unackedMessages" : 100,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233756220,
        "lastConsumedTimestamp" : 1747233756074,
        "lastConsumedFlowTimestamp" : 1747233756072,
        "metadata" : { },
        "address" : "/10.0.113.3:53414",
        "connectedSince" : "2025-05-14T13:36:51.290648375Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:36.22Z",
        "lastConsumedTime" : "2025-05-14T14:42:36.074Z"
      }, {
        "msgRateOut" : 4.1666654020837175,
        "msgThroughputOut" : 4251.7820429174835,
        "bytesOutCounter" : 11691956,
        "msgOutCounter" : 11450,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 4.949998492560459,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "b2581",
        "availablePermits" : 0,
        "unackedMessages" : 77,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233767690,
        "lastConsumedTimestamp" : 1747233761992,
        "lastConsumedFlowTimestamp" : 1747233761990,
        "metadata" : { },
        "address" : "/10.0.113.3:53414",
        "connectedSince" : "2025-05-14T13:36:52.102476053Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:47.69Z",
        "lastConsumedTime" : "2025-05-14T14:42:41.992Z"
      }, {
        "msgRateOut" : 4.9999984757504645,
        "msgThroughputOut" : 5102.148444610047,
        "bytesOutCounter" : 12041315,
        "msgOutCounter" : 11800,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 4.999998441667152,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "9dd56",
        "availablePermits" : 0,
        "unackedMessages" : 94,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233767681,
        "lastConsumedTimestamp" : 1747233755665,
        "lastConsumedFlowTimestamp" : 1747233755663,
        "metadata" : { },
        "address" : "/10.0.104.252:51760",
        "connectedSince" : "2025-05-14T13:37:05.978420631Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:47.681Z",
        "lastConsumedTime" : "2025-05-14T14:42:35.665Z"
      }, {
        "msgRateOut" : 4.999998425250496,
        "msgThroughputOut" : 5104.415059031144,
        "bytesOutCounter" : 12046303,
        "msgOutCounter" : 11800,
        "msgRateRedeliver" : 0.0,
        "messageAckRate" : 5.083331732507449,
        "chunkedMessageRate" : 0.0,
        "consumerName" : "d6279",
        "availablePermits" : 0,
        "unackedMessages" : 100,
        "avgMessagesPerEntry" : 1,
        "blockedConsumerOnUnackedMsgs" : false,
        "lastAckedTimestamp" : 1747233766480,
        "lastConsumedTimestamp" : 1747233766275,
        "lastConsumedFlowTimestamp" : 1747233766273,
        "metadata" : { },
        "address" : "/10.0.104.252:51760",
        "connectedSince" : "2025-05-14T13:37:07.479324256Z",
        "clientVersion" : "Pulsar-Java-v3.0.4",
        "lastAckedTime" : "2025-05-14T14:42:46.48Z",
        "lastConsumedTime" : "2025-05-14T14:42:46.275Z"
      } ],
      "isDurable" : true,
      "isReplicated" : false,
      "allowOutOfOrderDelivery" : false,
      "consumersAfterMarkDeletePosition" : { },
      "nonContiguousDeletedMessagesRanges" : 18,
      "nonContiguousDeletedMessagesRangesSerializedSize" : 380,
      "delayedMessageIndexSizeInBytes" : 0,
      "subscriptionProperties" : { },
      "filterProcessedMsgCount" : 0,
      "filterAcceptedMsgCount" : 0,
      "filterRejectedMsgCount" : 0,
      "filterRescheduledMsgCount" : 0,
      "durable" : true,
      "replicated" : false
    }
  },
  "replication" : { },
  "deduplicationStatus" : "Disabled",
  "nonContiguousDeletedMessagesRanges" : 18,
  "nonContiguousDeletedMessagesRangesSerializedSize" : 380,
  "delayedMessageIndexSizeInBytes" : 0,
  "compaction" : {
    "lastCompactionRemovedEventCount" : 0,
    "lastCompactionSucceedTimestamp" : 0,
    "lastCompactionFailedTimestamp" : 0,
    "lastCompactionDurationTimeInMills" : 0
  },
  "ownerBroker" : "pulsarv3-broker-0.pulsarv3-broker.pulsarv3.svc.cluster.local:8080"
}
{
    "entriesAddedCounter" : 295779,
    "numberOfEntries" : 45779,
    "totalSize" : 46730622,
    "currentLedgerEntries" : 45779,
    "currentLedgerSize" : 46730622,
    "lastLedgerCreatedTimestamp" : "2025-05-14T14:25:06.67Z",
    "waitingCursorsCount" : 0,
    "pendingAddEntriesCount" : 0,
    "lastConfirmedEntry" : "1414729:45778",
    "state" : "LedgerOpened",
    "ledgers" : [ {
      "ledgerId" : 1414729,
      "entries" : 0,
      "size" : 0,
      "offloaded" : false,
      "underReplicated" : false
    } ],
    "cursors" : {
      "some-integration" : {
        "markDeletePosition" : "1414729:14902",
        "readPosition" : "1414729:19471",
        "waitingReadOp" : false,
        "pendingReadOps" : 0,
        "messagesConsumedCounter" : 266871,
        "cursorLedger" : 1414502,
        "cursorLedgerLastEntry" : 5610,
        "individuallyDeletedMessages" : "[(1414729:14920..1414729:15270],(1414729:15320..1414729:15903],(1414729:15920..1414729:16323],(1414729:16420..1414729:16470],(1414729:16520..1414729:16533],(1414729:16570..1414729:16720],(1414729:16820..1414729:16930],(1414729:16970..1414729:17020],(1414729:17070..1414729:17118],(1414729:17270..1414729:17320],(1414729:17420..1414729:17469],(1414729:17470..1414729:17552],(1414729:17820..1414729:17834],(1414729:17970..1414729:17986]]",
        "lastLedgerSwitchTimestamp" : "2025-05-14T13:07:14.328Z",
        "state" : "Open",
        "active" : false,
        "numberOfEntriesSinceFirstNotAckedMessage" : 4569,
        "totalNonContiguousDeletedMessagesRange" : 14,
        "subscriptionHavePendingRead" : false,
        "subscriptionHavePendingReplayRead" : false,
        "properties" : { }
      }
    },
    "schemaLedgers" : [ ],
    "compactedLedger" : {
      "ledgerId" : -1,
      "entries" : -1,
      "size" : -1,
      "offloaded" : false,
      "underReplicated" : false
    }
}

The dashboard screenshot shows a drop in storage usage when the issue was resolved but the backlog numbers remained high.

Image

danielnesaraj avatar May 15 '25 08:05 danielnesaraj

@danielnesaraj msgBacklog is currently an estimated value as described in #6045, perhaps docs should explain this too. If you need accurate values, there's --get-precise-backlog option for topic stats and exposePreciseBacklogInPrometheus=true for prometheus topic metrics. This might come with an additional cost which you would have to test in your environment.

The relevant code that differs can be seen here:

https://github.com/apache/pulsar/blob/616c3a1b2b731f5c15fef0d34670845510a5fdf0/managed-ledger/src/main/java/org/apache/bookkeeper/mledger/impl/ManagedCursorImpl.java#L1202-L1220

https://github.com/apache/pulsar/blob/616c3a1b2b731f5c15fef0d34670845510a5fdf0/managed-ledger/src/main/java/org/apache/bookkeeper/mledger/impl/ManagedCursorImpl.java#L1195-L1200

https://github.com/apache/pulsar/blob/616c3a1b2b731f5c15fef0d34670845510a5fdf0/managed-ledger/src/main/java/org/apache/bookkeeper/mledger/impl/ManagedCursorImpl.java#L1680-L1727

lhotari avatar May 19 '25 16:05 lhotari

Thank you @lhotari ! I did come across the exposePreciseBacklogInPrometheus config when I was going through the code. I will investigate this.

danielnesaraj avatar May 23 '25 08:05 danielnesaraj