[GitHub] [zookeeper] kezhuw commented on a diff in pull request #1989: ZOOKEEPER-4216: Fix a race condition in WatcherCleanerTest.testDeadWatcherMetrics

["kezhuw (via GitHub)" <gi...@apache.org>]

kezhuw commented on code in PR #1989:
URL: https://github.com/apache/zookeeper/pull/1989#discussion_r1145649475


##########
zookeeper-server/src/test/java/org/apache/zookeeper/server/watch/WatcherCleanerTest.java:
##########
@@ -156,19 +156,19 @@ public void testDeadWatcherMetrics() {
         assertTrue(listener.wait(5000));
 
         Map<String, Object> values = MetricsUtils.currentServerMetrics();
-        assertThat("Adding dead watcher should be stalled twice", (Long) values.get("add_dead_watcher_stall_time"), greaterThan(0L));
-        assertEquals(3L, values.get("dead_watchers_queued"), "Total dead watchers added to the queue should be 3");
-        assertEquals(3L, values.get("dead_watchers_cleared"), "Total dead watchers cleared should be 3");
-
-        assertEquals(3L, values.get("cnt_dead_watchers_cleaner_latency"));
-
-        //Each latency should be a little over 20 ms, allow 20 ms deviation
-        assertEquals(20D, (Double) values.get("avg_dead_watchers_cleaner_latency"), 20);
-        assertEquals(20D, ((Long) values.get("min_dead_watchers_cleaner_latency")).doubleValue(), 20);
-        assertEquals(20D, ((Long) values.get("max_dead_watchers_cleaner_latency")).doubleValue(), 20);
-        assertEquals(20D, ((Long) values.get("p50_dead_watchers_cleaner_latency")).doubleValue(), 20);
-        assertEquals(20D, ((Long) values.get("p95_dead_watchers_cleaner_latency")).doubleValue(), 20);
-        assertEquals(20D, ((Long) values.get("p99_dead_watchers_cleaner_latency")).doubleValue(), 20);
+        // Adding dead watcher should be stalled twice
+        waitForMetric("add_dead_watcher_stall_time", greaterThan(0L));
+        waitForMetric("dead_watchers_queued", is(3L));
+        waitForMetric("dead_watchers_cleared", is(3L));
+        waitForMetric("cnt_dead_watchers_cleaner_latency", is(3L));
+
+        //Each latency should be a little over 20 ms, allow 5 ms deviation

Review Comment:
   Seems that we rollback ZOOKEEPER-4200(#1592) after `waitForMetric`. I am not sure whether this is a regression. But I think ZOOKEEPER-4200 could also caused by concurrency in `avg` assertion and not atomic `DEAD_WATCHERS_CLEANER_LATENCY.add(latency)`. I am neutral to this change. But `max` is more likely to fail in loaded environment. Maybe we can treat `max` a little special ? What do you think ? @ztzg @eolivelli 
   
   https://github.com/apache/zookeeper/blob/e50a0bbae1bc0b812ac2656f5ba3f9eab7c3d62e/zookeeper-server/src/main/java/org/apache/zookeeper/server/metric/AvgMinMaxCounter.java#L44-L49
   
   https://github.com/apache/zookeeper/blob/e50a0bbae1bc0b812ac2656f5ba3f9eab7c3d62e/zookeeper-server/src/main/java/org/apache/zookeeper/server/metric/AvgMinMaxCounter.java#L65-L76



##########
zookeeper-server/src/test/java/org/apache/zookeeper/ZKTestCase.java:
##########
@@ -114,4 +120,36 @@ public void waitFor(String msg, WaitForCondition condition, int timeout) throws
         fail(msg);
     }
 
-}
+    public static <T> void waitForMetric(String metricKey, Matcher<T> matcher) throws InterruptedException {
+        waitForMetric(metricKey, matcher, DEFAULT_METRIC_TIMEOUT);
+    }
+
+    public static <T> void waitForMetric(String metricKey, Matcher<T> matcher, int timeoutInSeconds) throws InterruptedException {
+        String errorMessage = String.format("metric \"%s\" failed to match after %d seconds",
+            metricKey, timeoutInSeconds);
+        waitFor(errorMessage, () -> {
+            @SuppressWarnings("unchecked")
+            T actual = (T) MetricsUtils.currentServerMetrics().get(metricKey);
+            if (!matcher.matches(actual)) {
+                Description description = new StringDescription();
+                matcher.describeMismatch(actual, description);
+                LOG.info("match failed for metric {}: {}", metricKey, description);

Review Comment:
   This message might be distractive in success case. Given that this method is moved from `LearnerMetricsTest`, I think we could refactor it in separated jira to log matcher description only in failure case.



##########
zookeeper-server/src/test/java/org/apache/zookeeper/server/watch/WatcherCleanerTest.java:
##########
@@ -156,19 +156,19 @@ public void testDeadWatcherMetrics() {
         assertTrue(listener.wait(5000));
 
         Map<String, Object> values = MetricsUtils.currentServerMetrics();

Review Comment:
   `values` is useless now.



-- 
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: notifications-unsubscribe@zookeeper.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org