Add zk-stats instrumentation to get zk-client stats #507

rdhabalia · 2017-06-20T23:12:30Z

Motivation

Right now, broker doesn't have zk-client stats to measure zk-operation count and its latency. So, added instrumentation to measure zk-client operation latency.

Modifications

Introduce new ZkClientFactory: ZookeeperBkClientFactoryImpl which uses ZookeeperClient implemented in Bookkeeper which by default sends request-creation time in ctx which can be used to measure latency when broker receives zk-response back.
Added instrumentation measures zk-operation latency and captured it as a part of broker-metrics.

Result

Broker's metrics will have zk-operation latency.

merlimat · 2017-06-29T18:52:00Z

@rdhabalia I'll get to this one soon

merlimat

Few minor comments. Though I don't completely understand if the AOT part is needed if we are going to wrap the ZooKeeper client class.

Can't the latency measurement be done in the ZK client wrapper?

merlimat · 2017-07-10T22:10:04Z

pulsar-broker/src/main/java/org/apache/pulsar/broker/stats/DimensionStats.java

+        this.dimensionCounts = dimensionHistogram.getTotalCount();
+    }
+
+    public void recordDimensionTimeValue(long latency) {


latency should have the time unit in the var name, or we should accept a separate TimeUnit arg

merlimat · 2017-07-10T22:11:18Z

pulsar-broker/src/main/java/org/apache/pulsar/broker/stats/DimensionStats.java

+
+    public double elapsedIntervalMs;
+
+    private Recorder dimensionTimeRecorder = new Recorder(TimeUnit.MINUTES.toMillis(10), 2);


Instead of using the HdrHistogram here, we could use the Prometheus client lib. It has the same support for the quantiles and it will get automatically exposed and reported in the /metrics REST handler

here, we have renamed PulsarStats to DimensionStats which is used to record BrokerOperatabilityMetrics- topicLoadLatency + Zk-read/write latency which metrics we use along with Prometheus.
Do you think we can keep it here and add into Prometheus also else, we have to make changes into monitoring tool to parse Prometheus output to just get zk-latency.??

Even if you're not getting it from /metics, you can anyway use the prometheus Java lib in the same way as the HdrHistogram, querying to get the percentiles out of it.

Sure, I have replaced HdrHistogram with Prometheus.Summary.

merlimat · 2017-07-10T22:18:52Z

pulsar-broker/src/main/java/org/apache/pulsar/broker/zookeeper/aspectj/ClientCnxnAspect.java

+        return null;
+    }
+
+    public static void addListner(EventListner listener) {


addListener

merlimat · 2017-07-10T22:19:27Z

pulsar-broker/src/main/java/org/apache/pulsar/broker/zookeeper/aspectj/ClientCnxnAspect.java

+                Record response = (Record) field.get(packet);
+                return response;
+            }
+        } catch (Exception e) {


This would silently mask the exception

do you think we should do warn logging here?
actually, as we are using reflection and if in future field-name or anything changed which throws exception then it can entirely fill out logs so, I made it as debug-log.

merlimat · 2017-07-10T22:20:43Z

pulsar-broker/src/main/java/org/apache/pulsar/broker/service/BrokerService.java

@@ -189,6 +190,10 @@ public BrokerService(PulsarService pulsar) throws Exception {

        this.multiLayerTopicsMap = new ConcurrentOpenHashMap<>();
        this.pulsarStats = new PulsarStats(pulsar);
+        // register listener to capture zk-latency
+        ClientCnxnAspect.addListner((eventType, latencyMs) -> {
+            this.pulsarStats.recordZkLatencyTimeValue(eventType, latencyMs);


We should also record fractions of Millis, since the getData() operations are going to be in the order of 0.1 to 0.5 millis most of the time

Actually, right now, we are using BK-Yahoo version where BK-ZK-Client captures startTime in Msec and it doesn't have OpStatsLoggger yet. And it seems both the things are fixed in BK-master.
Therefore, startTime is milliseconds, it's not possible to capture time < 1 msec for now. We can do it once we move to latest BK version.

What about importing the BookkeeperClient.java source file from bk master?

rdhabalia · 2017-07-10T23:09:58Z

Can't the latency measurement be done in the ZK client wrapper?

Latency is measured against ZK-Client org.apache.zookeeper.ClientCnxn only. So, you mean ClientCnxnAspect should not be part of pulsar-broker and part of other module?

Though I don't completely understand if the AOT part is needed if we are going to wrap the ZooKeeper client class.

Not, completely understand your comment. But in this PR we are loading AOT-agent at runtime because of that we don't have to define agent in jvm-args and we can test aspect with unit-test.
In previous ZK-server-aspect PR, we don't have any unit-test case because we can't weave aspectj- advice in unit-test so, hard to test as well. So, do you think we should load aspectj-agent at runtime rather passing as jvm-args in zk-server AOT?

merlimat · 2017-07-10T23:21:58Z

Latency is measured against ZK-Client org.apache.zookeeper.ClientCnxn only. So, you mean ClientCnxnAspect should not be part of pulsar-broker and part of other module?

What I was meaning is that since you mention the ZookeeperClient from BK, that wrapper is already collecting the latency stats (through the StatsLogger mechanism). Isn't that enough to collect and report the latencies?

rdhabalia · 2017-07-11T00:29:21Z

What I was meaning is that since you mention the ZookeeperClient from BK, that wrapper is already collecting the latency stats (through the StatsLogger mechanism).

OpStatsLogger is not present into BK-Yahoo version

merlimat · 2017-07-11T00:39:12Z

I know, that's why I was saying whether it was easier to just import the code, until we sync up with future BK releases :)

…

-- Matteo Merli <matteo.merli@gmail.com>

On Mon, Jul 10, 2017 at 5:29 PM, Rajan Dhabalia ***@***.***> wrote: What I was meaning is that since you mention the ZookeeperClient from BK, that wrapper is already collecting the latency stats (through the StatsLogger mechanism). OpStatsLogger <https://github.com/apache/bookkeeper/blob/master/bookkeeper-server/src/main/java/org/apache/bookkeeper/zookeeper/ZooWorker.java#L45> is not present into BK-Yahoo version <https://github.com/yahoo/bookkeeper/blob/yahoo-4.3/bookkeeper-server/src/main/java/org/apache/bookkeeper/zookeeper/ZooWorker.java> — You are receiving this because your review was requested. Reply to this email directly, view it on GitHub <#507 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAD0JPZ8ODbPwZi9Sz61Dmx2NK-dJS0cks5sMsHhgaJpZM4OARCW> .

rdhabalia · 2017-07-11T19:09:06Z

@merlimat Addressed all the changes.

merlimat

👍 Looks good. Just 2 very minor suggestions.

For the long run, let's try to collect the stats in the wrapper (maybe when using latest BK) so that we don't need to instrument the code and we can get sub-millis resolution

merlimat · 2017-07-11T19:17:42Z

pulsar-broker/src/main/java/org/apache/pulsar/broker/stats/DimensionStats.java

+    }
+
+    public double getDimensionSum() {
+        return defaultRegistry.getSampleValue(name + "_sum").doubleValue();


Can save the name + "_sum" (and count) into a member variable to avoid recreating the string each time

merlimat · 2017-07-11T19:18:28Z

pulsar-broker/src/main/java/org/apache/pulsar/broker/stats/DimensionStats.java

+
+    private double getQuantile(double q) {
+        return defaultRegistry
+                .getSampleValue(name, new String[] { "quantile" }, new String[] { Collector.doubleToGoString(q) })


Can the String[] be cached?

rdhabalia · 2017-07-11T20:45:31Z

pom.xml

@@ -479,6 +479,13 @@ flexible messaging model and an intuitive client API.</description>
        <artifactId>aspectjweaver</artifactId>
        <version>${aspectj.version}</version>
      </dependency>
+
+	  <!-- TODO: should we callout BSD license: https://github.com/electronicarts/ea-agent-loader -->


@merlimat Do you think we should add BSD license into NOTICE file?

I think it should only be added to the NOTICE file that gets included in the binary distribution, not in the sources one, because there we're not including it.

I did some initial work in collecting the list of dependencies and the licenses to adjust the LICENSE and NOTICE files for both bin and src tgzs. You can leave it out for now, and remove the TODO comment. We'll fix it along with all the other dependencies.

merlimat · 2017-07-13T17:35:47Z

@rdhabalia I think the build started failing after this commit got merged:

https://travis-ci.org/apache/incubator-pulsar/builds/252621888

Do you have any idea what could it be?

rdhabalia · 2017-07-13T17:37:58Z

let me check.. actually I have merged after PR-travis build passed.

merlimat · 2017-07-13T17:43:54Z

Yes, I saw. Initially I thought the problem was about my commit upgrading the Jna library, but it fails consistently on local build even before that commit.

merlimat · 2017-07-13T18:12:49Z

@rdhabalia I did a git bisect locally and it started failing at this commit :)

It reproduces consistently on local build.

rdhabalia added the type/feature The PR added a new feature or issue requested a new feature label Jun 20, 2017

rdhabalia added this to the 1.19 milestone Jun 20, 2017

rdhabalia self-assigned this Jun 20, 2017

rdhabalia mentioned this pull request Jun 20, 2017

introduce zk-stats: zk-latency + zk-rate #320

Closed

rdhabalia force-pushed the zk_aspect branch 4 times, most recently from 59dac64 to cda9d0a Compare June 21, 2017 18:31

rdhabalia force-pushed the zk_aspect branch 2 times, most recently from acd8341 to c7c465b Compare June 28, 2017 00:55

Add zk-stats instrumentation to get zk-client stats

ce73e74

rdhabalia force-pushed the zk_aspect branch from c7c465b to ce73e74 Compare June 28, 2017 00:56

rdhabalia requested a review from merlimat June 28, 2017 00:57

merlimat reviewed Jul 10, 2017

View reviewed changes

fix: listnerTypo + add timeUnit

56d9405

Add Prometheus for dimension metrics instead histogram

ce6cc72

merlimat approved these changes Jul 11, 2017

View reviewed changes

caching string variable

14f4029

rdhabalia commented Jul 11, 2017

View reviewed changes

rdhabalia added 2 commits July 11, 2017 15:04

remove pom: todo

9d10f85

Fix: duplicate summary registration for unit-test

8035914

rdhabalia merged commit bb0a8fb into apache:master Jul 11, 2017

Technoboy- mentioned this pull request Jun 2, 2023

[improve][broker] Add metric prefix for topic_load_times #20472

Merged

4 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add zk-stats instrumentation to get zk-client stats #507

Add zk-stats instrumentation to get zk-client stats #507

rdhabalia commented Jun 20, 2017

merlimat commented Jun 29, 2017

merlimat left a comment

merlimat Jul 10, 2017

merlimat Jul 10, 2017

rdhabalia Jul 11, 2017

merlimat Jul 11, 2017

rdhabalia Jul 11, 2017

merlimat Jul 10, 2017

merlimat Jul 10, 2017

rdhabalia Jul 11, 2017

merlimat Jul 10, 2017

rdhabalia Jul 11, 2017

merlimat Jul 11, 2017

rdhabalia commented Jul 10, 2017

merlimat commented Jul 10, 2017

rdhabalia commented Jul 11, 2017

merlimat commented Jul 11, 2017 via email

rdhabalia commented Jul 11, 2017

merlimat left a comment

merlimat Jul 11, 2017

merlimat Jul 11, 2017

rdhabalia Jul 11, 2017

merlimat Jul 11, 2017

merlimat commented Jul 13, 2017

rdhabalia commented Jul 13, 2017

merlimat commented Jul 13, 2017

merlimat commented Jul 13, 2017


		public double elapsedIntervalMs;

		private Recorder dimensionTimeRecorder = new Recorder(TimeUnit.MINUTES.toMillis(10), 2);

Add zk-stats instrumentation to get zk-client stats #507

Add zk-stats instrumentation to get zk-client stats #507

Conversation

rdhabalia commented Jun 20, 2017

Motivation

Modifications

Result

merlimat commented Jun 29, 2017

merlimat left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

rdhabalia commented Jul 10, 2017

merlimat commented Jul 10, 2017

rdhabalia commented Jul 11, 2017

merlimat commented Jul 11, 2017 via email

rdhabalia commented Jul 11, 2017

merlimat left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

merlimat commented Jul 13, 2017

rdhabalia commented Jul 13, 2017

merlimat commented Jul 13, 2017

merlimat commented Jul 13, 2017