You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@pulsar.apache.org by Tecno Brain <ce...@gmail.com> on 2022/03/11 05:24:37 UTC

Messages replayed

Hello,
 I have an application using Pulsar just as JMS (we get single messages,
acknowledge them when we are done processing it)
 The entire system, composed of several types of apps, uses about 40
different topics.

 Yesterday, an application that subscribes to about 20 queues, suddenly was
inundated with thousands of messages from two of the queues but I could not
track those messages to an application producing them. We found that the
messages were *duplicates*.
  So it seems that the cursor to these two topics was lost, and messages
from 3 hours earlier were consumed again.  I found the following paragraph :

 "Each subscription stores a cursor. The cursor is the current offset in
the log. Subscriptions store their cursor in BookKeeper in ledgers. This
makes cursor tracking scalable just like topics."
 (
https://jack-vanlightly.com/blog/2018/10/2/understanding-how-apache-pulsar-works
)

My guess is that the cursor was lost.
How could I verify that this was the case? I can't find anything relevant
in the logs.

The only message I found occurring around the same time is

New ensemble: [pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181,
pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181,
pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181] is not
adhering to Placement Policy

Any pointers are appreciated.

Re: Messages replayed

Posted by Tecno Brain <ce...@gmail.com>.
One more piece of information, we are using Pulsar 2.8.2


On Mon, Apr 25, 2022 at 2:24 PM Tecno Brain <ce...@gmail.com>
wrote:

> but we did find messages about resetting of the cursor for the topic with
> the problem:
>
> "@timestamp",message,mediaId,taskId,appName
> "Apr 25, 2022 @ 12:18:31.922","19:18:31.922
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 285143:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:31.926","19:18:31.926
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 285463:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:31.926","19:18:31.926
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 285143:0 before current read position 290249:238 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:31.937","19:18:31.937
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 285463:0 skipping from current read position 285143:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:31.937","19:18:31.937
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 285790:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:31.957","19:18:31.957
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 286120:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:31.957","19:18:31.957
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 285790:0 skipping from current read position 285463:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:31.978","19:18:31.978
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 286439:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:31.978","19:18:31.978
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 286120:0 skipping from current read position 285790:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:31.999","19:18:31.999
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 286439:0 skipping from current read position 286120:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:31.999","19:18:31.999
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 286754:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.020","19:18:32.020
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 286754:0 skipping from current read position 286439:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.020","19:18:32.020
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 287227:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.041","19:18:32.041
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 287227:0 skipping from current read position 286754:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.041","19:18:32.041
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 287627:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.062","19:18:32.062
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 288001:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.062","19:18:32.061
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 287627:0 skipping from current read position 287227:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.077","19:18:32.077
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 288373:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.077","19:18:32.077
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 288001:0 skipping from current read position 287627:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.098","19:18:32.098
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 288373:0 skipping from current read position 288001:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.098","19:18:32.098
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 288733:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.119","19:18:32.118
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 288733:0 skipping from current read position 288373:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.119","19:18:32.119
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 289101:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.136","19:18:32.136
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 289101:0 skipping from current read position 288733:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.136","19:18:32.136
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 289480:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.150","19:18:32.150
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 289480:0 skipping from current read position 289101:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.150","19:18:32.150
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 289849:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.171","19:18:32.171
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 289849:0 skipping from current read position 289480:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.171","19:18:32.171
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> Initiate reset position to 290249:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.188","19:18:32.188
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 285022:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.188","19:18:32.188
> [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
> reset position to 290249:0 skipping from current read position 289849:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.208","19:18:32.208
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 285345:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.208","19:18:32.207
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 285022:0 before current read position 290104:1946 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.228","19:18:32.228
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 285345:0 skipping from current read position 285022:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.228","19:18:32.228
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 285668:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.249","19:18:32.249
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 285992:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.249","19:18:32.249
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 285668:0 skipping from current read position 285345:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.270","19:18:32.270
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 285992:0 skipping from current read position 285668:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.270","19:18:32.270
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 286320:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.291","19:18:32.291
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 286320:0 skipping from current read position 285992:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.291","19:18:32.291
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 286635:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.311","19:18:32.311
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 286635:0 skipping from current read position 286320:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.311","19:18:32.311
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 287023:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.332","19:18:32.332
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 287023:0 skipping from current read position 286635:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.332","19:18:32.332
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 287500:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.353","19:18:32.353
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 287500:0 skipping from current read position 287023:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.353","19:18:32.353
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 287873:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.374","19:18:32.374
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 287873:0 skipping from current read position 287500:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.374","19:18:32.374
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 288244:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.395","19:18:32.395
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 288244:0 skipping from current read position 287873:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.395","19:18:32.395
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 288603:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.416","19:18:32.416
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 288603:0 skipping from current read position 288244:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.416","19:18:32.416
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 288977:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.433","19:18:32.432
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 288977:0 skipping from current read position 288603:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.433","19:18:32.433
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 289356:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.452","19:18:32.452
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 289724:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.452","19:18:32.452
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 289356:0 skipping from current read position 288977:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.473","19:18:32.473
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 289724:0 skipping from current read position 289356:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.473","19:18:32.473
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> Initiate reset position to 290104:0 on cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
> "Apr 25, 2022 @ 12:18:32.494","19:18:32.494
> [BookKeeperClientWorker-OrderedExecutor-1-0] INFO
>  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
> [platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
> reset position to 290104:0 skipping from current read position 289724:0 on
> cursor
> platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
>
> On Mon, Apr 25, 2022 at 2:16 PM Tecno Brain <ce...@gmail.com>
> wrote:
>
>> I observed the same problem again, the cursor of a topic got reset about
>> an hour and 15 minutes.
>> The queue went from zero to about 2,000 elements in a second without any
>> application adding messages. All messages that had occurred during that
>> time were replayed.
>> (My application, as you can see, does not generate a lot of messages for
>> this topic).
>>
>> I need to understand how the cursors are stored.
>>
>> Can anyone point me to any documentation or code?
>>
>> I could not find any exceptions in the log for that topic, but I did
>> found around the same time the following exception in a different topic.
>> Any help is appreciated.
>>
>> "Apr 25, 2022 @ 12:18:32.509","19:18:32.509 [BookKeeperClientWorker-OrderedExecutor-0-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181, pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181, pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181] is not adhering to Placement Policy. quarantinedBookies: []"
>> "Apr 25, 2022 @ 12:18:31.958","19:18:31.958 [pulsar-io-4-3] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181, pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181, pulsar-bookie-4.pulsar-bookie.pulsar.svc.cluster.local:3181] is not adhering to Placement Policy. quarantinedBookies: []"
>> "Apr 25, 2022 @ 12:18:31.921","java.lang.NullPointerException: null"
>> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.broker.service.BacklogQuotaManager.dropBacklogForTimeLimit(BacklogQuotaManager.java:247) ~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
>> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.broker.service.BrokerService.lambda$forEachTopic$71(BrokerService.java:1684) ~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
>> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.common.util.collections.ConcurrentOpenHashMap$Section.forEach(ConcurrentOpenHashMap.java:413) ~[io.streamnative-pulsar-common-2.8.2.0.jar:2.8.2.0]"
>> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.common.util.collections.ConcurrentOpenHashMap.forEach(ConcurrentOpenHashMap.java:185) ~[io.streamnative-pulsar-common-2.8.2.0.jar:2.8.2.0]"
>> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.broker.service.BrokerService.monitorBacklogQuota(BrokerService.java:1693) ~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
>> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.bookkeeper.mledger.util.SafeRun$1.safeRun(SafeRun.java:32) [io.streamnative-managed-ledger-2.8.2.0.jar:2.8.2.0]"
>> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.bookkeeper.common.util.SafeRunnable.run(SafeRunnable.java:36) [org.apache.bookkeeper-bookkeeper-common-4.14.3.jar:4.14.3]"
>> "Apr 25, 2022 @ 12:18:31.921","	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]"
>> "Apr 25, 2022 @ 12:18:31.921","	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]"
>> "Apr 25, 2022 @ 12:18:31.921","19:18:31.906 [pulsar-backlog-quota-checker-35-1] ERROR org.apache.pulsar.broker.service.BacklogQuotaManager - [persistent://platform/system/merge-response-publish-odd-partition-2] Error resetting cursor for slowest consumer [platform_merge-response-publish-odd_queue]"
>> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.broker.service.BacklogQuotaManager.handleExceededBacklogQuota(BacklogQuotaManager.java:129) ~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
>> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.broker.service.BrokerService.lambda$monitorBacklogQuota$72(BrokerService.java:1700) ~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
>> "Apr 25, 2022 @ 12:18:31.921","	at java.util.Optional.ifPresent(Optional.java:183) ~[?:?]"
>> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.broker.service.BrokerService.forEachTopic(BrokerService.java:1682) ~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
>> "Apr 25, 2022 @ 12:18:31.921","	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]"
>> "Apr 25, 2022 @ 12:18:31.921","	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]"
>> "Apr 25, 2022 @ 12:18:31.921","	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]"
>> "Apr 25, 2022 @ 12:18:31.921","	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.72.Final.jar:4.1.72.Final]"
>> "Apr 25, 2022 @ 12:18:31.921","	at java.lang.Thread.run(Thread.java:829) [?:?]"
>> "Apr 25, 2022 @ 12:18:31.888","19:18:31.888 [BookKeeperClientWorker-OrderedExecutor-0-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local
>>
>> Thanks
>>
>>
>>
>>
>> On Fri, Mar 18, 2022 at 9:15 PM PengHui Li <pe...@apache.org> wrote:
>>
>>> It means you have other reset cursor options when doing the ledger
>>> trimming
>>>
>>> On Sat, Mar 19, 2022 at 5:52 AM Tecno Brain <
>>> cerebrotecnologico@gmail.com> wrote:
>>>
>>>> I found this in the logs:
>>>> *    Failed to mark delete while trimming data ledgers: Reset cursor in
>>>> progress - unable to mark delete position 18377:-1*
>>>> but although the messages indicate different topics, the time matches
>>>> when we started to see messages replayed.
>>>>
>>>> What causes that message? What are the consequences of it?
>>>>
>>>> On Fri, Mar 18, 2022 at 1:31 PM Tecno Brain <
>>>> cerebrotecnologico@gmail.com> wrote:
>>>>
>>>>> I wonder what would I have seen in the logs if someone had done
>>>>> something like this:
>>>>>
>>>>> bin/pulsar-admin persistent reset-cursor --time 3h persistent://tenant/namespace/topic
>>>>>
>>>>>
>>>>> On Thu, Mar 17, 2022 at 1:54 PM Tecno Brain <
>>>>> cerebrotecnologico@gmail.com> wrote:
>>>>>
>>>>>> Hi Penghui,
>>>>>>    No, we are not seeing messages "disappear" because of TTL.
>>>>>>   What we observed is that messages from 3 out of 20  topics were
>>>>>> reprocessed.
>>>>>>   We initially thought that the messages were written again into the
>>>>>> topic by our own applications, but we did not find any evidence of that
>>>>>> happening. Our applications logs are pretty good and we would have found
>>>>>> some evidence.
>>>>>>   We couldn't find the reason.
>>>>>>   Our hypothesis was  that the cursor was lost and I was trying to
>>>>>> find a way to verify that hypothesis through the Pulsar logs...looking if
>>>>>> we had lost a broker or a bookie.
>>>>>>   Initially, I thought that perhaps those 3 topics belonged to the
>>>>>> same "bundle" and whenever the broker changed, the cursor was lost.
>>>>>>   But Pulsar stores the cursor in the bookies, not the broker....so,
>>>>>> a broker change shouldn't affect the cursor for the subscription (a shared
>>>>>> subscription)
>>>>>>   We haven't observed the same issue again.
>>>>>>
>>>>>>
>>>>>>
>>>>>> On Sat, Mar 12, 2022 at 7:21 AM PengHui Li <pe...@apache.org>
>>>>>> wrote:
>>>>>>
>>>>>>> If you have TTL, the messages will be expired.
>>>>>>> You mean "cursor was lost", how do you verify this?
>>>>>>> to list subscriptions or not able to consume the message?
>>>>>>> If it is the latter, I think it should be related to the message TTL.
>>>>>>>
>>>>>>> And how about the "brokerDeleteInactiveTopicsMode" in your broker
>>>>>>> settings?
>>>>>>> If you are using "delete_when_subscriptions_caught_up", after all
>>>>>>> the message
>>>>>>> been expired, the topic will be deleted automatically by default.
>>>>>>>
>>>>>>> Penghui
>>>>>>>
>>>>>>> On Sat, Mar 12, 2022 at 5:28 AM Tecno Brain <
>>>>>>> cerebrotecnologico@gmail.com> wrote:
>>>>>>>
>>>>>>>> We do have a backlog quota and messageTTL
>>>>>>>>
>>>>>>>> Our namespace is configured as follows:
>>>>>>>>
>>>>>>>> Backlog quota:
>>>>>>>>
>>>>>>>>
>>>>>>>> *"message_age    BacklogQuotaImpl(limit=-1, limitSize=-1,
>>>>>>>> limitTime=180000, policy=consumer_backlog_eviction)"*
>>>>>>>> Retention:
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> *{  "retentionTimeInMinutes" : 0,  "retentionSizeInMB" : 0}*
>>>>>>>>
>>>>>>>> Message TTL:
>>>>>>>>
>>>>>>>> *172800*
>>>>>>>>
>>>>>>>> All topics are partitioned.
>>>>>>>>
>>>>>>>> *{
>>>>>>>>   "partitions" : 3
>>>>>>>> }*
>>>>>>>>
>>>>>>>>
>>>>>>>> On Thu, Mar 10, 2022 at 11:24 PM PengHui Li <
>>>>>>>> codelipenghui@gmail.com> wrote:
>>>>>>>>
>>>>>>>>> Have you changed the backlog quota policy or enabled the message
>>>>>>>>> TTL?
>>>>>>>>> Pulsar will not remove any cursors or skip messages by default.
>>>>>>>>>
>>>>>>>>> Penghui
>>>>>>>>> On Mar 11, 2022, 1:25 PM +0800, Tecno Brain <
>>>>>>>>> cerebrotecnologico@gmail.com>, wrote:
>>>>>>>>>
>>>>>>>>> Hello,
>>>>>>>>>  I have an application using Pulsar just as JMS (we get single
>>>>>>>>> messages, acknowledge them when we are done processing it)
>>>>>>>>>  The entire system, composed of several types of apps, uses about
>>>>>>>>> 40 different topics.
>>>>>>>>>
>>>>>>>>>  Yesterday, an application that subscribes to about 20 queues,
>>>>>>>>> suddenly was inundated with thousands of messages from two of the queues
>>>>>>>>> but I could not track those messages to an application producing them. We
>>>>>>>>> found that the messages were *duplicates*.
>>>>>>>>>   So it seems that the cursor to these two topics was lost, and
>>>>>>>>> messages from 3 hours earlier were consumed again.  I found the following
>>>>>>>>> paragraph :
>>>>>>>>>
>>>>>>>>>  "Each subscription stores a cursor. The cursor is the current
>>>>>>>>> offset in the log. Subscriptions store their cursor in BookKeeper in
>>>>>>>>> ledgers. This makes cursor tracking scalable just like topics."
>>>>>>>>>  (
>>>>>>>>> https://jack-vanlightly.com/blog/2018/10/2/understanding-how-apache-pulsar-works
>>>>>>>>> )
>>>>>>>>>
>>>>>>>>> My guess is that the cursor was lost.
>>>>>>>>> How could I verify that this was the case? I can't find anything
>>>>>>>>> relevant in the logs.
>>>>>>>>>
>>>>>>>>> The only message I found occurring around the same time is
>>>>>>>>>
>>>>>>>>> New ensemble:
>>>>>>>>> [pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>>>>>>>> pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>>>>>>>> pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181] is not
>>>>>>>>> adhering to Placement Policy
>>>>>>>>>
>>>>>>>>> Any pointers are appreciated.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>

Re: Messages replayed

Posted by Tecno Brain <ce...@gmail.com>.
but we did find messages about resetting of the cursor for the topic with
the problem:

"@timestamp",message,mediaId,taskId,appName
"Apr 25, 2022 @ 12:18:31.922","19:18:31.922
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 285143:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:31.926","19:18:31.926
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 285463:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:31.926","19:18:31.926
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 285143:0 before current read position 290249:238 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:31.937","19:18:31.937
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 285463:0 skipping from current read position 285143:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:31.937","19:18:31.937
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 285790:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:31.957","19:18:31.957
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 286120:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:31.957","19:18:31.957
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 285790:0 skipping from current read position 285463:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:31.978","19:18:31.978
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 286439:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:31.978","19:18:31.978
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 286120:0 skipping from current read position 285790:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:31.999","19:18:31.999
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 286439:0 skipping from current read position 286120:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:31.999","19:18:31.999
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 286754:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.020","19:18:32.020
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 286754:0 skipping from current read position 286439:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.020","19:18:32.020
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 287227:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.041","19:18:32.041
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 287227:0 skipping from current read position 286754:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.041","19:18:32.041
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 287627:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.062","19:18:32.062
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 288001:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.062","19:18:32.061
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 287627:0 skipping from current read position 287227:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.077","19:18:32.077
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 288373:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.077","19:18:32.077
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 288001:0 skipping from current read position 287627:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.098","19:18:32.098
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 288373:0 skipping from current read position 288001:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.098","19:18:32.098
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 288733:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.119","19:18:32.118
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 288733:0 skipping from current read position 288373:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.119","19:18:32.119
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 289101:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.136","19:18:32.136
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 289101:0 skipping from current read position 288733:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.136","19:18:32.136
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 289480:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.150","19:18:32.150
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 289480:0 skipping from current read position 289101:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.150","19:18:32.150
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 289849:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.171","19:18:32.171
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 289849:0 skipping from current read position 289480:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.171","19:18:32.171
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
Initiate reset position to 290249:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.188","19:18:32.188
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 285022:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.188","19:18:32.188
[BookKeeperClientWorker-OrderedExecutor-0-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-1]
reset position to 290249:0 skipping from current read position 289849:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.208","19:18:32.208
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 285345:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.208","19:18:32.207
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 285022:0 before current read position 290104:1946 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.228","19:18:32.228
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 285345:0 skipping from current read position 285022:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.228","19:18:32.228
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 285668:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.249","19:18:32.249
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 285992:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.249","19:18:32.249
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 285668:0 skipping from current read position 285345:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.270","19:18:32.270
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 285992:0 skipping from current read position 285668:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.270","19:18:32.270
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 286320:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.291","19:18:32.291
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 286320:0 skipping from current read position 285992:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.291","19:18:32.291
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 286635:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.311","19:18:32.311
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 286635:0 skipping from current read position 286320:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.311","19:18:32.311
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 287023:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.332","19:18:32.332
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 287023:0 skipping from current read position 286635:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.332","19:18:32.332
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 287500:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.353","19:18:32.353
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 287500:0 skipping from current read position 287023:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.353","19:18:32.353
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 287873:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.374","19:18:32.374
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 287873:0 skipping from current read position 287500:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.374","19:18:32.374
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 288244:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.395","19:18:32.395
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 288244:0 skipping from current read position 287873:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.395","19:18:32.395
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 288603:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.416","19:18:32.416
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 288603:0 skipping from current read position 288244:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.416","19:18:32.416
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 288977:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.433","19:18:32.432
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 288977:0 skipping from current read position 288603:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.433","19:18:32.433
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 289356:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.452","19:18:32.452
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 289724:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.452","19:18:32.452
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 289356:0 skipping from current read position 288977:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.473","19:18:32.473
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 289724:0 skipping from current read position 289356:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.473","19:18:32.473
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
Initiate reset position to 290104:0 on cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"
"Apr 25, 2022 @ 12:18:32.494","19:18:32.494
[BookKeeperClientWorker-OrderedExecutor-1-0] INFO
 org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[platform/system/persistent/tsc-sm-request-recognition-en-odd-partition-0]
reset position to 290104:0 skipping from current read position 289724:0 on
cursor
platform_persistent%3A%2F%2Fplatform%2Fsystem%2Ftsc-sm-request-recognition-en-odd_queue","-","-","pulsar-broker"

On Mon, Apr 25, 2022 at 2:16 PM Tecno Brain <ce...@gmail.com>
wrote:

> I observed the same problem again, the cursor of a topic got reset about
> an hour and 15 minutes.
> The queue went from zero to about 2,000 elements in a second without any
> application adding messages. All messages that had occurred during that
> time were replayed.
> (My application, as you can see, does not generate a lot of messages for
> this topic).
>
> I need to understand how the cursors are stored.
>
> Can anyone point me to any documentation or code?
>
> I could not find any exceptions in the log for that topic, but I did found
> around the same time the following exception in a different topic. Any help
> is appreciated.
>
> "Apr 25, 2022 @ 12:18:32.509","19:18:32.509 [BookKeeperClientWorker-OrderedExecutor-0-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181, pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181, pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181] is not adhering to Placement Policy. quarantinedBookies: []"
> "Apr 25, 2022 @ 12:18:31.958","19:18:31.958 [pulsar-io-4-3] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181, pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181, pulsar-bookie-4.pulsar-bookie.pulsar.svc.cluster.local:3181] is not adhering to Placement Policy. quarantinedBookies: []"
> "Apr 25, 2022 @ 12:18:31.921","java.lang.NullPointerException: null"
> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.broker.service.BacklogQuotaManager.dropBacklogForTimeLimit(BacklogQuotaManager.java:247) ~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.broker.service.BrokerService.lambda$forEachTopic$71(BrokerService.java:1684) ~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.common.util.collections.ConcurrentOpenHashMap$Section.forEach(ConcurrentOpenHashMap.java:413) ~[io.streamnative-pulsar-common-2.8.2.0.jar:2.8.2.0]"
> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.common.util.collections.ConcurrentOpenHashMap.forEach(ConcurrentOpenHashMap.java:185) ~[io.streamnative-pulsar-common-2.8.2.0.jar:2.8.2.0]"
> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.broker.service.BrokerService.monitorBacklogQuota(BrokerService.java:1693) ~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.bookkeeper.mledger.util.SafeRun$1.safeRun(SafeRun.java:32) [io.streamnative-managed-ledger-2.8.2.0.jar:2.8.2.0]"
> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.bookkeeper.common.util.SafeRunnable.run(SafeRunnable.java:36) [org.apache.bookkeeper-bookkeeper-common-4.14.3.jar:4.14.3]"
> "Apr 25, 2022 @ 12:18:31.921","	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]"
> "Apr 25, 2022 @ 12:18:31.921","	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]"
> "Apr 25, 2022 @ 12:18:31.921","19:18:31.906 [pulsar-backlog-quota-checker-35-1] ERROR org.apache.pulsar.broker.service.BacklogQuotaManager - [persistent://platform/system/merge-response-publish-odd-partition-2] Error resetting cursor for slowest consumer [platform_merge-response-publish-odd_queue]"
> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.broker.service.BacklogQuotaManager.handleExceededBacklogQuota(BacklogQuotaManager.java:129) ~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.broker.service.BrokerService.lambda$monitorBacklogQuota$72(BrokerService.java:1700) ~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
> "Apr 25, 2022 @ 12:18:31.921","	at java.util.Optional.ifPresent(Optional.java:183) ~[?:?]"
> "Apr 25, 2022 @ 12:18:31.921","	at org.apache.pulsar.broker.service.BrokerService.forEachTopic(BrokerService.java:1682) ~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
> "Apr 25, 2022 @ 12:18:31.921","	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]"
> "Apr 25, 2022 @ 12:18:31.921","	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]"
> "Apr 25, 2022 @ 12:18:31.921","	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]"
> "Apr 25, 2022 @ 12:18:31.921","	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.72.Final.jar:4.1.72.Final]"
> "Apr 25, 2022 @ 12:18:31.921","	at java.lang.Thread.run(Thread.java:829) [?:?]"
> "Apr 25, 2022 @ 12:18:31.888","19:18:31.888 [BookKeeperClientWorker-OrderedExecutor-0-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local
>
> Thanks
>
>
>
>
> On Fri, Mar 18, 2022 at 9:15 PM PengHui Li <pe...@apache.org> wrote:
>
>> It means you have other reset cursor options when doing the ledger
>> trimming
>>
>> On Sat, Mar 19, 2022 at 5:52 AM Tecno Brain <ce...@gmail.com>
>> wrote:
>>
>>> I found this in the logs:
>>> *    Failed to mark delete while trimming data ledgers: Reset cursor in
>>> progress - unable to mark delete position 18377:-1*
>>> but although the messages indicate different topics, the time matches
>>> when we started to see messages replayed.
>>>
>>> What causes that message? What are the consequences of it?
>>>
>>> On Fri, Mar 18, 2022 at 1:31 PM Tecno Brain <
>>> cerebrotecnologico@gmail.com> wrote:
>>>
>>>> I wonder what would I have seen in the logs if someone had done
>>>> something like this:
>>>>
>>>> bin/pulsar-admin persistent reset-cursor --time 3h persistent://tenant/namespace/topic
>>>>
>>>>
>>>> On Thu, Mar 17, 2022 at 1:54 PM Tecno Brain <
>>>> cerebrotecnologico@gmail.com> wrote:
>>>>
>>>>> Hi Penghui,
>>>>>    No, we are not seeing messages "disappear" because of TTL.
>>>>>   What we observed is that messages from 3 out of 20  topics were
>>>>> reprocessed.
>>>>>   We initially thought that the messages were written again into the
>>>>> topic by our own applications, but we did not find any evidence of that
>>>>> happening. Our applications logs are pretty good and we would have found
>>>>> some evidence.
>>>>>   We couldn't find the reason.
>>>>>   Our hypothesis was  that the cursor was lost and I was trying to
>>>>> find a way to verify that hypothesis through the Pulsar logs...looking if
>>>>> we had lost a broker or a bookie.
>>>>>   Initially, I thought that perhaps those 3 topics belonged to the
>>>>> same "bundle" and whenever the broker changed, the cursor was lost.
>>>>>   But Pulsar stores the cursor in the bookies, not the broker....so, a
>>>>> broker change shouldn't affect the cursor for the subscription (a shared
>>>>> subscription)
>>>>>   We haven't observed the same issue again.
>>>>>
>>>>>
>>>>>
>>>>> On Sat, Mar 12, 2022 at 7:21 AM PengHui Li <pe...@apache.org> wrote:
>>>>>
>>>>>> If you have TTL, the messages will be expired.
>>>>>> You mean "cursor was lost", how do you verify this?
>>>>>> to list subscriptions or not able to consume the message?
>>>>>> If it is the latter, I think it should be related to the message TTL.
>>>>>>
>>>>>> And how about the "brokerDeleteInactiveTopicsMode" in your broker
>>>>>> settings?
>>>>>> If you are using "delete_when_subscriptions_caught_up", after all the
>>>>>> message
>>>>>> been expired, the topic will be deleted automatically by default.
>>>>>>
>>>>>> Penghui
>>>>>>
>>>>>> On Sat, Mar 12, 2022 at 5:28 AM Tecno Brain <
>>>>>> cerebrotecnologico@gmail.com> wrote:
>>>>>>
>>>>>>> We do have a backlog quota and messageTTL
>>>>>>>
>>>>>>> Our namespace is configured as follows:
>>>>>>>
>>>>>>> Backlog quota:
>>>>>>>
>>>>>>>
>>>>>>> *"message_age    BacklogQuotaImpl(limit=-1, limitSize=-1,
>>>>>>> limitTime=180000, policy=consumer_backlog_eviction)"*
>>>>>>> Retention:
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>> *{  "retentionTimeInMinutes" : 0,  "retentionSizeInMB" : 0}*
>>>>>>>
>>>>>>> Message TTL:
>>>>>>>
>>>>>>> *172800*
>>>>>>>
>>>>>>> All topics are partitioned.
>>>>>>>
>>>>>>> *{
>>>>>>>   "partitions" : 3
>>>>>>> }*
>>>>>>>
>>>>>>>
>>>>>>> On Thu, Mar 10, 2022 at 11:24 PM PengHui Li <co...@gmail.com>
>>>>>>> wrote:
>>>>>>>
>>>>>>>> Have you changed the backlog quota policy or enabled the message
>>>>>>>> TTL?
>>>>>>>> Pulsar will not remove any cursors or skip messages by default.
>>>>>>>>
>>>>>>>> Penghui
>>>>>>>> On Mar 11, 2022, 1:25 PM +0800, Tecno Brain <
>>>>>>>> cerebrotecnologico@gmail.com>, wrote:
>>>>>>>>
>>>>>>>> Hello,
>>>>>>>>  I have an application using Pulsar just as JMS (we get single
>>>>>>>> messages, acknowledge them when we are done processing it)
>>>>>>>>  The entire system, composed of several types of apps, uses about
>>>>>>>> 40 different topics.
>>>>>>>>
>>>>>>>>  Yesterday, an application that subscribes to about 20 queues,
>>>>>>>> suddenly was inundated with thousands of messages from two of the queues
>>>>>>>> but I could not track those messages to an application producing them. We
>>>>>>>> found that the messages were *duplicates*.
>>>>>>>>   So it seems that the cursor to these two topics was lost, and
>>>>>>>> messages from 3 hours earlier were consumed again.  I found the following
>>>>>>>> paragraph :
>>>>>>>>
>>>>>>>>  "Each subscription stores a cursor. The cursor is the current
>>>>>>>> offset in the log. Subscriptions store their cursor in BookKeeper in
>>>>>>>> ledgers. This makes cursor tracking scalable just like topics."
>>>>>>>>  (
>>>>>>>> https://jack-vanlightly.com/blog/2018/10/2/understanding-how-apache-pulsar-works
>>>>>>>> )
>>>>>>>>
>>>>>>>> My guess is that the cursor was lost.
>>>>>>>> How could I verify that this was the case? I can't find anything
>>>>>>>> relevant in the logs.
>>>>>>>>
>>>>>>>> The only message I found occurring around the same time is
>>>>>>>>
>>>>>>>> New ensemble:
>>>>>>>> [pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>>>>>>> pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>>>>>>> pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181] is not
>>>>>>>> adhering to Placement Policy
>>>>>>>>
>>>>>>>> Any pointers are appreciated.
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>

Re: Messages replayed

Posted by Tecno Brain <ce...@gmail.com>.
I observed the same problem again, the cursor of a topic got reset about an
hour and 15 minutes.
The queue went from zero to about 2,000 elements in a second without any
application adding messages. All messages that had occurred during that
time were replayed.
(My application, as you can see, does not generate a lot of messages for
this topic).

I need to understand how the cursors are stored.

Can anyone point me to any documentation or code?

I could not find any exceptions in the log for that topic, but I did found
around the same time the following exception in a different topic. Any help
is appreciated.

"Apr 25, 2022 @ 12:18:32.509","19:18:32.509
[BookKeeperClientWorker-OrderedExecutor-0-0] WARN
org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble:
[pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181,
pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181,
pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181] is not
adhering to Placement Policy. quarantinedBookies: []"
"Apr 25, 2022 @ 12:18:31.958","19:18:31.958 [pulsar-io-4-3] WARN
org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble:
[pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181,
pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181,
pulsar-bookie-4.pulsar-bookie.pulsar.svc.cluster.local:3181] is not
adhering to Placement Policy. quarantinedBookies: []"
"Apr 25, 2022 @ 12:18:31.921","java.lang.NullPointerException: null"
"Apr 25, 2022 @ 12:18:31.921","	at
org.apache.pulsar.broker.service.BacklogQuotaManager.dropBacklogForTimeLimit(BacklogQuotaManager.java:247)
~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
"Apr 25, 2022 @ 12:18:31.921","	at
org.apache.pulsar.broker.service.BrokerService.lambda$forEachTopic$71(BrokerService.java:1684)
~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
"Apr 25, 2022 @ 12:18:31.921","	at
org.apache.pulsar.common.util.collections.ConcurrentOpenHashMap$Section.forEach(ConcurrentOpenHashMap.java:413)
~[io.streamnative-pulsar-common-2.8.2.0.jar:2.8.2.0]"
"Apr 25, 2022 @ 12:18:31.921","	at
org.apache.pulsar.common.util.collections.ConcurrentOpenHashMap.forEach(ConcurrentOpenHashMap.java:185)
~[io.streamnative-pulsar-common-2.8.2.0.jar:2.8.2.0]"
"Apr 25, 2022 @ 12:18:31.921","	at
org.apache.pulsar.broker.service.BrokerService.monitorBacklogQuota(BrokerService.java:1693)
~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
"Apr 25, 2022 @ 12:18:31.921","	at
org.apache.bookkeeper.mledger.util.SafeRun$1.safeRun(SafeRun.java:32)
[io.streamnative-managed-ledger-2.8.2.0.jar:2.8.2.0]"
"Apr 25, 2022 @ 12:18:31.921","	at
org.apache.bookkeeper.common.util.SafeRunnable.run(SafeRunnable.java:36)
[org.apache.bookkeeper-bookkeeper-common-4.14.3.jar:4.14.3]"
"Apr 25, 2022 @ 12:18:31.921","	at
java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
[?:?]"
"Apr 25, 2022 @ 12:18:31.921","	at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[?:?]"
"Apr 25, 2022 @ 12:18:31.921","19:18:31.906
[pulsar-backlog-quota-checker-35-1] ERROR
org.apache.pulsar.broker.service.BacklogQuotaManager -
[persistent://platform/system/merge-response-publish-odd-partition-2]
Error resetting cursor for slowest consumer
[platform_merge-response-publish-odd_queue]"
"Apr 25, 2022 @ 12:18:31.921","	at
org.apache.pulsar.broker.service.BacklogQuotaManager.handleExceededBacklogQuota(BacklogQuotaManager.java:129)
~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
"Apr 25, 2022 @ 12:18:31.921","	at
org.apache.pulsar.broker.service.BrokerService.lambda$monitorBacklogQuota$72(BrokerService.java:1700)
~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
"Apr 25, 2022 @ 12:18:31.921","	at
java.util.Optional.ifPresent(Optional.java:183) ~[?:?]"
"Apr 25, 2022 @ 12:18:31.921","	at
org.apache.pulsar.broker.service.BrokerService.forEachTopic(BrokerService.java:1682)
~[io.streamnative-pulsar-broker-2.8.2.0.jar:2.8.2.0]"
"Apr 25, 2022 @ 12:18:31.921","	at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
[?:?]"
"Apr 25, 2022 @ 12:18:31.921","	at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
[?:?]"
"Apr 25, 2022 @ 12:18:31.921","	at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[?:?]"
"Apr 25, 2022 @ 12:18:31.921","	at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
[io.netty-netty-common-4.1.72.Final.jar:4.1.72.Final]"
"Apr 25, 2022 @ 12:18:31.921","	at java.lang.Thread.run(Thread.java:829) [?:?]"
"Apr 25, 2022 @ 12:18:31.888","19:18:31.888
[BookKeeperClientWorker-OrderedExecutor-0-0] WARN
org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble:
[pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local

Thanks




On Fri, Mar 18, 2022 at 9:15 PM PengHui Li <pe...@apache.org> wrote:

> It means you have other reset cursor options when doing the ledger trimming
>
> On Sat, Mar 19, 2022 at 5:52 AM Tecno Brain <ce...@gmail.com>
> wrote:
>
>> I found this in the logs:
>> *    Failed to mark delete while trimming data ledgers: Reset cursor in
>> progress - unable to mark delete position 18377:-1*
>> but although the messages indicate different topics, the time matches
>> when we started to see messages replayed.
>>
>> What causes that message? What are the consequences of it?
>>
>> On Fri, Mar 18, 2022 at 1:31 PM Tecno Brain <ce...@gmail.com>
>> wrote:
>>
>>> I wonder what would I have seen in the logs if someone had done
>>> something like this:
>>>
>>> bin/pulsar-admin persistent reset-cursor --time 3h persistent://tenant/namespace/topic
>>>
>>>
>>> On Thu, Mar 17, 2022 at 1:54 PM Tecno Brain <
>>> cerebrotecnologico@gmail.com> wrote:
>>>
>>>> Hi Penghui,
>>>>    No, we are not seeing messages "disappear" because of TTL.
>>>>   What we observed is that messages from 3 out of 20  topics were
>>>> reprocessed.
>>>>   We initially thought that the messages were written again into the
>>>> topic by our own applications, but we did not find any evidence of that
>>>> happening. Our applications logs are pretty good and we would have found
>>>> some evidence.
>>>>   We couldn't find the reason.
>>>>   Our hypothesis was  that the cursor was lost and I was trying to find
>>>> a way to verify that hypothesis through the Pulsar logs...looking if we had
>>>> lost a broker or a bookie.
>>>>   Initially, I thought that perhaps those 3 topics belonged to the same
>>>> "bundle" and whenever the broker changed, the cursor was lost.
>>>>   But Pulsar stores the cursor in the bookies, not the broker....so, a
>>>> broker change shouldn't affect the cursor for the subscription (a shared
>>>> subscription)
>>>>   We haven't observed the same issue again.
>>>>
>>>>
>>>>
>>>> On Sat, Mar 12, 2022 at 7:21 AM PengHui Li <pe...@apache.org> wrote:
>>>>
>>>>> If you have TTL, the messages will be expired.
>>>>> You mean "cursor was lost", how do you verify this?
>>>>> to list subscriptions or not able to consume the message?
>>>>> If it is the latter, I think it should be related to the message TTL.
>>>>>
>>>>> And how about the "brokerDeleteInactiveTopicsMode" in your broker
>>>>> settings?
>>>>> If you are using "delete_when_subscriptions_caught_up", after all the
>>>>> message
>>>>> been expired, the topic will be deleted automatically by default.
>>>>>
>>>>> Penghui
>>>>>
>>>>> On Sat, Mar 12, 2022 at 5:28 AM Tecno Brain <
>>>>> cerebrotecnologico@gmail.com> wrote:
>>>>>
>>>>>> We do have a backlog quota and messageTTL
>>>>>>
>>>>>> Our namespace is configured as follows:
>>>>>>
>>>>>> Backlog quota:
>>>>>>
>>>>>>
>>>>>> *"message_age    BacklogQuotaImpl(limit=-1, limitSize=-1,
>>>>>> limitTime=180000, policy=consumer_backlog_eviction)"*
>>>>>> Retention:
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> *{  "retentionTimeInMinutes" : 0,  "retentionSizeInMB" : 0}*
>>>>>>
>>>>>> Message TTL:
>>>>>>
>>>>>> *172800*
>>>>>>
>>>>>> All topics are partitioned.
>>>>>>
>>>>>> *{
>>>>>>   "partitions" : 3
>>>>>> }*
>>>>>>
>>>>>>
>>>>>> On Thu, Mar 10, 2022 at 11:24 PM PengHui Li <co...@gmail.com>
>>>>>> wrote:
>>>>>>
>>>>>>> Have you changed the backlog quota policy or enabled the message TTL?
>>>>>>> Pulsar will not remove any cursors or skip messages by default.
>>>>>>>
>>>>>>> Penghui
>>>>>>> On Mar 11, 2022, 1:25 PM +0800, Tecno Brain <
>>>>>>> cerebrotecnologico@gmail.com>, wrote:
>>>>>>>
>>>>>>> Hello,
>>>>>>>  I have an application using Pulsar just as JMS (we get single
>>>>>>> messages, acknowledge them when we are done processing it)
>>>>>>>  The entire system, composed of several types of apps, uses about 40
>>>>>>> different topics.
>>>>>>>
>>>>>>>  Yesterday, an application that subscribes to about 20 queues,
>>>>>>> suddenly was inundated with thousands of messages from two of the queues
>>>>>>> but I could not track those messages to an application producing them. We
>>>>>>> found that the messages were *duplicates*.
>>>>>>>   So it seems that the cursor to these two topics was lost, and
>>>>>>> messages from 3 hours earlier were consumed again.  I found the following
>>>>>>> paragraph :
>>>>>>>
>>>>>>>  "Each subscription stores a cursor. The cursor is the current
>>>>>>> offset in the log. Subscriptions store their cursor in BookKeeper in
>>>>>>> ledgers. This makes cursor tracking scalable just like topics."
>>>>>>>  (
>>>>>>> https://jack-vanlightly.com/blog/2018/10/2/understanding-how-apache-pulsar-works
>>>>>>> )
>>>>>>>
>>>>>>> My guess is that the cursor was lost.
>>>>>>> How could I verify that this was the case? I can't find anything
>>>>>>> relevant in the logs.
>>>>>>>
>>>>>>> The only message I found occurring around the same time is
>>>>>>>
>>>>>>> New ensemble:
>>>>>>> [pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>>>>>> pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>>>>>> pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181] is not
>>>>>>> adhering to Placement Policy
>>>>>>>
>>>>>>> Any pointers are appreciated.
>>>>>>>
>>>>>>>
>>>>>>>
>>>>>>>

Re: Messages replayed

Posted by PengHui Li <pe...@apache.org>.
It means you have other reset cursor options when doing the ledger trimming

On Sat, Mar 19, 2022 at 5:52 AM Tecno Brain <ce...@gmail.com>
wrote:

> I found this in the logs:
> *    Failed to mark delete while trimming data ledgers: Reset cursor in
> progress - unable to mark delete position 18377:-1*
> but although the messages indicate different topics, the time matches when
> we started to see messages replayed.
>
> What causes that message? What are the consequences of it?
>
> On Fri, Mar 18, 2022 at 1:31 PM Tecno Brain <ce...@gmail.com>
> wrote:
>
>> I wonder what would I have seen in the logs if someone had done something
>> like this:
>>
>> bin/pulsar-admin persistent reset-cursor --time 3h persistent://tenant/namespace/topic
>>
>>
>> On Thu, Mar 17, 2022 at 1:54 PM Tecno Brain <ce...@gmail.com>
>> wrote:
>>
>>> Hi Penghui,
>>>    No, we are not seeing messages "disappear" because of TTL.
>>>   What we observed is that messages from 3 out of 20  topics were
>>> reprocessed.
>>>   We initially thought that the messages were written again into the
>>> topic by our own applications, but we did not find any evidence of that
>>> happening. Our applications logs are pretty good and we would have found
>>> some evidence.
>>>   We couldn't find the reason.
>>>   Our hypothesis was  that the cursor was lost and I was trying to find
>>> a way to verify that hypothesis through the Pulsar logs...looking if we had
>>> lost a broker or a bookie.
>>>   Initially, I thought that perhaps those 3 topics belonged to the same
>>> "bundle" and whenever the broker changed, the cursor was lost.
>>>   But Pulsar stores the cursor in the bookies, not the broker....so, a
>>> broker change shouldn't affect the cursor for the subscription (a shared
>>> subscription)
>>>   We haven't observed the same issue again.
>>>
>>>
>>>
>>> On Sat, Mar 12, 2022 at 7:21 AM PengHui Li <pe...@apache.org> wrote:
>>>
>>>> If you have TTL, the messages will be expired.
>>>> You mean "cursor was lost", how do you verify this?
>>>> to list subscriptions or not able to consume the message?
>>>> If it is the latter, I think it should be related to the message TTL.
>>>>
>>>> And how about the "brokerDeleteInactiveTopicsMode" in your broker
>>>> settings?
>>>> If you are using "delete_when_subscriptions_caught_up", after all the
>>>> message
>>>> been expired, the topic will be deleted automatically by default.
>>>>
>>>> Penghui
>>>>
>>>> On Sat, Mar 12, 2022 at 5:28 AM Tecno Brain <
>>>> cerebrotecnologico@gmail.com> wrote:
>>>>
>>>>> We do have a backlog quota and messageTTL
>>>>>
>>>>> Our namespace is configured as follows:
>>>>>
>>>>> Backlog quota:
>>>>>
>>>>>
>>>>> *"message_age    BacklogQuotaImpl(limit=-1, limitSize=-1,
>>>>> limitTime=180000, policy=consumer_backlog_eviction)"*
>>>>> Retention:
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> *{  "retentionTimeInMinutes" : 0,  "retentionSizeInMB" : 0}*
>>>>>
>>>>> Message TTL:
>>>>>
>>>>> *172800*
>>>>>
>>>>> All topics are partitioned.
>>>>>
>>>>> *{
>>>>>   "partitions" : 3
>>>>> }*
>>>>>
>>>>>
>>>>> On Thu, Mar 10, 2022 at 11:24 PM PengHui Li <co...@gmail.com>
>>>>> wrote:
>>>>>
>>>>>> Have you changed the backlog quota policy or enabled the message TTL?
>>>>>> Pulsar will not remove any cursors or skip messages by default.
>>>>>>
>>>>>> Penghui
>>>>>> On Mar 11, 2022, 1:25 PM +0800, Tecno Brain <
>>>>>> cerebrotecnologico@gmail.com>, wrote:
>>>>>>
>>>>>> Hello,
>>>>>>  I have an application using Pulsar just as JMS (we get single
>>>>>> messages, acknowledge them when we are done processing it)
>>>>>>  The entire system, composed of several types of apps, uses about 40
>>>>>> different topics.
>>>>>>
>>>>>>  Yesterday, an application that subscribes to about 20 queues,
>>>>>> suddenly was inundated with thousands of messages from two of the queues
>>>>>> but I could not track those messages to an application producing them. We
>>>>>> found that the messages were *duplicates*.
>>>>>>   So it seems that the cursor to these two topics was lost, and
>>>>>> messages from 3 hours earlier were consumed again.  I found the following
>>>>>> paragraph :
>>>>>>
>>>>>>  "Each subscription stores a cursor. The cursor is the current offset
>>>>>> in the log. Subscriptions store their cursor in BookKeeper in ledgers. This
>>>>>> makes cursor tracking scalable just like topics."
>>>>>>  (
>>>>>> https://jack-vanlightly.com/blog/2018/10/2/understanding-how-apache-pulsar-works
>>>>>> )
>>>>>>
>>>>>> My guess is that the cursor was lost.
>>>>>> How could I verify that this was the case? I can't find anything
>>>>>> relevant in the logs.
>>>>>>
>>>>>> The only message I found occurring around the same time is
>>>>>>
>>>>>> New ensemble:
>>>>>> [pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>>>>> pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>>>>> pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181] is not
>>>>>> adhering to Placement Policy
>>>>>>
>>>>>> Any pointers are appreciated.
>>>>>>
>>>>>>
>>>>>>
>>>>>>

Re: Messages replayed

Posted by Tecno Brain <ce...@gmail.com>.
I found this in the logs:
*    Failed to mark delete while trimming data ledgers: Reset cursor in
progress - unable to mark delete position 18377:-1*
but although the messages indicate different topics, the time matches when
we started to see messages replayed.

What causes that message? What are the consequences of it?

On Fri, Mar 18, 2022 at 1:31 PM Tecno Brain <ce...@gmail.com>
wrote:

> I wonder what would I have seen in the logs if someone had done something
> like this:
>
> bin/pulsar-admin persistent reset-cursor --time 3h persistent://tenant/namespace/topic
>
>
> On Thu, Mar 17, 2022 at 1:54 PM Tecno Brain <ce...@gmail.com>
> wrote:
>
>> Hi Penghui,
>>    No, we are not seeing messages "disappear" because of TTL.
>>   What we observed is that messages from 3 out of 20  topics were
>> reprocessed.
>>   We initially thought that the messages were written again into the
>> topic by our own applications, but we did not find any evidence of that
>> happening. Our applications logs are pretty good and we would have found
>> some evidence.
>>   We couldn't find the reason.
>>   Our hypothesis was  that the cursor was lost and I was trying to find a
>> way to verify that hypothesis through the Pulsar logs...looking if we had
>> lost a broker or a bookie.
>>   Initially, I thought that perhaps those 3 topics belonged to the same
>> "bundle" and whenever the broker changed, the cursor was lost.
>>   But Pulsar stores the cursor in the bookies, not the broker....so, a
>> broker change shouldn't affect the cursor for the subscription (a shared
>> subscription)
>>   We haven't observed the same issue again.
>>
>>
>>
>> On Sat, Mar 12, 2022 at 7:21 AM PengHui Li <pe...@apache.org> wrote:
>>
>>> If you have TTL, the messages will be expired.
>>> You mean "cursor was lost", how do you verify this?
>>> to list subscriptions or not able to consume the message?
>>> If it is the latter, I think it should be related to the message TTL.
>>>
>>> And how about the "brokerDeleteInactiveTopicsMode" in your broker
>>> settings?
>>> If you are using "delete_when_subscriptions_caught_up", after all the
>>> message
>>> been expired, the topic will be deleted automatically by default.
>>>
>>> Penghui
>>>
>>> On Sat, Mar 12, 2022 at 5:28 AM Tecno Brain <
>>> cerebrotecnologico@gmail.com> wrote:
>>>
>>>> We do have a backlog quota and messageTTL
>>>>
>>>> Our namespace is configured as follows:
>>>>
>>>> Backlog quota:
>>>>
>>>>
>>>> *"message_age    BacklogQuotaImpl(limit=-1, limitSize=-1,
>>>> limitTime=180000, policy=consumer_backlog_eviction)"*
>>>> Retention:
>>>>
>>>>
>>>>
>>>>
>>>> *{  "retentionTimeInMinutes" : 0,  "retentionSizeInMB" : 0}*
>>>>
>>>> Message TTL:
>>>>
>>>> *172800*
>>>>
>>>> All topics are partitioned.
>>>>
>>>> *{
>>>>   "partitions" : 3
>>>> }*
>>>>
>>>>
>>>> On Thu, Mar 10, 2022 at 11:24 PM PengHui Li <co...@gmail.com>
>>>> wrote:
>>>>
>>>>> Have you changed the backlog quota policy or enabled the message TTL?
>>>>> Pulsar will not remove any cursors or skip messages by default.
>>>>>
>>>>> Penghui
>>>>> On Mar 11, 2022, 1:25 PM +0800, Tecno Brain <
>>>>> cerebrotecnologico@gmail.com>, wrote:
>>>>>
>>>>> Hello,
>>>>>  I have an application using Pulsar just as JMS (we get single
>>>>> messages, acknowledge them when we are done processing it)
>>>>>  The entire system, composed of several types of apps, uses about 40
>>>>> different topics.
>>>>>
>>>>>  Yesterday, an application that subscribes to about 20 queues,
>>>>> suddenly was inundated with thousands of messages from two of the queues
>>>>> but I could not track those messages to an application producing them. We
>>>>> found that the messages were *duplicates*.
>>>>>   So it seems that the cursor to these two topics was lost, and
>>>>> messages from 3 hours earlier were consumed again.  I found the following
>>>>> paragraph :
>>>>>
>>>>>  "Each subscription stores a cursor. The cursor is the current offset
>>>>> in the log. Subscriptions store their cursor in BookKeeper in ledgers. This
>>>>> makes cursor tracking scalable just like topics."
>>>>>  (
>>>>> https://jack-vanlightly.com/blog/2018/10/2/understanding-how-apache-pulsar-works
>>>>> )
>>>>>
>>>>> My guess is that the cursor was lost.
>>>>> How could I verify that this was the case? I can't find anything
>>>>> relevant in the logs.
>>>>>
>>>>> The only message I found occurring around the same time is
>>>>>
>>>>> New ensemble:
>>>>> [pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>>>> pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>>>> pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181] is not
>>>>> adhering to Placement Policy
>>>>>
>>>>> Any pointers are appreciated.
>>>>>
>>>>>
>>>>>
>>>>>

Re: Messages replayed

Posted by Tecno Brain <ce...@gmail.com>.
I wonder what would I have seen in the logs if someone had done something
like this:

bin/pulsar-admin persistent reset-cursor --time 3h
persistent://tenant/namespace/topic


On Thu, Mar 17, 2022 at 1:54 PM Tecno Brain <ce...@gmail.com>
wrote:

> Hi Penghui,
>    No, we are not seeing messages "disappear" because of TTL.
>   What we observed is that messages from 3 out of 20  topics were
> reprocessed.
>   We initially thought that the messages were written again into the topic
> by our own applications, but we did not find any evidence of that
> happening. Our applications logs are pretty good and we would have found
> some evidence.
>   We couldn't find the reason.
>   Our hypothesis was  that the cursor was lost and I was trying to find a
> way to verify that hypothesis through the Pulsar logs...looking if we had
> lost a broker or a bookie.
>   Initially, I thought that perhaps those 3 topics belonged to the same
> "bundle" and whenever the broker changed, the cursor was lost.
>   But Pulsar stores the cursor in the bookies, not the broker....so, a
> broker change shouldn't affect the cursor for the subscription (a shared
> subscription)
>   We haven't observed the same issue again.
>
>
>
> On Sat, Mar 12, 2022 at 7:21 AM PengHui Li <pe...@apache.org> wrote:
>
>> If you have TTL, the messages will be expired.
>> You mean "cursor was lost", how do you verify this?
>> to list subscriptions or not able to consume the message?
>> If it is the latter, I think it should be related to the message TTL.
>>
>> And how about the "brokerDeleteInactiveTopicsMode" in your broker
>> settings?
>> If you are using "delete_when_subscriptions_caught_up", after all the
>> message
>> been expired, the topic will be deleted automatically by default.
>>
>> Penghui
>>
>> On Sat, Mar 12, 2022 at 5:28 AM Tecno Brain <ce...@gmail.com>
>> wrote:
>>
>>> We do have a backlog quota and messageTTL
>>>
>>> Our namespace is configured as follows:
>>>
>>> Backlog quota:
>>>
>>>
>>> *"message_age    BacklogQuotaImpl(limit=-1, limitSize=-1,
>>> limitTime=180000, policy=consumer_backlog_eviction)"*
>>> Retention:
>>>
>>>
>>>
>>>
>>> *{  "retentionTimeInMinutes" : 0,  "retentionSizeInMB" : 0}*
>>>
>>> Message TTL:
>>>
>>> *172800*
>>>
>>> All topics are partitioned.
>>>
>>> *{
>>>   "partitions" : 3
>>> }*
>>>
>>>
>>> On Thu, Mar 10, 2022 at 11:24 PM PengHui Li <co...@gmail.com>
>>> wrote:
>>>
>>>> Have you changed the backlog quota policy or enabled the message TTL?
>>>> Pulsar will not remove any cursors or skip messages by default.
>>>>
>>>> Penghui
>>>> On Mar 11, 2022, 1:25 PM +0800, Tecno Brain <
>>>> cerebrotecnologico@gmail.com>, wrote:
>>>>
>>>> Hello,
>>>>  I have an application using Pulsar just as JMS (we get single
>>>> messages, acknowledge them when we are done processing it)
>>>>  The entire system, composed of several types of apps, uses about 40
>>>> different topics.
>>>>
>>>>  Yesterday, an application that subscribes to about 20 queues, suddenly
>>>> was inundated with thousands of messages from two of the queues but I could
>>>> not track those messages to an application producing them. We found that
>>>> the messages were *duplicates*.
>>>>   So it seems that the cursor to these two topics was lost, and
>>>> messages from 3 hours earlier were consumed again.  I found the following
>>>> paragraph :
>>>>
>>>>  "Each subscription stores a cursor. The cursor is the current offset
>>>> in the log. Subscriptions store their cursor in BookKeeper in ledgers. This
>>>> makes cursor tracking scalable just like topics."
>>>>  (
>>>> https://jack-vanlightly.com/blog/2018/10/2/understanding-how-apache-pulsar-works
>>>> )
>>>>
>>>> My guess is that the cursor was lost.
>>>> How could I verify that this was the case? I can't find anything
>>>> relevant in the logs.
>>>>
>>>> The only message I found occurring around the same time is
>>>>
>>>> New ensemble:
>>>> [pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>>> pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>>> pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181] is not
>>>> adhering to Placement Policy
>>>>
>>>> Any pointers are appreciated.
>>>>
>>>>
>>>>
>>>>

Re: Messages replayed

Posted by Tecno Brain <ce...@gmail.com>.
Hi Penghui,
   No, we are not seeing messages "disappear" because of TTL.
  What we observed is that messages from 3 out of 20  topics were
reprocessed.
  We initially thought that the messages were written again into the topic
by our own applications, but we did not find any evidence of that
happening. Our applications logs are pretty good and we would have found
some evidence.
  We couldn't find the reason.
  Our hypothesis was  that the cursor was lost and I was trying to find a
way to verify that hypothesis through the Pulsar logs...looking if we had
lost a broker or a bookie.
  Initially, I thought that perhaps those 3 topics belonged to the same
"bundle" and whenever the broker changed, the cursor was lost.
  But Pulsar stores the cursor in the bookies, not the broker....so, a
broker change shouldn't affect the cursor for the subscription (a shared
subscription)
  We haven't observed the same issue again.



On Sat, Mar 12, 2022 at 7:21 AM PengHui Li <pe...@apache.org> wrote:

> If you have TTL, the messages will be expired.
> You mean "cursor was lost", how do you verify this?
> to list subscriptions or not able to consume the message?
> If it is the latter, I think it should be related to the message TTL.
>
> And how about the "brokerDeleteInactiveTopicsMode" in your broker settings?
> If you are using "delete_when_subscriptions_caught_up", after all the
> message
> been expired, the topic will be deleted automatically by default.
>
> Penghui
>
> On Sat, Mar 12, 2022 at 5:28 AM Tecno Brain <ce...@gmail.com>
> wrote:
>
>> We do have a backlog quota and messageTTL
>>
>> Our namespace is configured as follows:
>>
>> Backlog quota:
>>
>>
>> *"message_age    BacklogQuotaImpl(limit=-1, limitSize=-1,
>> limitTime=180000, policy=consumer_backlog_eviction)"*
>> Retention:
>>
>>
>>
>>
>> *{  "retentionTimeInMinutes" : 0,  "retentionSizeInMB" : 0}*
>>
>> Message TTL:
>>
>> *172800*
>>
>> All topics are partitioned.
>>
>> *{
>>   "partitions" : 3
>> }*
>>
>>
>> On Thu, Mar 10, 2022 at 11:24 PM PengHui Li <co...@gmail.com>
>> wrote:
>>
>>> Have you changed the backlog quota policy or enabled the message TTL?
>>> Pulsar will not remove any cursors or skip messages by default.
>>>
>>> Penghui
>>> On Mar 11, 2022, 1:25 PM +0800, Tecno Brain <
>>> cerebrotecnologico@gmail.com>, wrote:
>>>
>>> Hello,
>>>  I have an application using Pulsar just as JMS (we get single messages,
>>> acknowledge them when we are done processing it)
>>>  The entire system, composed of several types of apps, uses about 40
>>> different topics.
>>>
>>>  Yesterday, an application that subscribes to about 20 queues, suddenly
>>> was inundated with thousands of messages from two of the queues but I could
>>> not track those messages to an application producing them. We found that
>>> the messages were *duplicates*.
>>>   So it seems that the cursor to these two topics was lost, and messages
>>> from 3 hours earlier were consumed again.  I found the following paragraph :
>>>
>>>  "Each subscription stores a cursor. The cursor is the current offset in
>>> the log. Subscriptions store their cursor in BookKeeper in ledgers. This
>>> makes cursor tracking scalable just like topics."
>>>  (
>>> https://jack-vanlightly.com/blog/2018/10/2/understanding-how-apache-pulsar-works
>>> )
>>>
>>> My guess is that the cursor was lost.
>>> How could I verify that this was the case? I can't find anything
>>> relevant in the logs.
>>>
>>> The only message I found occurring around the same time is
>>>
>>> New ensemble:
>>> [pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>> pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181,
>>> pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181] is not
>>> adhering to Placement Policy
>>>
>>> Any pointers are appreciated.
>>>
>>>
>>>
>>>

Re: Messages replayed

Posted by PengHui Li <pe...@apache.org>.
If you have TTL, the messages will be expired.
You mean "cursor was lost", how do you verify this?
to list subscriptions or not able to consume the message?
If it is the latter, I think it should be related to the message TTL.

And how about the "brokerDeleteInactiveTopicsMode" in your broker settings?
If you are using "delete_when_subscriptions_caught_up", after all the
message
been expired, the topic will be deleted automatically by default.

Penghui

On Sat, Mar 12, 2022 at 5:28 AM Tecno Brain <ce...@gmail.com>
wrote:

> We do have a backlog quota and messageTTL
>
> Our namespace is configured as follows:
>
> Backlog quota:
>
>
> *"message_age    BacklogQuotaImpl(limit=-1, limitSize=-1,
> limitTime=180000, policy=consumer_backlog_eviction)"*
> Retention:
>
>
>
>
> *{  "retentionTimeInMinutes" : 0,  "retentionSizeInMB" : 0}*
>
> Message TTL:
>
> *172800*
>
> All topics are partitioned.
>
> *{
>   "partitions" : 3
> }*
>
>
> On Thu, Mar 10, 2022 at 11:24 PM PengHui Li <co...@gmail.com>
> wrote:
>
>> Have you changed the backlog quota policy or enabled the message TTL?
>> Pulsar will not remove any cursors or skip messages by default.
>>
>> Penghui
>> On Mar 11, 2022, 1:25 PM +0800, Tecno Brain <ce...@gmail.com>,
>> wrote:
>>
>> Hello,
>>  I have an application using Pulsar just as JMS (we get single messages,
>> acknowledge them when we are done processing it)
>>  The entire system, composed of several types of apps, uses about 40
>> different topics.
>>
>>  Yesterday, an application that subscribes to about 20 queues, suddenly
>> was inundated with thousands of messages from two of the queues but I could
>> not track those messages to an application producing them. We found that
>> the messages were *duplicates*.
>>   So it seems that the cursor to these two topics was lost, and messages
>> from 3 hours earlier were consumed again.  I found the following paragraph :
>>
>>  "Each subscription stores a cursor. The cursor is the current offset in
>> the log. Subscriptions store their cursor in BookKeeper in ledgers. This
>> makes cursor tracking scalable just like topics."
>>  (
>> https://jack-vanlightly.com/blog/2018/10/2/understanding-how-apache-pulsar-works
>> )
>>
>> My guess is that the cursor was lost.
>> How could I verify that this was the case? I can't find anything relevant
>> in the logs.
>>
>> The only message I found occurring around the same time is
>>
>> New ensemble:
>> [pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181,
>> pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181,
>> pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181] is not
>> adhering to Placement Policy
>>
>> Any pointers are appreciated.
>>
>>
>>
>>

Re: Messages replayed

Posted by Tecno Brain <ce...@gmail.com>.
We do have a backlog quota and messageTTL

Our namespace is configured as follows:

Backlog quota:


*"message_age    BacklogQuotaImpl(limit=-1, limitSize=-1, limitTime=180000,
policy=consumer_backlog_eviction)"*
Retention:




*{  "retentionTimeInMinutes" : 0,  "retentionSizeInMB" : 0}*

Message TTL:

*172800*

All topics are partitioned.

*{
  "partitions" : 3
}*


On Thu, Mar 10, 2022 at 11:24 PM PengHui Li <co...@gmail.com> wrote:

> Have you changed the backlog quota policy or enabled the message TTL?
> Pulsar will not remove any cursors or skip messages by default.
>
> Penghui
> On Mar 11, 2022, 1:25 PM +0800, Tecno Brain <ce...@gmail.com>,
> wrote:
>
> Hello,
>  I have an application using Pulsar just as JMS (we get single messages,
> acknowledge them when we are done processing it)
>  The entire system, composed of several types of apps, uses about 40
> different topics.
>
>  Yesterday, an application that subscribes to about 20 queues, suddenly
> was inundated with thousands of messages from two of the queues but I could
> not track those messages to an application producing them. We found that
> the messages were *duplicates*.
>   So it seems that the cursor to these two topics was lost, and messages
> from 3 hours earlier were consumed again.  I found the following paragraph :
>
>  "Each subscription stores a cursor. The cursor is the current offset in
> the log. Subscriptions store their cursor in BookKeeper in ledgers. This
> makes cursor tracking scalable just like topics."
>  (
> https://jack-vanlightly.com/blog/2018/10/2/understanding-how-apache-pulsar-works
> )
>
> My guess is that the cursor was lost.
> How could I verify that this was the case? I can't find anything relevant
> in the logs.
>
> The only message I found occurring around the same time is
>
> New ensemble:
> [pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181,
> pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181,
> pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181] is not
> adhering to Placement Policy
>
> Any pointers are appreciated.
>
>
>
>

Re: Messages replayed

Posted by PengHui Li <co...@gmail.com>.
Have you changed the backlog quota policy or enabled the message TTL?
Pulsar will not remove any cursors or skip messages by default.

Penghui
On Mar 11, 2022, 1:25 PM +0800, Tecno Brain <ce...@gmail.com>, wrote:
> Hello,
>  I have an application using Pulsar just as JMS (we get single messages, acknowledge them when we are done processing it)
>  The entire system, composed of several types of apps, uses about 40 different topics.
>
>  Yesterday, an application that subscribes to about 20 queues, suddenly was inundated with thousands of messages from two of the queues but I could not track those messages to an application producing them. We found that the messages were duplicates.
>   So it seems that the cursor to these two topics was lost, and messages from 3 hours earlier were consumed again.  I found the following paragraph :
>
>  "Each subscription stores a cursor. The cursor is the current offset in the log. Subscriptions store their cursor in BookKeeper in ledgers. This makes cursor tracking scalable just like topics."
>  (https://jack-vanlightly.com/blog/2018/10/2/understanding-how-apache-pulsar-works)
>
> My guess is that the cursor was lost.
> How could I verify that this was the case? I can't find anything relevant in the logs.
>
> The only message I found occurring around the same time is
>
> New ensemble: [pulsar-bookie-2.pulsar-bookie.pulsar.svc.cluster.local:3181, pulsar-bookie-0.pulsar-bookie.pulsar.svc.cluster.local:3181, pulsar-bookie-3.pulsar-bookie.pulsar.svc.cluster.local:3181] is not adhering to Placement Policy
>
> Any pointers are appreciated.
>
>
>