codelipenghui opened a new pull request #5894: [hot-fix]Fix potential read 0 entries cause dispatcher stop dispatch URL: https://github.com/apache/pulsar/pull/5894 ### Motivation Fix topic stop dispatch messages to consumers after read or replay 0 entries from bookie Here is the topic stats and internal stats: ```json { "msgRateIn" : 231.6668315416007, "msgThroughputIn" : 62304.81100356746, "msgRateOut" : 0.0, "msgThroughputOut" : 0.0, "averageMsgSize" : 268.94143882819634, "storageSize" : 5353680152, "backlogSize" : 2293765539, "publishers" : [ { "msgRateIn" : 13.666676654501744, "msgThroughputIn" : 3648.502666386557, "averageMsgSize" : 266.0, "producerId" : 1, "metadata" : { }, "producerName" : "pulsar-cluster-gz-tencent-0-33", "connectedSince" : "2019-12-18T16:28:05.043+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.54.106:56772" }, { "msgRateIn" : 32.66669035219495, "msgThroughputIn" : 8777.806364494802, "averageMsgSize" : 268.0, "producerId" : 1, "metadata" : { }, "producerName" : "pulsar-cluster-gz-tencent-0-39", "connectedSince" : "2019-12-18T16:28:04.987+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.39.73:51922" }, { "msgRateIn" : 32.66669006799454, "msgThroughputIn" : 8862.206348589221, "averageMsgSize" : 271.0, "producerId" : 1, "metadata" : { }, "producerName" : "pulsar-cluster-gz-tencent-0-40", "connectedSince" : "2019-12-18T16:28:04.991+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.109.208:48844" }, { "msgRateIn" : 32.66668995638327, "msgThroughputIn" : 8566.072773848251, "averageMsgSize" : 262.0, "producerId" : 1, "metadata" : { }, "producerName" : "pulsar-cluster-gz-tencent-0-37", "connectedSince" : "2019-12-18T16:28:04.987+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.45.83:51648" }, { "msgRateIn" : 13.666676315567923, "msgThroughputIn" : 3927.4027728118144, "averageMsgSize" : 287.0, "producerId" : 1, "metadata" : { }, "producerName" : "pulsar-cluster-gz-tencent-0-30", "connectedSince" : "2019-12-18T16:28:04.991+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.90.118:57522" }, { "msgRateIn" : 13.666676282540099, "msgThroughputIn" : 3920.436091752167, "averageMsgSize" : 286.0, "producerId" : 1, "metadata" : { }, "producerName" : "pulsar-cluster-gz-tencent-0-31", "connectedSince" : "2019-12-18T16:28:04.991+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.34.177:59462" }, { "msgRateIn" : 13.66667625976229, "msgThroughputIn" : 3840.8693627009015, "averageMsgSize" : 281.0, "producerId" : 1, "metadata" : { }, "producerName" : "pulsar-cluster-gz-tencent-0-34", "connectedSince" : "2019-12-18T16:28:04.991+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.85.194:59974" }, { "msgRateIn" : 13.666676221723346, "msgThroughputIn" : 3913.902736405098, "averageMsgSize" : 286.0, "producerId" : 1, "metadata" : { }, "producerName" : "pulsar-cluster-gz-tencent-0-32", "connectedSince" : "2019-12-18T16:28:04.99+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.27.60:50226" }, { "msgRateIn" : 32.66668975384965, "msgThroughputIn" : 8136.522417153886, "averageMsgSize" : 249.0, "producerId" : 1, "metadata" : { }, "producerName" : "pulsar-cluster-gz-tencent-0-38", "connectedSince" : "2019-12-18T16:28:04.991+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.27.210:35402" }, { "msgRateIn" : 32.66668967708288, "msgThroughputIn" : 8711.089469424756, "averageMsgSize" : 266.0, "producerId" : 1, "metadata" : { }, "producerName" : "pulsar-cluster-gz-tencent-0-41", "connectedSince" : "2019-12-18T16:28:04.99+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.11.34:39868" } ], "subscriptions" : { "metrics-report" : { "msgRateOut" : 0.0, "msgThroughputOut" : 0.0, "msgRateRedeliver" : 0.0, "msgBacklog" : 8273844, "blockedSubscriptionOnUnackedMsgs" : false, "msgDelayed" : 0, "unackedMessages" : 0, "type" : "Shared", "msgRateExpired" : 0.003333398671602924, "consumers" : [ { "msgRateOut" : 0.0, "msgThroughputOut" : 0.0, "msgRateRedeliver" : 0.0, "consumerName" : "4f619", "availablePermits" : 1238, "unackedMessages" : 0, "blockedConsumerOnUnackedMsgs" : false, "metadata" : { }, "connectedSince" : "2019-12-18T16:28:04.996+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.18.155:33928" }, { "msgRateOut" : 0.0, "msgThroughputOut" : 0.0, "msgRateRedeliver" : 0.0, "consumerName" : "cd8d2", "availablePermits" : 1499, "unackedMessages" : 0, "blockedConsumerOnUnackedMsgs" : false, "metadata" : { }, "connectedSince" : "2019-12-18T16:28:05.042+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.18.155:33928" }, { "msgRateOut" : 0.0, "msgThroughputOut" : 0.0, "msgRateRedeliver" : 0.0, "consumerName" : "ea6bd", "availablePermits" : 1185, "unackedMessages" : 0, "blockedConsumerOnUnackedMsgs" : false, "metadata" : { }, "connectedSince" : "2019-12-18T16:28:05.043+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.48.189:51814" }, { "msgRateOut" : 0.0, "msgThroughputOut" : 0.0, "msgRateRedeliver" : 0.0, "consumerName" : "00538", "availablePermits" : 1796, "unackedMessages" : 0, "blockedConsumerOnUnackedMsgs" : false, "metadata" : { }, "connectedSince" : "2019-12-18T16:28:05.044+08:00", "clientVersion" : "2.4.2", "address" : "/10.205.48.189:51814" } ], "isReplicated" : false } }, "replication" : { }, "deduplicationStatus" : "Disabled" } ``` ```json { "entriesAddedCounter" : 13781240, "numberOfEntries" : 19316859, "totalSize" : 5356151463, "currentLedgerEntries" : 61403, "currentLedgerSize" : 16997235, "lastLedgerCreatedTimestamp" : "2019-12-19T09:28:37.573+08:00", "waitingCursorsCount" : 0, "pendingAddEntriesCount" : 34, "lastConfirmedEntry" : "529:61368", "state" : "LedgerOpened", "ledgers" : [ { "ledgerId" : 359, "entries" : 120899, "size" : 33537519, "offloaded" : false }, { "ledgerId" : 360, "entries" : 131621, "size" : 36492727, "offloaded" : false }, { "ledgerId" : 363, "entries" : 72643, "size" : 20087043, "offloaded" : false }, { "ledgerId" : 364, "entries" : 131744, "size" : 36528233, "offloaded" : false }, { "ledgerId" : 366, "entries" : 131400, "size" : 36432940, "offloaded" : false }, { "ledgerId" : 367, "entries" : 131785, "size" : 36539047, "offloaded" : false }, { "ledgerId" : 368, "entries" : 131592, "size" : 36482286, "offloaded" : false }, { "ledgerId" : 369, "entries" : 131445, "size" : 36444679, "offloaded" : false }, { "ledgerId" : 370, "entries" : 131624, "size" : 36504410, "offloaded" : false }, { "ledgerId" : 371, "entries" : 130645, "size" : 36231191, "offloaded" : false }, { "ledgerId" : 372, "entries" : 130996, "size" : 36326816, "offloaded" : false }, { "ledgerId" : 373, "entries" : 131044, "size" : 36351467, "offloaded" : false }, { "ledgerId" : 375, "entries" : 131053, "size" : 36350878, "offloaded" : false }, { "ledgerId" : 376, "entries" : 130903, "size" : 36310763, "offloaded" : false }, { "ledgerId" : 377, "entries" : 130976, "size" : 36328038, "offloaded" : false }, { "ledgerId" : 378, "entries" : 131002, "size" : 36330921, "offloaded" : false }, { "ledgerId" : 379, "entries" : 131120, "size" : 36370705, "offloaded" : false }, { "ledgerId" : 380, "entries" : 130967, "size" : 36322602, "offloaded" : false }, { "ledgerId" : 381, "entries" : 130835, "size" : 36300058, "offloaded" : false }, { "ledgerId" : 382, "entries" : 131196, "size" : 36397872, "offloaded" : false }, { "ledgerId" : 383, "entries" : 130972, "size" : 36340551, "offloaded" : false }, { "ledgerId" : 384, "entries" : 131092, "size" : 36374984, "offloaded" : false }, { "ledgerId" : 385, "entries" : 130632, "size" : 36234576, "offloaded" : false }, { "ledgerId" : 386, "entries" : 131074, "size" : 36362165, "offloaded" : false }, { "ledgerId" : 387, "entries" : 130854, "size" : 36294119, "offloaded" : false }, { "ledgerId" : 388, "entries" : 130889, "size" : 36302291, "offloaded" : false }, { "ledgerId" : 389, "entries" : 131602, "size" : 36503883, "offloaded" : false }, { "ledgerId" : 391, "entries" : 130826, "size" : 36277953, "offloaded" : false }, { "ledgerId" : 393, "entries" : 130757, "size" : 36275478, "offloaded" : false }, { "ledgerId" : 394, "entries" : 131225, "size" : 36406255, "offloaded" : false }, { "ledgerId" : 395, "entries" : 130976, "size" : 36338946, "offloaded" : false }, { "ledgerId" : 396, "entries" : 130992, "size" : 36342660, "offloaded" : false }, { "ledgerId" : 397, "entries" : 131296, "size" : 36409977, "offloaded" : false }, { "ledgerId" : 398, "entries" : 131427, "size" : 36467874, "offloaded" : false }, { "ledgerId" : 399, "entries" : 131073, "size" : 36363489, "offloaded" : false }, { "ledgerId" : 402, "entries" : 131680, "size" : 36505224, "offloaded" : false }, { "ledgerId" : 403, "entries" : 131229, "size" : 36393385, "offloaded" : false }, { "ledgerId" : 404, "entries" : 132303, "size" : 36668216, "offloaded" : false }, { "ledgerId" : 405, "entries" : 131959, "size" : 36581524, "offloaded" : false }, { "ledgerId" : 406, "entries" : 131636, "size" : 36489010, "offloaded" : false }, { "ledgerId" : 407, "entries" : 132227, "size" : 36649507, "offloaded" : false }, { "ledgerId" : 408, "entries" : 132029, "size" : 36596043, "offloaded" : false }, { "ledgerId" : 409, "entries" : 91379, "size" : 25325201, "offloaded" : false }, { "ledgerId" : 412, "entries" : 131861, "size" : 36547936, "offloaded" : false }, { "ledgerId" : 416, "entries" : 132070, "size" : 36603573, "offloaded" : false }, { "ledgerId" : 417, "entries" : 131668, "size" : 36500614, "offloaded" : false }, { "ledgerId" : 418, "entries" : 131870, "size" : 36550936, "offloaded" : false }, { "ledgerId" : 419, "entries" : 131763, "size" : 36524647, "offloaded" : false }, { "ledgerId" : 420, "entries" : 131469, "size" : 36445510, "offloaded" : false }, { "ledgerId" : 421, "entries" : 133365, "size" : 36951916, "offloaded" : false }, { "ledgerId" : 422, "entries" : 133817, "size" : 37079172, "offloaded" : false }, { "ledgerId" : 423, "entries" : 134338, "size" : 37233015, "offloaded" : false }, { "ledgerId" : 424, "entries" : 134487, "size" : 37272180, "offloaded" : false }, { "ledgerId" : 425, "entries" : 134674, "size" : 37343523, "offloaded" : false }, { "ledgerId" : 426, "entries" : 134548, "size" : 37305098, "offloaded" : false }, { "ledgerId" : 427, "entries" : 134837, "size" : 37375415, "offloaded" : false }, { "ledgerId" : 428, "entries" : 134340, "size" : 37237593, "offloaded" : false }, { "ledgerId" : 429, "entries" : 134633, "size" : 37308727, "offloaded" : false }, { "ledgerId" : 430, "entries" : 134456, "size" : 37278480, "offloaded" : false }, { "ledgerId" : 431, "entries" : 134457, "size" : 37278726, "offloaded" : false }, { "ledgerId" : 432, "entries" : 134951, "size" : 37418914, "offloaded" : false }, { "ledgerId" : 433, "entries" : 134497, "size" : 37303701, "offloaded" : false }, { "ledgerId" : 434, "entries" : 134280, "size" : 37246342, "offloaded" : false }, { "ledgerId" : 435, "entries" : 134637, "size" : 37339677, "offloaded" : false }, { "ledgerId" : 436, "entries" : 134623, "size" : 37339740, "offloaded" : false }, { "ledgerId" : 437, "entries" : 134492, "size" : 37303129, "offloaded" : false }, { "ledgerId" : 438, "entries" : 134686, "size" : 37353161, "offloaded" : false }, { "ledgerId" : 440, "entries" : 134446, "size" : 37280256, "offloaded" : false }, { "ledgerId" : 443, "entries" : 134437, "size" : 37285427, "offloaded" : false }, { "ledgerId" : 444, "entries" : 134798, "size" : 37391951, "offloaded" : false }, { "ledgerId" : 445, "entries" : 134811, "size" : 37395462, "offloaded" : false }, { "ledgerId" : 446, "entries" : 134153, "size" : 37221662, "offloaded" : false }, { "ledgerId" : 447, "entries" : 134330, "size" : 37267056, "offloaded" : false }, { "ledgerId" : 448, "entries" : 134520, "size" : 37316904, "offloaded" : false }, { "ledgerId" : 449, "entries" : 134722, "size" : 37373454, "offloaded" : false }, { "ledgerId" : 450, "entries" : 134541, "size" : 37319480, "offloaded" : false }, { "ledgerId" : 451, "entries" : 134568, "size" : 37329800, "offloaded" : false }, { "ledgerId" : 452, "entries" : 134664, "size" : 37363469, "offloaded" : false }, { "ledgerId" : 453, "entries" : 134621, "size" : 37358490, "offloaded" : false }, { "ledgerId" : 454, "entries" : 134666, "size" : 37356418, "offloaded" : false }, { "ledgerId" : 455, "entries" : 134586, "size" : 37338696, "offloaded" : false }, { "ledgerId" : 456, "entries" : 134613, "size" : 37350411, "offloaded" : false }, { "ledgerId" : 457, "entries" : 134580, "size" : 37340493, "offloaded" : false }, { "ledgerId" : 458, "entries" : 134357, "size" : 37275882, "offloaded" : false }, { "ledgerId" : 459, "entries" : 134271, "size" : 37250533, "offloaded" : false }, { "ledgerId" : 460, "entries" : 134294, "size" : 37259749, "offloaded" : false }, { "ledgerId" : 461, "entries" : 134212, "size" : 37228832, "offloaded" : false }, { "ledgerId" : 462, "entries" : 134273, "size" : 37254995, "offloaded" : false }, { "ledgerId" : 463, "entries" : 134221, "size" : 37248061, "offloaded" : false }, { "ledgerId" : 464, "entries" : 134435, "size" : 37307430, "offloaded" : false }, { "ledgerId" : 465, "entries" : 134178, "size" : 37234131, "offloaded" : false }, { "ledgerId" : 466, "entries" : 134486, "size" : 37302764, "offloaded" : false }, { "ledgerId" : 469, "entries" : 134126, "size" : 37212885, "offloaded" : false }, { "ledgerId" : 471, "entries" : 134222, "size" : 37234442, "offloaded" : false }, { "ledgerId" : 472, "entries" : 134595, "size" : 37321857, "offloaded" : false }, { "ledgerId" : 473, "entries" : 134431, "size" : 37274843, "offloaded" : false }, { "ledgerId" : 474, "entries" : 134397, "size" : 37268737, "offloaded" : false }, { "ledgerId" : 475, "entries" : 134111, "size" : 37194364, "offloaded" : false }, { "ledgerId" : 476, "entries" : 134702, "size" : 37337615, "offloaded" : false }, { "ledgerId" : 477, "entries" : 134620, "size" : 37306178, "offloaded" : false }, { "ledgerId" : 478, "entries" : 134817, "size" : 37358171, "offloaded" : false }, { "ledgerId" : 479, "entries" : 134527, "size" : 37288571, "offloaded" : false }, { "ledgerId" : 480, "entries" : 134780, "size" : 37348551, "offloaded" : false }, { "ledgerId" : 481, "entries" : 134726, "size" : 37328577, "offloaded" : false }, { "ledgerId" : 482, "entries" : 134669, "size" : 37312381, "offloaded" : false }, { "ledgerId" : 483, "entries" : 134833, "size" : 37350362, "offloaded" : false }, { "ledgerId" : 484, "entries" : 134735, "size" : 37328956, "offloaded" : false }, { "ledgerId" : 485, "entries" : 134457, "size" : 37248395, "offloaded" : false }, { "ledgerId" : 486, "entries" : 134801, "size" : 37330152, "offloaded" : false }, { "ledgerId" : 487, "entries" : 134937, "size" : 37374120, "offloaded" : false }, { "ledgerId" : 488, "entries" : 134949, "size" : 37364683, "offloaded" : false }, { "ledgerId" : 489, "entries" : 134941, "size" : 37366551, "offloaded" : false }, { "ledgerId" : 490, "entries" : 134937, "size" : 37365778, "offloaded" : false }, { "ledgerId" : 491, "entries" : 134556, "size" : 37257762, "offloaded" : false }, { "ledgerId" : 492, "entries" : 135184, "size" : 37414706, "offloaded" : false }, { "ledgerId" : 493, "entries" : 134994, "size" : 37376523, "offloaded" : false }, { "ledgerId" : 496, "entries" : 134946, "size" : 37355336, "offloaded" : false }, { "ledgerId" : 498, "entries" : 135052, "size" : 37382590, "offloaded" : false }, { "ledgerId" : 499, "entries" : 134953, "size" : 37346822, "offloaded" : false }, { "ledgerId" : 500, "entries" : 134752, "size" : 37297186, "offloaded" : false }, { "ledgerId" : 501, "entries" : 134625, "size" : 37260558, "offloaded" : false }, { "ledgerId" : 502, "entries" : 135196, "size" : 37416677, "offloaded" : false }, { "ledgerId" : 503, "entries" : 134912, "size" : 37395449, "offloaded" : false }, { "ledgerId" : 504, "entries" : 135435, "size" : 37549514, "offloaded" : false }, { "ledgerId" : 505, "entries" : 134797, "size" : 37390263, "offloaded" : false }, { "ledgerId" : 506, "entries" : 135352, "size" : 37534228, "offloaded" : false }, { "ledgerId" : 507, "entries" : 134808, "size" : 37385536, "offloaded" : false }, { "ledgerId" : 508, "entries" : 134965, "size" : 37440714, "offloaded" : false }, { "ledgerId" : 509, "entries" : 134998, "size" : 37430969, "offloaded" : false }, { "ledgerId" : 510, "entries" : 135007, "size" : 37437828, "offloaded" : false }, { "ledgerId" : 511, "entries" : 135160, "size" : 37499791, "offloaded" : false }, { "ledgerId" : 512, "entries" : 135023, "size" : 37454858, "offloaded" : false }, { "ledgerId" : 513, "entries" : 134912, "size" : 37415707, "offloaded" : false }, { "ledgerId" : 514, "entries" : 135381, "size" : 37553416, "offloaded" : false }, { "ledgerId" : 515, "entries" : 134798, "size" : 37385651, "offloaded" : false }, { "ledgerId" : 516, "entries" : 135567, "size" : 37605825, "offloaded" : false }, { "ledgerId" : 517, "entries" : 134876, "size" : 37418205, "offloaded" : false }, { "ledgerId" : 518, "entries" : 134694, "size" : 37376818, "offloaded" : false }, { "ledgerId" : 519, "entries" : 135155, "size" : 37507615, "offloaded" : false }, { "ledgerId" : 520, "entries" : 135026, "size" : 37461996, "offloaded" : false }, { "ledgerId" : 522, "entries" : 135055, "size" : 37480507, "offloaded" : false }, { "ledgerId" : 524, "entries" : 134758, "size" : 37407173, "offloaded" : false }, { "ledgerId" : 526, "entries" : 135286, "size" : 37553631, "offloaded" : false }, { "ledgerId" : 527, "entries" : 134866, "size" : 37448120, "offloaded" : false }, { "ledgerId" : 528, "entries" : 134867, "size" : 37438996, "offloaded" : false }, { "ledgerId" : 529, "entries" : 0, "size" : 0, "offloaded" : false } ], "cursors" : { "metrics-report" : { "markDeletePosition" : "459:122", "readPosition" : "459:123", "waitingReadOp" : false, "pendingReadOps" : 0, "messagesConsumedCounter" : 5498355, "cursorLedger" : 523, "cursorLedgerLastEntry" : 10, "individuallyDeletedMessages" : "[]", "lastLedgerSwitchTimestamp" : "2019-12-19T08:42:11.3+08:00", "state" : "Open", "numberOfEntriesSinceFirstNotAckedMessage" : 1, "totalNonContiguousDeletedMessagesRange" : 0, "properties" : { } } } } ``` After check the broker log, i find following logs: ``` 23:18:27.125 [bookkeeper-ml-workers-OrderedExecutor-0-0] DEBUG org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers - [persistent://message-platform/client-metrics/monitor-metrics / metrics-report] Distributing 0 messages to 4 consumers ``` This will cause do not continue reading more entries https://github.com/apache/pulsar/blob/master/pulsar-broker/src/main/java/org/apache/pulsar/broker/service/persistent/PersistentDispatcherMultipleConsumers.java#L460 Because readMoreEntries is called at the end of sendMessagesToConsumers, if the consumer no longer sends a permit request because it has not received any messages, dispatcher will stop dispatch any messages. ### Modifications If read 0 entries from bookie, trigger readMoreEntries ### Verifying this change I have tried to add unit test to ensure the consumer can continue consume messages if read 0 entries happens, looks it's hard to reproduce read 0 entries. ### Does this pull request potentially affect one of the following parts: *If `yes` was chosen, please highlight the changes* - Dependencies (does it add or upgrade a dependency): ( no) - The public API: (no) - The schema: (no) - The default values of configurations: (no) - The wire protocol: (no) - The rest endpoints: (no) - The admin cli options: (no) - Anything that affects deployment: (no) ### Documentation - Does this pull request introduce a new feature? (no)
---------------------------------------------------------------- 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. For queries about this service, please contact Infrastructure at: [email protected] With regards, Apache Git Services
