commit de2bf29a317ded2e393b7e8a0122849b484b044f
author EdColeman <dev1@etcoleman.com> Wed Apr 29 10:29:50 2020 -0400
committer GitHub <noreply@github.com> Wed Apr 29 10:29:50 2020 -0400
tree b13d022012641eb120ee378e7048e0676b42922e
parent c4c15d715efe4f1f9eef179e95971cb8011492ad

Improve GcMetricsIT adding timestamp check. (#1597)

Fix #1591. Added check so that the metrics timestamp must be later than test or last update
for the metrics to be valid to address issues with jenkins testing.  Concurrent
test may still be an issue.

test/src/main/java/org/apache/accumulo/test/functional/GcMetricsIT.java

diff --git a/test/src/main/java/org/apache/accumulo/test/functional/GcMetricsIT.java b/test/src/main/java/org/apache/accumulo/test/functional/GcMetricsIT.java
index 083a1ab..355844e 100644
--- a/test/src/main/java/org/apache/accumulo/test/functional/GcMetricsIT.java
+++ b/test/src/main/java/org/apache/accumulo/test/functional/GcMetricsIT.java
@@ -22,8 +22,11 @@
 
 import java.util.Collections;
 import java.util.Map;
+import java.util.Objects;
 import java.util.TreeMap;
 import java.util.concurrent.TimeUnit;
+import java.util.regex.Matcher;
+import java.util.regex.Pattern;
 
 import org.apache.accumulo.core.client.Accumulo;
 import org.apache.accumulo.core.client.AccumuloClient;
@@ -77,7 +80,7 @@
         cluster.getSiteConfiguration().getBoolean(Property.GC_METRICS_ENABLED);
 
     if (!gcMetricsEnabled) {
-      log.info("gc metrics are disabled with GC_METRICS_ENABLED={}", gcMetricsEnabled);
+      log.info("gc metrics are disabled with GC_METRICS_ENABLED=true");
       return;
     }
 
@@ -93,7 +96,7 @@
 
     try {
 
-      long testStart = System.currentTimeMillis();
+      var updateTimestamp = System.currentTimeMillis();
 
       // Read two updates, throw away the first snapshot - it could have been from a previous run
       // or another test (the file appends.)
@@ -106,8 +109,9 @@
       log.trace("M:{}", firstSeenMap);
 
       assertTrue(lookForExpectedKeys(firstSeenMap));
-      sanity(testStart, firstSeenMap);
+      sanity(updateTimestamp, firstSeenMap);
 
+      updateTimestamp = System.currentTimeMillis();
       LineUpdate nextUpdate = waitForUpdate(firstUpdate.getLastUpdate(), gcTail);
 
       Map<String,Long> updateSeenMap = parseLine(nextUpdate.getLine());
@@ -116,7 +120,7 @@
       log.trace("Mapped values:{}", updateSeenMap);
 
       assertTrue(lookForExpectedKeys(updateSeenMap));
-      sanity(testStart, updateSeenMap);
+      sanity(updateTimestamp, updateSeenMap);
 
       validate(firstSeenMap, updateSeenMap);
 
@@ -239,12 +243,14 @@
 
   private LineUpdate waitForUpdate(final long prevUpdate, final MetricsFileTailer tail) {
 
+    long start = System.currentTimeMillis();
+
     for (int count = 0; count < NUM_TAIL_ATTEMPTS; count++) {
 
       String line = tail.getLast();
       long currUpdate = tail.getLastUpdate();
 
-      if (line != null && (currUpdate != prevUpdate)) {
+      if (line != null && (currUpdate != prevUpdate) && isValidTimestamp(line, start)) {
         return new LineUpdate(tail.getLastUpdate(), line);
       }
 
@@ -261,6 +267,28 @@
             TimeUnit.MILLISECONDS.toSeconds(TAIL_DELAY * NUM_TAIL_ATTEMPTS)));
   }
 
+  private static final Pattern timestampPattern = Pattern.compile("^\\s*(?<timestamp>\\d+).*");
+
+  private boolean isValidTimestamp(final String line, final long start) {
+
+    if (Objects.isNull(line)) {
+      return false;
+    }
+
+    Matcher m = timestampPattern.matcher(line);
+
+    if (m.matches()) {
+      try {
+        var timestamp = Long.parseLong(m.group("timestamp"));
+        return timestamp >= start;
+      } catch (NumberFormatException ex) {
+        log.trace("Could not parse timestamp from line '{}", line);
+        return false;
+      }
+    }
+    return false;
+  }
+
   private boolean lookForExpectedKeys(final Map<String,Long> received) {
 
     for (String e : EXPECTED_METRIC_KEYS) {