Add performance logs for filling accounts and checking isServiceUser

Something with loading accounts is slow, but we can't pin it down yet.
To gain further insights add performance logs for filling accounts and
for checking whether an account is a service user which is done for
every account.

Bug: Google b/325070428
Release-Notes: skip
Change-Id: Ie7e288085f85f86eeee54206ecd0b2f66a326df3
Signed-off-by: Edwin Kempin <ekempin@google.com>
diff --git a/java/com/google/gerrit/server/account/AccountLoader.java b/java/com/google/gerrit/server/account/AccountLoader.java
index c260401..42687987 100644
--- a/java/com/google/gerrit/server/account/AccountLoader.java
+++ b/java/com/google/gerrit/server/account/AccountLoader.java
@@ -21,6 +21,9 @@
 import com.google.gerrit.entities.Account;
 import com.google.gerrit.extensions.common.AccountInfo;
 import com.google.gerrit.server.account.AccountDirectory.FillOptions;
+import com.google.gerrit.server.logging.Metadata;
+import com.google.gerrit.server.logging.TraceContext;
+import com.google.gerrit.server.logging.TraceContext.TraceTimer;
 import com.google.gerrit.server.permissions.PermissionBackendException;
 import com.google.inject.assistedinject.Assisted;
 import com.google.inject.assistedinject.AssistedInject;
@@ -90,7 +93,9 @@
   }
 
   public void fill() throws PermissionBackendException {
-    directory.fillAccountInfo(Iterables.concat(created.values(), provided), options);
+    try (TraceTimer timer = TraceContext.newTimer("Fill accounts", Metadata.empty())) {
+      directory.fillAccountInfo(Iterables.concat(created.values(), provided), options);
+    }
   }
 
   public void fill(Collection<? extends AccountInfo> infos) throws PermissionBackendException {
diff --git a/java/com/google/gerrit/server/account/ServiceUserClassifierImpl.java b/java/com/google/gerrit/server/account/ServiceUserClassifierImpl.java
index db030f9..a05baf5 100644
--- a/java/com/google/gerrit/server/account/ServiceUserClassifierImpl.java
+++ b/java/com/google/gerrit/server/account/ServiceUserClassifierImpl.java
@@ -19,6 +19,9 @@
 import com.google.gerrit.entities.AccountGroup;
 import com.google.gerrit.entities.InternalGroup;
 import com.google.gerrit.server.IdentifiedUser;
+import com.google.gerrit.server.logging.Metadata;
+import com.google.gerrit.server.logging.TraceContext;
+import com.google.gerrit.server.logging.TraceContext.TraceTimer;
 import com.google.inject.AbstractModule;
 import com.google.inject.Module;
 import com.google.inject.Scopes;
@@ -63,41 +66,43 @@
 
   @Override
   public boolean isServiceUser(Account.Id user) {
-    Optional<InternalGroup> maybeGroup = groupCache.get(AccountGroup.nameKey(SERVICE_USERS));
-    if (!maybeGroup.isPresent()) {
+    try (TraceTimer timer = TraceContext.newTimer("isServiceUser", Metadata.empty())) {
+      Optional<InternalGroup> maybeGroup = groupCache.get(AccountGroup.nameKey(SERVICE_USERS));
+      if (!maybeGroup.isPresent()) {
+        return false;
+      }
+      List<AccountGroup.UUID> toTraverse = new ArrayList<>();
+      toTraverse.add(maybeGroup.get().getGroupUUID());
+      Set<AccountGroup.UUID> seen = new HashSet<>();
+      while (!toTraverse.isEmpty()) {
+        InternalGroup currentGroup =
+            groupCache
+                .get(toTraverse.remove(0))
+                .orElseThrow(() -> new IllegalStateException("invalid subgroup"));
+        if (seen.contains(currentGroup.getGroupUUID())) {
+          logger.atFine().log(
+              "Skipping %s because it's a cyclic subgroup", currentGroup.getGroupUUID());
+          continue;
+        }
+        seen.add(currentGroup.getGroupUUID());
+        if (currentGroup.getMembers().contains(user)) {
+          // The user is a member of the 'Service Users' group or a subgroup.
+          return true;
+        }
+        boolean hasExternalSubgroup =
+            currentGroup.getSubgroups().stream().anyMatch(g -> !internalGroupBackend.handles(g));
+        if (hasExternalSubgroup) {
+          // 'Service Users or a subgroup of Service User' contains an external subgroup, so we have
+          // to default to the more expensive evaluation of getting all of the user's group
+          // memberships.
+          return identifiedUserFactory
+              .create(user)
+              .getEffectiveGroups()
+              .contains(maybeGroup.get().getGroupUUID());
+        }
+        toTraverse.addAll(currentGroup.getSubgroups());
+      }
       return false;
     }
-    List<AccountGroup.UUID> toTraverse = new ArrayList<>();
-    toTraverse.add(maybeGroup.get().getGroupUUID());
-    Set<AccountGroup.UUID> seen = new HashSet<>();
-    while (!toTraverse.isEmpty()) {
-      InternalGroup currentGroup =
-          groupCache
-              .get(toTraverse.remove(0))
-              .orElseThrow(() -> new IllegalStateException("invalid subgroup"));
-      if (seen.contains(currentGroup.getGroupUUID())) {
-        logger.atFine().log(
-            "Skipping %s because it's a cyclic subgroup", currentGroup.getGroupUUID());
-        continue;
-      }
-      seen.add(currentGroup.getGroupUUID());
-      if (currentGroup.getMembers().contains(user)) {
-        // The user is a member of the 'Service Users' group or a subgroup.
-        return true;
-      }
-      boolean hasExternalSubgroup =
-          currentGroup.getSubgroups().stream().anyMatch(g -> !internalGroupBackend.handles(g));
-      if (hasExternalSubgroup) {
-        // 'Service Users or a subgroup of Service User' contains an external subgroup, so we have
-        // to default to the more expensive evaluation of getting all of the user's group
-        // memberships.
-        return identifiedUserFactory
-            .create(user)
-            .getEffectiveGroups()
-            .contains(maybeGroup.get().getGroupUUID());
-      }
-      toTraverse.addAll(currentGroup.getSubgroups());
-    }
-    return false;
   }
 }