nodece opened a new pull request, #25990:
URL: https://github.com/apache/pulsar/pull/25990
### Motivation
Under large-scale delayed delivery workload (~500M delayed messages), stats
collection paths
are blocked by dispatcher lock contention.
Multiple threads are observed in `BLOCKED` state during jstack analysis:
```
"pulsar-2-1" #131 [182] prio=5 os_prio=0 cpu=201.27ms elapsed=494.51s
allocated=8993K defined_classes=97 tid=0x00007feab30cdee0 nid=182 waiting for
monitor entry [0x00007feab26d2000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers.getDelayedTrackerMemoryUsage(PersistentDispatcherMultipleConsumers.java:1455)
- waiting to lock <0x00000007039b0bc8> (a
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers)
at
org.apache.pulsar.broker.service.persistent.PersistentSubscription.getStatsAsync(PersistentSubscription.java:1410)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.lambda$asyncGetStats$113(PersistentTopic.java:2978)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic$$Lambda/0x0000000800ce9a60.accept(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.forEach([email protected]/Unknown Source)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.asyncGetStats(PersistentTopic.java:2977)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.asyncGetStats(PersistentTopic.java:2849)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.getStats(PersistentTopic.java:2827)
at
org.apache.pulsar.broker.service.BrokerService.lambda$getTopicStats$150(BrokerService.java:2921)
--
at
java.util.concurrent.ThreadPoolExecutor.runWorker([email protected]/Unknown
Source)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run([email protected]/Unknown
Source)
at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.runWith([email protected]/Unknown Source)
at java.lang.Thread.run([email protected]/Unknown Source)
Locked ownable synchronizers:
- None
"pulsar-web-55-1" #137 [188] prio=5 os_prio=0 cpu=2211.82ms elapsed=494.06s
allocated=607M defined_classes=258 tid=0x00007feab397fee0 nid=188 waiting for
monitor entry [0x00007feab228d000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers.getDelayedTrackerMemoryUsage(PersistentDispatcherMultipleConsumers.java:1455)
- waiting to lock <0x00000007039b0bc8> (a
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers)
at
org.apache.pulsar.broker.service.persistent.PersistentSubscription.getStatsAsync(PersistentSubscription.java:1410)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.lambda$asyncGetStats$113(PersistentTopic.java:2978)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic$$Lambda/0x0000000800ce9a60.accept(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.forEach([email protected]/Unknown Source)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.asyncGetStats(PersistentTopic.java:2977)
at
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase.lambda$internalGetPartitionedStats$166(PersistentTopicsBase.java:1523)
at
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase$$Lambda/0x0000000800d1e490.apply(Unknown
Source)
at
java.util.concurrent.CompletableFuture.uniComposeStage([email protected]/Unknown
Source)
--
at
java.util.concurrent.ThreadPoolExecutor.runWorker([email protected]/Unknown
Source)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run([email protected]/Unknown
Source)
at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.runWith([email protected]/Unknown Source)
at java.lang.Thread.run([email protected]/Unknown Source)
Locked ownable synchronizers:
- <0x000000070222bdd0> (a
java.util.concurrent.ThreadPoolExecutor$Worker)
"pulsar-web-55-4" #140 [191] prio=5 os_prio=0 cpu=2278.78ms elapsed=494.06s
allocated=672M defined_classes=63 tid=0x00007feab39816e0 nid=191 waiting for
monitor entry [0x00007feab1f73000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers.getDelayedTrackerMemoryUsage(PersistentDispatcherMultipleConsumers.java:1455)
- waiting to lock <0x00000007039b0bc8> (a
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers)
at
org.apache.pulsar.broker.service.persistent.PersistentSubscription.getStatsAsync(PersistentSubscription.java:1410)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.lambda$asyncGetStats$113(PersistentTopic.java:2978)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic$$Lambda/0x0000000800ce9a60.accept(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.forEach([email protected]/Unknown Source)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.asyncGetStats(PersistentTopic.java:2977)
at
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase.lambda$internalGetPartitionedStats$166(PersistentTopicsBase.java:1523)
at
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase$$Lambda/0x0000000800d1e490.apply(Unknown
Source)
at
java.util.concurrent.CompletableFuture.uniComposeStage([email protected]/Unknown
Source)
--
at
java.util.concurrent.ThreadPoolExecutor.runWorker([email protected]/Unknown
Source)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run([email protected]/Unknown
Source)
at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.runWith([email protected]/Unknown Source)
at java.lang.Thread.run([email protected]/Unknown Source)
Locked ownable synchronizers:
- <0x000000070225c288> (a
java.util.concurrent.ThreadPoolExecutor$Worker)
"pulsar-web-55-5" #141 [192] prio=5 os_prio=0 cpu=2058.77ms elapsed=494.06s
allocated=561M defined_classes=100 tid=0x00007feab384a010 nid=192 waiting for
monitor entry [0x00007feab1e73000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers.getDelayedTrackerMemoryUsage(PersistentDispatcherMultipleConsumers.java:1455)
- waiting to lock <0x00000007039b0bc8> (a
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers)
at
org.apache.pulsar.broker.service.persistent.PersistentSubscription.getStatsAsync(PersistentSubscription.java:1410)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.lambda$asyncGetStats$113(PersistentTopic.java:2978)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic$$Lambda/0x0000000800ce9a60.accept(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.forEach([email protected]/Unknown Source)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.asyncGetStats(PersistentTopic.java:2977)
at
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase.lambda$internalGetPartitionedStats$166(PersistentTopicsBase.java:1523)
at
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase$$Lambda/0x0000000800d1e490.apply(Unknown
Source)
at
java.util.concurrent.CompletableFuture.uniComposeStage([email protected]/Unknown
Source)
--
at
java.util.concurrent.ThreadPoolExecutor.runWorker([email protected]/Unknown
Source)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run([email protected]/Unknown
Source)
at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.runWith([email protected]/Unknown Source)
at java.lang.Thread.run([email protected]/Unknown Source)
Locked ownable synchronizers:
- <0x000000070222bea0> (a
java.util.concurrent.ThreadPoolExecutor$Worker)
"pulsar-web-55-6" #142 [193] prio=5 os_prio=0 cpu=2394.23ms elapsed=494.06s
allocated=676M defined_classes=290 tid=0x00007feab384a800 nid=193 waiting for
monitor entry [0x00007feab1d72000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers.getDelayedTrackerMemoryUsage(PersistentDispatcherMultipleConsumers.java:1455)
- waiting to lock <0x00000007039b0bc8> (a
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers)
at
org.apache.pulsar.broker.service.persistent.PersistentSubscription.getStatsAsync(PersistentSubscription.java:1410)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.lambda$asyncGetStats$113(PersistentTopic.java:2978)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic$$Lambda/0x0000000800ce9a60.accept(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.forEach([email protected]/Unknown Source)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.asyncGetStats(PersistentTopic.java:2977)
at
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase.lambda$internalGetStatsAsync$146(PersistentTopicsBase.java:1350)
at
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase$$Lambda/0x0000000800d03818.apply(Unknown
Source)
at
java.util.concurrent.CompletableFuture.uniComposeStage([email protected]/Unknown
Source)
--
at
java.util.concurrent.ThreadPoolExecutor.runWorker([email protected]/Unknown
Source)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run([email protected]/Unknown
Source)
at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.runWith([email protected]/Unknown Source)
at java.lang.Thread.run([email protected]/Unknown Source)
Locked ownable synchronizers:
- <0x000000070225c348> (a
java.util.concurrent.ThreadPoolExecutor$Worker)
"pulsar-web-55-7" #143 [194] prio=5 os_prio=0 cpu=2269.39ms elapsed=494.06s
allocated=634M defined_classes=122 tid=0x00007feab384b000 nid=194 waiting for
monitor entry [0x00007feab1c71000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers.getDelayedTrackerMemoryUsage(PersistentDispatcherMultipleConsumers.java:1455)
- waiting to lock <0x00000007039b0bc8> (a
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers)
at
org.apache.pulsar.broker.service.persistent.PersistentSubscription.getStatsAsync(PersistentSubscription.java:1410)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.lambda$asyncGetStats$113(PersistentTopic.java:2978)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic$$Lambda/0x0000000800ce9a60.accept(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.forEach([email protected]/Unknown Source)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.asyncGetStats(PersistentTopic.java:2977)
at
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase.lambda$internalGetPartitionedStats$166(PersistentTopicsBase.java:1523)
at
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase$$Lambda/0x0000000800d1e490.apply(Unknown
Source)
at
java.util.concurrent.CompletableFuture.uniComposeStage([email protected]/Unknown
Source)
--
at
java.util.concurrent.ThreadPoolExecutor.runWorker([email protected]/Unknown
Source)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run([email protected]/Unknown
Source)
at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.runWith([email protected]/Unknown Source)
at java.lang.Thread.run([email protected]/Unknown Source)
Locked ownable synchronizers:
- <0x000000070222c9e8> (a
java.util.concurrent.ThreadPoolExecutor$Worker)
"pulsar-web-55-8" #144 [195] prio=5 os_prio=0 cpu=1943.69ms elapsed=494.06s
allocated=547M defined_classes=53 tid=0x00007feab384b810 nid=195 waiting for
monitor entry [0x00007feab1b6f000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers.getDelayedTrackerMemoryUsage(PersistentDispatcherMultipleConsumers.java:1455)
- waiting to lock <0x00000007039b0bc8> (a
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers)
at
org.apache.pulsar.broker.service.persistent.PersistentSubscription.getStatsAsync(PersistentSubscription.java:1410)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.lambda$asyncGetStats$113(PersistentTopic.java:2978)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic$$Lambda/0x0000000800ce9a60.accept(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.forEach([email protected]/Unknown Source)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.asyncGetStats(PersistentTopic.java:2977)
at
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase.lambda$internalGetPartitionedStats$166(PersistentTopicsBase.java:1523)
at
org.apache.pulsar.broker.admin.impl.PersistentTopicsBase$$Lambda/0x0000000800d1e490.apply(Unknown
Source)
at
java.util.concurrent.CompletableFuture.uniComposeStage([email protected]/Unknown
Source)
--
at
java.util.concurrent.ForkJoinPool.unmanagedBlock([email protected]/Unknown
Source)
at
java.util.concurrent.ForkJoinPool.managedBlock([email protected]/Unknown Source)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await([email protected]/Unknown
Source)
at
java.util.concurrent.LinkedBlockingQueue.take([email protected]/Unknown Source)
at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:537)
Locked ownable synchronizers:
- None
"prometheus-stats-56-1" #373 [419] prio=5 os_prio=0 cpu=266.78ms
elapsed=486.95s allocated=25570K defined_classes=125 tid=0x00007feaa3ad96a0
nid=419 waiting for monitor entry [0x00007feaa560c000]
java.lang.Thread.State: BLOCKED (on object monitor)
at
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers.getDelayedTrackerMemoryUsage(PersistentDispatcherMultipleConsumers.java:1455)
- waiting to lock <0x00000007039b0bc8> (a
org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers)
at
org.apache.pulsar.broker.service.persistent.PersistentSubscription.getStatsAsync(PersistentSubscription.java:1410)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.lambda$asyncGetStats$113(PersistentTopic.java:2978)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic$$Lambda/0x0000000800ce9a60.accept(Unknown
Source)
at
java.util.concurrent.ConcurrentHashMap.forEach([email protected]/Unknown Source)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.asyncGetStats(PersistentTopic.java:2977)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.asyncGetStats(PersistentTopic.java:2849)
at
org.apache.pulsar.broker.service.persistent.PersistentTopic.getStats(PersistentTopic.java:2827)
at
org.apache.pulsar.broker.stats.prometheus.NamespaceStatsAggregator.getTopicStats(NamespaceStatsAggregator.java:223)
````
### Modifications
Remove unnecessary synchronization in delayed delivery stats read path.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
