commit 5782cd6350afc34d1c84d92f3cdf3395f451663e
author Patrick Hiesel <hiesel@google.com> Thu Mar 14 15:41:24 2019 +0000
committer Gerrit Code Review <noreply-gerritcodereview@google.com> Thu Mar 14 15:41:24 2019 +0000
tree 8a7c16a8293eeb4c7d52fedaa049686ba6f1f57b
parent 7a82815691dac8490d912e504d80e8f85b3e77b2
parent 44b6e767faf3dc2fcf579e36df870b95a042ef77

Merge "AsyncReceiveCommits: add metric for total push latency"

Documentation/metrics.txt

diff --git a/Documentation/metrics.txt b/Documentation/metrics.txt
index 6864c68..064859d 100644
--- a/Documentation/metrics.txt
+++ b/Documentation/metrics.txt
@@ -23,10 +23,12 @@
 === Pushes
 
 * `receivecommits/changes`: histogram of number of changes processed
-in a single upload, split up by update type (new change created,
-existing changed updated, change autoclosed).
+in a single upload, split up by update type (change created/updated,
+change autoclosed).
 * `receivecommits/latency`: latency per change for processing a push,
 split up by update type (create+replace, and autoclose)
+* `receivecommits/push_latency`: total latency for processing a push,
+split up by update type (create+replace, autoclose, normal)
 * `receivecommits/timeout`: number of timeouts during push processing.
 
 === Process

java/com/google/gerrit/server/git/receive/AsyncReceiveCommits.java

diff --git a/java/com/google/gerrit/server/git/receive/AsyncReceiveCommits.java b/java/com/google/gerrit/server/git/receive/AsyncReceiveCommits.java
index f0077cd..1f3f001 100644
--- a/java/com/google/gerrit/server/git/receive/AsyncReceiveCommits.java
+++ b/java/com/google/gerrit/server/git/receive/AsyncReceiveCommits.java
@@ -175,29 +175,45 @@
     }
   }
 
+  private enum PushType {
+    CREATE_REPLACE,
+    NORMAL,
+    AUTOCLOSE,
+  };
+
   @Singleton
   private static class Metrics {
-    private final Histogram1<ResultChangeIds.Key> changes;
-    private final Timer1<String> latencyPerChange;
+    private final Histogram1<PushType> changes;
+    private final Timer1<PushType> latencyPerChange;
+    private final Timer1<PushType> latencyPerPush;
     private final Counter0 timeouts;
 
     @Inject
     Metrics(MetricMaker metricMaker) {
       changes =
           metricMaker.newHistogram(
-              "receivecommits/changes",
+              "receivecommits/changes_per_push",
               new Description("number of changes uploaded in a single push.").setCumulative(),
-              Field.ofEnum(
-                  ResultChangeIds.Key.class,
-                  "type",
-                  "type of update (replace, create, autoclose)"));
+              Field.ofEnum(PushType.class, "type", "type of push (create/replace, autoclose)"));
+
       latencyPerChange =
           metricMaker.newTimer(
-              "receivecommits/latency",
-              new Description("average delay per updated change")
+              "receivecommits/latency_per_push_per_change",
+              new Description(
+                      "Processing delay per push divided by the number of changes in said push. "
+                          + "(Only includes pushes which contain changes.)")
                   .setUnit(Units.MILLISECONDS)
                   .setCumulative(),
-              Field.ofString("type", "type of update (create/replace, autoclose)"));
+              Field.ofEnum(PushType.class, "type", "type of push (create/replace, autoclose)"));
+
+      latencyPerPush =
+          metricMaker.newTimer(
+              "receivecommits/latency_per_push",
+              new Description("processing delay for a processing single push")
+                  .setUnit(Units.MILLISECONDS)
+                  .setCumulative(),
+              Field.ofEnum(
+                  PushType.class, "type", "type of push (create/replace, autoclose, normal)"));
 
       timeouts =
           metricMaker.newCounter(
@@ -342,24 +358,29 @@
     long deltaNanos = System.nanoTime() - startNanos;
     int totalChanges = 0;
 
+    PushType pushType;
     if (resultChangeIds.isMagicPush()) {
+      pushType = PushType.CREATE_REPLACE;
       List<Change.Id> created = resultChangeIds.get(ResultChangeIds.Key.CREATED);
-      metrics.changes.record(ResultChangeIds.Key.CREATED, created.size());
       List<Change.Id> replaced = resultChangeIds.get(ResultChangeIds.Key.REPLACED);
-      metrics.changes.record(ResultChangeIds.Key.REPLACED, replaced.size());
-      totalChanges += replaced.size() + created.size();
+      metrics.changes.record(pushType, created.size() + replaced.size());
+      totalChanges = replaced.size() + created.size();
     } else {
       List<Change.Id> autoclosed = resultChangeIds.get(ResultChangeIds.Key.AUTOCLOSED);
-      metrics.changes.record(ResultChangeIds.Key.AUTOCLOSED, autoclosed.size());
-      totalChanges += autoclosed.size();
+      if (!autoclosed.isEmpty()) {
+        pushType = PushType.AUTOCLOSE;
+        metrics.changes.record(pushType, autoclosed.size());
+        totalChanges = autoclosed.size();
+      } else {
+        pushType = PushType.NORMAL;
+      }
     }
 
     if (totalChanges > 0) {
-      metrics.latencyPerChange.record(
-          resultChangeIds.isMagicPush() ? "CREATE_REPLACE" : ResultChangeIds.Key.AUTOCLOSED.name(),
-          deltaNanos / totalChanges,
-          NANOSECONDS);
+      metrics.latencyPerChange.record(pushType, deltaNanos / totalChanges, NANOSECONDS);
     }
+
+    metrics.latencyPerPush.record(pushType, deltaNanos, NANOSECONDS);
   }
 
   /** Returns the Change.Ids that were processed in onPreReceive */