You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@pulsar.apache.org by GitBox <gi...@apache.org> on 2022/08/30 05:44:15 UTC
[GitHub] [pulsar] hrsakai opened a new pull request, #17343: [Broker] Fix many stacktrace log when concurrent mark delete.
hrsakai opened a new pull request, #17343:
URL: https://github.com/apache/pulsar/pull/17343
* I reopened #14486 as a new PR.
### Motivation
In my environment, sometimes found following logs.
```
2022-08-26T00:41:52,420+0000 [bookkeeper-ml-scheduler-OrderedScheduler-0-0] WARN org.apache.bookkeeper.mledger.impl.ManagedCursorImpl - [public/default/persistent/log-topic1][sub1] Failed to flush mark-delete position
org.apache.bookkeeper.mledger.ManagedLedgerException: java.lang.IllegalArgumentException: Mark deleting an already mark-deleted position. Current mark-delete: 49:106343 -- attempted mark delete: 49:106338
Caused by: java.lang.IllegalArgumentException: Mark deleting an already mark-deleted position. Current mark-delete: 49:106343 -- attempted mark delete: 49:106338
at org.apache.bookkeeper.mledger.impl.ManagedCursorImpl.setAcknowledgedPosition(ManagedCursorImpl.java:1722) ~[managed-ledger.jar:2.11.0-SNAPSHOT]
at org.apache.bookkeeper.mledger.impl.ManagedCursorImpl.asyncMarkDelete(ManagedCursorImpl.java:1862) ~[managed-ledger.jar:2.11.0-SNAPSHOT]
at org.apache.bookkeeper.mledger.impl.ManagedCursorImpl.flush(ManagedCursorImpl.java:3254) ~[managed-ledger.jar:2.11.0-SNAPSHOT]
at org.apache.bookkeeper.mledger.impl.ManagedLedgerFactoryImpl.lambda$flushCursors$1(ManagedLedgerFactoryImpl.java:240) ~[managed-ledger.jar:2.11.0-SNAPSHOT]
at java.lang.Iterable.forEach(Iterable.java:75) ~[?:?]
at org.apache.bookkeeper.mledger.impl.ManagedLedgerFactoryImpl.lambda$flushCursors$2(ManagedLedgerFactoryImpl.java:240) ~[managed-ledger.jar:2.11.0-SNAPSHOT]
at java.util.concurrent.ConcurrentHashMap$ValuesView.forEach(ConcurrentHashMap.java:4780) ~[?:?]
at org.apache.bookkeeper.mledger.impl.ManagedLedgerFactoryImpl.flushCursors(ManagedLedgerFactoryImpl.java:236) ~[managed-ledger.jar:2.11.0-SNAPSHOT]
at org.apache.pulsar.common.util.Runnables$CatchingAndLoggingRunnable.run(Runnables.java:54) ~[pulsar-common.jar:2.11.0-SNAPSHOT]
at org.apache.bookkeeper.common.util.OrderedExecutor$TimedRunnable.run(OrderedExecutor.java:214) ~[bookkeeper-common-4.15.0.jar:4.15.0]
at com.google.common.util.concurrent.MoreExecutors$ScheduledListeningDecorator$NeverSuccessfulListenableFutureTask.run(MoreExecutors.java:718) ~[guava-31.0.1-jre.jar:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.77.Final.jar:4.1.77.Final]
at java.lang.Thread.run(Thread.java:833) ~[?:?]
```
* This is because periodic flush try to update mark delete position to old position.
In the log above, it tried to update mark delete position from `49:106343` to `49:106338`.
### Modifications
* Logging with debug level because the marker location was already marked for deletion.
### Reproduces
* Start standalone with `managedLedgerCursorPositionFlushSeconds=1 `
* Create a producer and consumer with same topic.
* Continue to send and recieve/acknowledge messages.
* Wait a minute and it will happen.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] hrsakai commented on pull request #17343: [Broker] Fix many stacktrace log when concurrent mark delete.
Posted by GitBox <gi...@apache.org>.
hrsakai commented on PR #17343:
URL: https://github.com/apache/pulsar/pull/17343#issuecomment-1233778351
/pulsarbot rerun-failure-checks
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] AnonHxy commented on pull request #17343: [Broker] Fix many stacktrace log when concurrent mark delete.
Posted by GitBox <gi...@apache.org>.
AnonHxy commented on PR #17343:
URL: https://github.com/apache/pulsar/pull/17343#issuecomment-1231190845
Should we set `isDirty` as true if we pass the `markDeleteLimiter` and new markDeletePosition is greater than `lastMarkDeleteEntry`?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] github-actions[bot] commented on pull request #17343: [Broker] Fix many stacktrace log when concurrent mark delete.
Posted by GitBox <gi...@apache.org>.
github-actions[bot] commented on PR #17343:
URL: https://github.com/apache/pulsar/pull/17343#issuecomment-1269217772
The pr had no activity for 30 days, mark with Stale label.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] hrsakai commented on pull request #17343: [Broker] Fix many stacktrace log when concurrent mark delete.
Posted by GitBox <gi...@apache.org>.
hrsakai commented on PR #17343:
URL: https://github.com/apache/pulsar/pull/17343#issuecomment-1233777823
@AnonHxy
I don't know we should do that.
At least in my environment, just before calling asyncMarkDelete in ManagedCursorImpl#flush, `lastMarkDeleteEntry.newPosition` and `markDeletePosition` were same position(when the above log was output, they were `49:106338`), so I think we can't avoid this issue even if set isDirty as true.
https://github.com/apache/pulsar/blob/46b1239a23fd2a250b009df1e9b4a65341d299a7/managed-ledger/src/main/java/org/apache/bookkeeper/mledger/impl/ManagedCursorImpl.java#L3259
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] hrsakai closed pull request #17343: [Broker] Fix many stacktrace log when concurrent mark delete.
Posted by GitBox <gi...@apache.org>.
hrsakai closed pull request #17343: [Broker] Fix many stacktrace log when concurrent mark delete.
URL: https://github.com/apache/pulsar/pull/17343
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org