Start adding basic metrics for NoteDb operations

Change-Id: Id903aa01aa3201b002ac09756f4096934fcaccec

gerrit-server/src/main/java/com/google/gerrit/server/notedb/AbstractChangeNotes.java

@@ -14,7 +14,10 @@
 
 package com.google.gerrit.server.notedb;
 
+import static com.google.gerrit.server.notedb.NoteDbTable.CHANGES;
+
 import com.google.common.annotations.VisibleForTesting;
+import com.google.gerrit.metrics.Timer1;
 import com.google.gerrit.reviewdb.client.Change;
 import com.google.gerrit.reviewdb.client.Project;
 import com.google.gerrit.server.config.AllUsersName;
@@ -40,17 +43,20 @@ public abstract class AbstractChangeNotes<T> {
     final NotesMigration migration;
     final AllUsersName allUsers;
     final ChangeNoteUtil noteUtil;
+    final NoteDbMetrics metrics;
 
     @Inject
     Args(
         GitRepositoryManager repoManager,
         NotesMigration migration,
         AllUsersName allUsers,
-        ChangeNoteUtil noteUtil) {
+        ChangeNoteUtil noteUtil,
+        NoteDbMetrics metrics) {
       this.repoManager = repoManager;
       this.migration = migration;
       this.allUsers = allUsers;
       this.noteUtil = noteUtil;
+      this.metrics = metrics;
     }
   }
 
@@ -82,7 +88,8 @@ public abstract class AbstractChangeNotes<T> {
       loadDefaults();
       return self();
     }
-    try (Repository repo =
+    try (Timer1.Context timer = args.metrics.readLatency.start(CHANGES);
+        Repository repo =
             args.repoManager.openMetadataRepository(getProjectName());
         RevWalk walk = new RevWalk(repo)) {
       Ref ref = repo.getRefDatabase().exactRef(getRefName());

gerrit-server/src/main/java/com/google/gerrit/server/notedb/ChangeNotes.java

@@ -526,7 +526,8 @@ public class ChangeNotes extends AbstractChangeNotes<ChangeNotes> {
       return;
     }
     try (ChangeNotesParser parser = new ChangeNotesParser(
-         project, change.getId(), rev, walk, args.repoManager, args.noteUtil)) {
+         project, change.getId(), rev, walk, args.repoManager, args.noteUtil,
+         args.metrics)) {
       parser.parseAll();
 
       if (parser.status != null) {

gerrit-server/src/main/java/com/google/gerrit/server/notedb/ChangeNotesParser.java

@@ -26,6 +26,7 @@ import static com.google.gerrit.server.notedb.ChangeNoteUtil.FOOTER_SUBJECT;
 import static com.google.gerrit.server.notedb.ChangeNoteUtil.FOOTER_SUBMISSION_ID;
 import static com.google.gerrit.server.notedb.ChangeNoteUtil.FOOTER_SUBMITTED_WITH;
 import static com.google.gerrit.server.notedb.ChangeNoteUtil.FOOTER_TOPIC;
+import static com.google.gerrit.server.notedb.NoteDbTable.CHANGES;
 
 import com.google.common.base.Enums;
 import com.google.common.base.Function;
@@ -47,6 +48,7 @@ import com.google.common.collect.Tables;
 import com.google.common.primitives.Ints;
 import com.google.gerrit.common.data.LabelType;
 import com.google.gerrit.common.data.SubmitRecord;
+import com.google.gerrit.metrics.Timer1;
 import com.google.gerrit.reviewdb.client.Account;
 import com.google.gerrit.reviewdb.client.Change;
 import com.google.gerrit.reviewdb.client.ChangeMessage;
@@ -115,6 +117,7 @@ class ChangeNotesParser implements AutoCloseable {
   RevisionNoteMap revisionNoteMap;
 
   private final ChangeNoteUtil noteUtil;
+  private final NoteDbMetrics metrics;
   private final Change.Id id;
   private final ObjectId tip;
   private final RevWalk walk;
@@ -126,13 +129,14 @@ class ChangeNotesParser implements AutoCloseable {
 
   ChangeNotesParser(Project.NameKey project, Change.Id changeId, ObjectId tip,
       RevWalk walk, GitRepositoryManager repoManager,
-      ChangeNoteUtil noteUtil)
+      ChangeNoteUtil noteUtil, NoteDbMetrics metrics)
       throws RepositoryNotFoundException, IOException {
     this.id = changeId;
     this.tip = tip;
     this.walk = walk;
     this.repo = repoManager.openMetadataRepository(project);
     this.noteUtil = noteUtil;
+    this.metrics = metrics;
     approvals = Maps.newHashMap();
     reviewers = Maps.newLinkedHashMap();
     allPastReviewers = Lists.newArrayList();
@@ -150,15 +154,21 @@ class ChangeNotesParser implements AutoCloseable {
   }
 
   void parseAll() throws ConfigInvalidException, IOException {
+    // Don't include initial parse in timer, as this might do more I/O to page
+    // in the block containing most commits. Later reads are not guaranteed to
+    // avoid I/O, but often should.
     walk.markStart(walk.parseCommit(tip));
-    for (RevCommit commit : walk) {
+
-      parse(commit);
+    try (Timer1.Context timer = metrics.parseLatency.start(CHANGES)) {
+      for (RevCommit commit : walk) {
+        parse(commit);
+      }
+      parseNotes();
+      allPastReviewers.addAll(reviewers.keySet());
+      pruneReviewers();
+      updatePatchSetStates();
+      checkMandatoryFooters();
     }
-    parseNotes();
-    allPastReviewers.addAll(reviewers.keySet());
-    pruneReviewers();
-    updatePatchSetStates();
-    checkMandatoryFooters();
   }
 
   ImmutableListMultimap<PatchSet.Id, PatchSetApproval>

gerrit-server/src/main/java/com/google/gerrit/server/notedb/ConfigNotesMigration.java

@@ -15,6 +15,7 @@
 package com.google.gerrit.server.notedb;
 
 import static com.google.common.base.Preconditions.checkArgument;
+import static com.google.gerrit.server.notedb.NoteDbTable.CHANGES;
 
 import com.google.gerrit.server.config.GerritServerConfig;
 import com.google.inject.AbstractModule;
@@ -45,21 +46,13 @@ public class ConfigNotesMigration extends NotesMigration {
     }
   }
 
-  private static enum Table {
-    CHANGES;
-
-    private String key() {
-      return name().toLowerCase();
-    }
-  }
-
   private static final String NOTE_DB = "noteDb";
   private static final String READ = "read";
   private static final String WRITE = "write";
 
   private static void checkConfig(Config cfg) {
     Set<String> keys = new HashSet<>();
-    for (Table t : Table.values()) {
+    for (NoteDbTable t : NoteDbTable.values()) {
       keys.add(t.key());
     }
     for (String t : cfg.getSubsections(NOTE_DB)) {
@@ -79,7 +72,7 @@ public class ConfigNotesMigration extends NotesMigration {
 
   public static Config allEnabledConfig() {
     Config cfg = new Config();
-    for (Table t : Table.values()) {
+    for (NoteDbTable t : NoteDbTable.values()) {
       cfg.setBoolean(NOTE_DB, t.key(), WRITE, true);
       cfg.setBoolean(NOTE_DB, t.key(), READ, true);
     }
@@ -92,8 +85,8 @@ public class ConfigNotesMigration extends NotesMigration {
   @Inject
   ConfigNotesMigration(@GerritServerConfig Config cfg) {
     checkConfig(cfg);
-    writeChanges = cfg.getBoolean(NOTE_DB, Table.CHANGES.key(), WRITE, false);
+    writeChanges = cfg.getBoolean(NOTE_DB, CHANGES.key(), WRITE, false);
-    readChanges = cfg.getBoolean(NOTE_DB, Table.CHANGES.key(), READ, false);
+    readChanges = cfg.getBoolean(NOTE_DB, CHANGES.key(), READ, false);
   }
 
   @Override

gerrit-server/src/main/java/com/google/gerrit/server/notedb/NoteDbMetrics.java

@@ -0,0 +1,67 @@
+// Copyright (C) 2016 The Android Open Source Project
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package com.google.gerrit.server.notedb;
+
+import com.google.gerrit.metrics.Description;
+import com.google.gerrit.metrics.Description.Units;
+import com.google.gerrit.metrics.Field;
+import com.google.gerrit.metrics.MetricMaker;
+import com.google.gerrit.metrics.Timer1;
+import com.google.inject.Inject;
+import com.google.inject.Singleton;
+
+@Singleton
+class NoteDbMetrics {
+  /** End-to-end latency for writing a collection of updates. */
+  final Timer1<NoteDbTable> updateLatency;
+
+  /**
+   * End-to-end latency for reading changes from NoteDb, including reading
+   * ref(s) and parsing.
+   */
+  final Timer1<NoteDbTable> readLatency;
+
+  /**
+   * The portion of {@link #readLatency} due to parsing commits, but excluding
+   * I/O (to a best effort).
+   */
+  final Timer1<NoteDbTable> parseLatency;
+
+  @Inject
+  NoteDbMetrics(MetricMaker metrics) {
+    Field<NoteDbTable> view = Field.ofEnum(NoteDbTable.class, "table");
+
+    updateLatency = metrics.newTimer(
+        "notedb/update_latency",
+        new Description("NoteDb update latency by table")
+            .setCumulative()
+            .setUnit(Units.MILLISECONDS),
+        view);
+
+    readLatency = metrics.newTimer(
+        "notedb/read_latency",
+        new Description("NoteDb read latency by table")
+            .setCumulative()
+            .setUnit(Units.MILLISECONDS),
+        view);
+
+    parseLatency = metrics.newTimer(
+        "notedb/parse_latency",
+        new Description("NoteDb parse latency by table")
+            .setCumulative()
+            .setUnit(Units.MICROSECONDS),
+        view);
+  }
+}

gerrit-server/src/main/java/com/google/gerrit/server/notedb/NoteDbTable.java

@@ -0,0 +1,28 @@
+// Copyright (C) 2016 The Android Open Source Project
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package com.google.gerrit.server.notedb;
+
+enum NoteDbTable {
+  CHANGES;
+
+  String key() {
+    return name().toLowerCase();
+  }
+
+  @Override
+  public String toString() {
+    return key();
+  }
+}

gerrit-server/src/main/java/com/google/gerrit/server/notedb/NoteDbUpdateManager.java

@@ -18,9 +18,11 @@ import static com.google.common.base.MoreObjects.firstNonNull;
 import static com.google.common.base.Preconditions.checkArgument;
 import static com.google.common.base.Preconditions.checkNotNull;
 import static com.google.common.base.Preconditions.checkState;
+import static com.google.gerrit.server.notedb.NoteDbTable.CHANGES;
 
 import com.google.common.collect.ArrayListMultimap;
 import com.google.common.collect.ListMultimap;
+import com.google.gerrit.metrics.Timer1;
 import com.google.gerrit.reviewdb.client.Project;
 import com.google.gerrit.server.config.AllUsersName;
 import com.google.gerrit.server.git.ChainedReceiveCommands;
@@ -73,6 +75,7 @@ public class NoteDbUpdateManager {
   private final GitRepositoryManager repoManager;
   private final NotesMigration migration;
   private final AllUsersName allUsersName;
+  private final NoteDbMetrics metrics;
   private final Project.NameKey projectName;
   private final ListMultimap<String, ChangeUpdate> changeUpdates;
   private final ListMultimap<String, ChangeDraftUpdate> draftUpdates;
@@ -84,10 +87,12 @@ public class NoteDbUpdateManager {
   NoteDbUpdateManager(GitRepositoryManager repoManager,
       NotesMigration migration,
       AllUsersName allUsersName,
+      NoteDbMetrics metrics,
       @Assisted Project.NameKey projectName) {
     this.repoManager = repoManager;
     this.migration = migration;
     this.allUsersName = allUsersName;
+    this.metrics = metrics;
     this.projectName = projectName;
     changeUpdates = ArrayListMultimap.create();
     draftUpdates = ArrayListMultimap.create();
@@ -186,7 +191,7 @@ public class NoteDbUpdateManager {
     if (isEmpty()) {
       return;
     }
-    try {
+    try (Timer1.Context timer = metrics.updateLatency.start(CHANGES)) {
       initChangeRepo();
       if (!draftUpdates.isEmpty()) {
         initAllUsersRepo();

gerrit-server/src/test/java/com/google/gerrit/server/notedb/AbstractChangeNotesTest.java

@@ -21,6 +21,8 @@ import com.google.common.collect.ImmutableList;
 import com.google.gerrit.common.TimeUtil;
 import com.google.gerrit.common.data.SubmitRecord;
 import com.google.gerrit.extensions.config.FactoryModule;
+import com.google.gerrit.metrics.DisabledMetricMaker;
+import com.google.gerrit.metrics.MetricMaker;
 import com.google.gerrit.reviewdb.client.Account;
 import com.google.gerrit.reviewdb.client.Change;
 import com.google.gerrit.reviewdb.client.CommentRange;
@@ -168,6 +170,7 @@ public abstract class AbstractChangeNotesTest extends GerritBaseTests {
             .toInstance(GitReferenceUpdated.DISABLED);
         bind(StarredChangesUtil.class)
             .toProvider(Providers.<StarredChangesUtil> of(null));
+        bind(MetricMaker.class).to(DisabledMetricMaker.class);
       }
     });
 

gerrit-server/src/test/java/com/google/gerrit/server/notedb/ChangeNotesParserTest.java

@@ -462,6 +462,6 @@ public class ChangeNotesParserTest extends AbstractChangeNotesTest {
   private ChangeNotesParser newParser(ObjectId tip) throws Exception {
     Change c = newChange();
     return new ChangeNotesParser(c.getProject(), c.getId(), tip, walk,
-        repoManager, noteUtil);
+        repoManager, noteUtil, args.metrics);
   }
 }

gerrit-server/src/test/java/com/google/gerrit/server/notedb/ChangeNotesTest.java

@@ -909,8 +909,9 @@ public class ChangeNotesTest extends AbstractChangeNotesTest {
     assertThat(commitWithComments).isNotNull();
 
     try (RevWalk rw = new RevWalk(repo)) {
-      try (ChangeNotesParser notesWithComments = new ChangeNotesParser(project,
+      try (ChangeNotesParser notesWithComments = new ChangeNotesParser(
-          c.getId(), commitWithComments.copy(), rw, repoManager, noteUtil)) {
+          project, c.getId(), commitWithComments.copy(), rw, repoManager,
+          noteUtil, args.metrics)) {
         notesWithComments.parseAll();
         ImmutableListMultimap<PatchSet.Id, PatchSetApproval> approvals1 =
             notesWithComments.buildApprovals();
@@ -922,7 +923,7 @@ public class ChangeNotesTest extends AbstractChangeNotesTest {
     try (RevWalk rw = new RevWalk(repo)) {
       try (ChangeNotesParser notesWithApprovals = new ChangeNotesParser(project,
           c.getId(), commitWithApprovals.copy(), rw, repoManager,
-          noteUtil)) {
+          noteUtil, args.metrics)) {
         notesWithApprovals.parseAll();
         ImmutableListMultimap<PatchSet.Id, PatchSetApproval> approvals2 =
             notesWithApprovals.buildApprovals();