Yike Xiao created ZOOKEEPER-4741:
------------------------------------
Summary: High latency under heavy load when prometheus metrics
enabled
Key: ZOOKEEPER-4741
URL: https://issues.apache.org/jira/browse/ZOOKEEPER-4741
Project: ZooKeeper
Issue Type: Bug
Components: server
Affects Versions: 3.8.2, 3.6.4
Environment: zookeeper version: 3.6.4
kernel: 3.10.0-1160.95.1.el7.x86_64
java version "1.8.0_111"
metricsProvider.className=org.apache.zookeeper.metrics.prometheus.PrometheusMetricsProvider
Reporter: Yike Xiao
Attachments: 32010.threaddump.001.txt, 32010.wallclock.profile.html,
image-2023-09-11-16-17-21-166.png
In our production, we use zookeeper built-in PrometheusMetricsProvider to
monitor zookeeper status, recently we observed very high latency in one of our
zookeeper cluster which serve heavy load.
Measured in a heavy client side, the latency could more than 25 seconds.
!image-2023-09-11-16-17-21-166.png! Observed many connections with high Recv-Q
on the server side.
CommitProcWorkThread *BLOCKED* in
{{{}org.apache.zookeeper.server.ServerStats#updateLatency:{}}}{{{}{}}}
"CommitProcWorkThread-15" #21595 daemon prio=5 os_prio=0 tid=0x00007f86d804a000
nid=0x6bca waiting for monitor entry [0x00007f86deb95000]
java.lang.Thread.State: BLOCKED (on object monitor) at
io.prometheus.client.CKMSQuantiles.insert(CKMSQuantiles.java:91) -
waiting to lock <0x0000000784dd1a18> (a io.prometheus.client.CKMSQuantiles)
at
io.prometheus.client.TimeWindowQuantiles.insert(TimeWindowQuantiles.java:38)
at io.prometheus.client.Summary$Child.observe(Summary.java:281) at
io.prometheus.client.Summary.observe(Summary.java:307) at
org.apache.zookeeper.metrics.prometheus.PrometheusMetricsProvider$PrometheusSummary.add(PrometheusMetricsProvider.java:355)
at
org.apache.zookeeper.server.ServerStats.updateLatency(ServerStats.java:153)
at
org.apache.zookeeper.server.FinalRequestProcessor.updateStats(FinalRequestProcessor.java:669)
at
org.apache.zookeeper.server.FinalRequestProcessor.processRequest(FinalRequestProcessor.java:585)
at
org.apache.zookeeper.server.quorum.CommitProcessor$CommitWorkRequest.doWork(CommitProcessor.java:545)
at
org.apache.zookeeper.server.WorkerService$ScheduledWorkRequest.run(WorkerService.java:154)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
The wall lock profile shows that there is lock contention within the
{{CommitProcWorkThread}} threads.
!https://gitlab.dev.zhaopin.com/sucheng.wang/notes/uploads/b9da2552d6b00c3f9130d87caf01325e/image.png!
{{}}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
