Log time that is spent on loading cache entries
Change-Id: I13c53228da3b2f5d2869406fe9568fc655d6d9b4
Signed-off-by: Edwin Kempin <ekempin@google.com>
diff --git a/java/com/google/gerrit/server/account/AccountCacheImpl.java b/java/com/google/gerrit/server/account/AccountCacheImpl.java
index b6ae216..fd48fa7 100644
--- a/java/com/google/gerrit/server/account/AccountCacheImpl.java
+++ b/java/com/google/gerrit/server/account/AccountCacheImpl.java
@@ -27,6 +27,8 @@
import com.google.gerrit.server.account.externalids.ExternalIds;
import com.google.gerrit.server.cache.CacheModule;
import com.google.gerrit.server.config.AllUsersName;
+import com.google.gerrit.server.logging.TraceContext;
+import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.util.time.TimeUtil;
import com.google.inject.Inject;
import com.google.inject.Module;
@@ -181,8 +183,9 @@
@Override
public Optional<AccountState> load(Account.Id who) throws Exception {
- logger.atFine().log("Loading account %s", who);
- return accounts.get(who);
+ try (TraceTimer timer = TraceContext.newTimer("Loading account %s", who)) {
+ return accounts.get(who);
+ }
}
}
}
diff --git a/java/com/google/gerrit/server/account/GroupCacheImpl.java b/java/com/google/gerrit/server/account/GroupCacheImpl.java
index 1f8cb88..c85e2df 100644
--- a/java/com/google/gerrit/server/account/GroupCacheImpl.java
+++ b/java/com/google/gerrit/server/account/GroupCacheImpl.java
@@ -21,6 +21,8 @@
import com.google.gerrit.server.cache.CacheModule;
import com.google.gerrit.server.group.InternalGroup;
import com.google.gerrit.server.group.db.Groups;
+import com.google.gerrit.server.logging.TraceContext;
+import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.query.group.InternalGroupQuery;
import com.google.inject.Inject;
import com.google.inject.Module;
@@ -147,8 +149,9 @@
@Override
public Optional<InternalGroup> load(AccountGroup.Id key) throws Exception {
- logger.atFine().log("Loading group %s by ID", key);
- return groupQueryProvider.get().byId(key);
+ try (TraceTimer timer = TraceContext.newTimer("Loading group %s by ID", key)) {
+ return groupQueryProvider.get().byId(key);
+ }
}
}
@@ -162,8 +165,9 @@
@Override
public Optional<InternalGroup> load(String name) throws Exception {
- logger.atFine().log("Loading group '%s' by name", name);
- return groupQueryProvider.get().byName(new AccountGroup.NameKey(name));
+ try (TraceTimer timer = TraceContext.newTimer("Loading group '%s' by name", name)) {
+ return groupQueryProvider.get().byName(new AccountGroup.NameKey(name));
+ }
}
}
@@ -177,8 +181,9 @@
@Override
public Optional<InternalGroup> load(String uuid) throws Exception {
- logger.atFine().log("Loading group %s by UUID", uuid);
- return groups.getGroup(new AccountGroup.UUID(uuid));
+ try (TraceTimer timer = TraceContext.newTimer("Loading group %s by UUID", uuid)) {
+ return groups.getGroup(new AccountGroup.UUID(uuid));
+ }
}
}
}
diff --git a/java/com/google/gerrit/server/account/GroupIncludeCacheImpl.java b/java/com/google/gerrit/server/account/GroupIncludeCacheImpl.java
index 5fb4ca1..58eaf21 100644
--- a/java/com/google/gerrit/server/account/GroupIncludeCacheImpl.java
+++ b/java/com/google/gerrit/server/account/GroupIncludeCacheImpl.java
@@ -27,6 +27,8 @@
import com.google.gerrit.server.cache.CacheModule;
import com.google.gerrit.server.group.InternalGroup;
import com.google.gerrit.server.group.db.Groups;
+import com.google.gerrit.server.logging.TraceContext;
+import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.query.group.InternalGroupQuery;
import com.google.gwtorm.server.OrmException;
import com.google.inject.Inject;
@@ -151,13 +153,14 @@
@Override
public ImmutableSet<AccountGroup.UUID> load(Account.Id memberId) throws OrmException {
- logger.atFine().log("Loading groups with member %s", memberId);
- return groupQueryProvider
- .get()
- .byMember(memberId)
- .stream()
- .map(InternalGroup::getGroupUUID)
- .collect(toImmutableSet());
+ try (TraceTimer timer = TraceContext.newTimer("Loading groups with member %s", memberId)) {
+ return groupQueryProvider
+ .get()
+ .byMember(memberId)
+ .stream()
+ .map(InternalGroup::getGroupUUID)
+ .collect(toImmutableSet());
+ }
}
}
@@ -172,13 +175,14 @@
@Override
public ImmutableList<AccountGroup.UUID> load(AccountGroup.UUID key) throws OrmException {
- logger.atFine().log("Loading parent groups of %s", key);
- return groupQueryProvider
- .get()
- .bySubgroup(key)
- .stream()
- .map(InternalGroup::getGroupUUID)
- .collect(toImmutableList());
+ try (TraceTimer timer = TraceContext.newTimer("Loading parent groups of %s", key)) {
+ return groupQueryProvider
+ .get()
+ .bySubgroup(key)
+ .stream()
+ .map(InternalGroup::getGroupUUID)
+ .collect(toImmutableList());
+ }
}
}
@@ -192,8 +196,9 @@
@Override
public ImmutableList<AccountGroup.UUID> load(String key) throws Exception {
- logger.atFine().log("Loading all external groups");
- return groups.getExternalGroups().collect(toImmutableList());
+ try (TraceTimer timer = TraceContext.newTimer("Loading all external groups")) {
+ return groups.getExternalGroups().collect(toImmutableList());
+ }
}
}
}
diff --git a/java/com/google/gerrit/server/account/externalids/ExternalIdCacheImpl.java b/java/com/google/gerrit/server/account/externalids/ExternalIdCacheImpl.java
index 5f64568..767bfd5 100644
--- a/java/com/google/gerrit/server/account/externalids/ExternalIdCacheImpl.java
+++ b/java/com/google/gerrit/server/account/externalids/ExternalIdCacheImpl.java
@@ -22,6 +22,8 @@
import com.google.common.collect.SetMultimap;
import com.google.common.flogger.FluentLogger;
import com.google.gerrit.reviewdb.client.Account;
+import com.google.gerrit.server.logging.TraceContext;
+import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.inject.Inject;
import com.google.inject.Singleton;
import com.google.inject.name.Named;
@@ -150,10 +152,12 @@
@Override
public AllExternalIds load(ObjectId notesRev) throws Exception {
- logger.atFine().log("Loading external IDs (revision=%s)", notesRev);
- ImmutableSet<ExternalId> externalIds = externalIdReader.all(notesRev);
- externalIds.forEach(ExternalId::checkThatBlobIdIsSet);
- return AllExternalIds.create(externalIds);
+ try (TraceTimer timer =
+ TraceContext.newTimer("Loading external IDs (revision=%s)", notesRev)) {
+ ImmutableSet<ExternalId> externalIds = externalIdReader.all(notesRev);
+ externalIds.forEach(ExternalId::checkThatBlobIdIsSet);
+ return AllExternalIds.create(externalIds);
+ }
}
}
}
diff --git a/java/com/google/gerrit/server/auth/ldap/LdapRealm.java b/java/com/google/gerrit/server/auth/ldap/LdapRealm.java
index ede8050..ed446f2 100644
--- a/java/com/google/gerrit/server/auth/ldap/LdapRealm.java
+++ b/java/com/google/gerrit/server/auth/ldap/LdapRealm.java
@@ -37,6 +37,8 @@
import com.google.gerrit.server.auth.NoSuchUserException;
import com.google.gerrit.server.config.AuthConfig;
import com.google.gerrit.server.config.GerritServerConfig;
+import com.google.gerrit.server.logging.TraceContext;
+import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.inject.Inject;
import com.google.inject.Singleton;
import com.google.inject.name.Named;
@@ -351,10 +353,11 @@
@Override
public Optional<Account.Id> load(String username) throws Exception {
- logger.atFine().log("Loading account for username %s", username);
- return externalIds
- .get(ExternalId.Key.create(SCHEME_GERRIT, username))
- .map(ExternalId::accountId);
+ try (TraceTimer timer = TraceContext.newTimer("Loading account for username %s", username)) {
+ return externalIds
+ .get(ExternalId.Key.create(SCHEME_GERRIT, username))
+ .map(ExternalId::accountId);
+ }
}
}
@@ -368,12 +371,14 @@
@Override
public Set<AccountGroup.UUID> load(String username) throws Exception {
- logger.atFine().log("Loading group for member with username %s", username);
- final DirContext ctx = helper.open();
- try {
- return helper.queryForGroups(ctx, username, null);
- } finally {
- helper.close(ctx);
+ try (TraceTimer timer =
+ TraceContext.newTimer("Loading group for member with username %s", username)) {
+ final DirContext ctx = helper.open();
+ try {
+ return helper.queryForGroups(ctx, username, null);
+ } finally {
+ helper.close(ctx);
+ }
}
}
}
@@ -388,18 +393,19 @@
@Override
public Boolean load(String groupDn) throws Exception {
- logger.atFine().log("Loading groupDn %s", groupDn);
- final DirContext ctx = helper.open();
- try {
- Name compositeGroupName = new CompositeName().add(groupDn);
+ try (TraceTimer timer = TraceContext.newTimer("Loading groupDn %s", groupDn)) {
+ final DirContext ctx = helper.open();
try {
- ctx.getAttributes(compositeGroupName);
- return true;
- } catch (NamingException e) {
- return false;
+ Name compositeGroupName = new CompositeName().add(groupDn);
+ try {
+ ctx.getAttributes(compositeGroupName);
+ return true;
+ } catch (NamingException e) {
+ return false;
+ }
+ } finally {
+ helper.close(ctx);
}
- } finally {
- helper.close(ctx);
}
}
}
diff --git a/java/com/google/gerrit/server/cache/h2/H2CacheImpl.java b/java/com/google/gerrit/server/cache/h2/H2CacheImpl.java
index a538897..a8fb53b 100644
--- a/java/com/google/gerrit/server/cache/h2/H2CacheImpl.java
+++ b/java/com/google/gerrit/server/cache/h2/H2CacheImpl.java
@@ -26,6 +26,8 @@
import com.google.gerrit.common.Nullable;
import com.google.gerrit.server.cache.PersistentCache;
import com.google.gerrit.server.cache.serialize.CacheSerializer;
+import com.google.gerrit.server.logging.TraceContext;
+import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.util.time.TimeUtil;
import com.google.inject.TypeLiteral;
import java.io.IOException;
@@ -235,19 +237,19 @@
@Override
public ValueHolder<V> load(K key) throws Exception {
- logger.atFine().log("Loading value for %s from cache", key);
-
- if (store.mightContain(key)) {
- ValueHolder<V> h = store.getIfPresent(key);
- if (h != null) {
- return h;
+ try (TraceTimer timer = TraceContext.newTimer("Loading value for %s from cache", key)) {
+ if (store.mightContain(key)) {
+ ValueHolder<V> h = store.getIfPresent(key);
+ if (h != null) {
+ return h;
+ }
}
- }
- final ValueHolder<V> h = new ValueHolder<>(loader.load(key));
- h.created = TimeUtil.nowMs();
- executor.execute(() -> store.put(key, h));
- return h;
+ final ValueHolder<V> h = new ValueHolder<>(loader.load(key));
+ h.created = TimeUtil.nowMs();
+ executor.execute(() -> store.put(key, h));
+ return h;
+ }
}
}
diff --git a/java/com/google/gerrit/server/git/SearchingChangeCacheImpl.java b/java/com/google/gerrit/server/git/SearchingChangeCacheImpl.java
index 5f1d8c6..d5e19cc 100644
--- a/java/com/google/gerrit/server/git/SearchingChangeCacheImpl.java
+++ b/java/com/google/gerrit/server/git/SearchingChangeCacheImpl.java
@@ -28,6 +28,8 @@
import com.google.gerrit.server.ReviewerSet;
import com.google.gerrit.server.cache.CacheModule;
import com.google.gerrit.server.index.change.ChangeField;
+import com.google.gerrit.server.logging.TraceContext;
+import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.query.change.ChangeData;
import com.google.gerrit.server.query.change.InternalChangeQuery;
import com.google.gerrit.server.util.ManualRequestContext;
@@ -144,8 +146,8 @@
@Override
public List<CachedChange> load(Project.NameKey key) throws Exception {
- logger.atFine().log("Loading changes of project %s", key);
- try (ManualRequestContext ctx = requestContext.open()) {
+ try (TraceTimer timer = TraceContext.newTimer("Loading changes of project %s", key);
+ ManualRequestContext ctx = requestContext.open()) {
List<ChangeData> cds =
queryProvider
.get()
diff --git a/java/com/google/gerrit/server/project/ProjectCacheImpl.java b/java/com/google/gerrit/server/project/ProjectCacheImpl.java
index dd6ce56..aa455e6 100644
--- a/java/com/google/gerrit/server/project/ProjectCacheImpl.java
+++ b/java/com/google/gerrit/server/project/ProjectCacheImpl.java
@@ -31,6 +31,8 @@
import com.google.gerrit.server.config.AllProjectsName;
import com.google.gerrit.server.config.AllUsersName;
import com.google.gerrit.server.git.GitRepositoryManager;
+import com.google.gerrit.server.logging.TraceContext;
+import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.inject.Inject;
import com.google.inject.Module;
import com.google.inject.Provider;
@@ -270,16 +272,17 @@
@Override
public ProjectState load(String projectName) throws Exception {
- logger.atFine().log("Loading project %s", projectName);
- long now = clock.read();
- Project.NameKey key = new Project.NameKey(projectName);
- try (Repository git = mgr.openRepository(key)) {
- ProjectConfig cfg = new ProjectConfig(key);
- cfg.load(key, git);
+ try (TraceTimer timer = TraceContext.newTimer("Loading project %s", projectName)) {
+ long now = clock.read();
+ Project.NameKey key = new Project.NameKey(projectName);
+ try (Repository git = mgr.openRepository(key)) {
+ ProjectConfig cfg = new ProjectConfig(key);
+ cfg.load(key, git);
- ProjectState state = projectStateFactory.create(cfg);
- state.initLastCheck(now);
- return state;
+ ProjectState state = projectStateFactory.create(cfg);
+ state.initLastCheck(now);
+ return state;
+ }
}
}
}
@@ -300,8 +303,9 @@
@Override
public ImmutableSortedSet<Project.NameKey> load(ListKey key) throws Exception {
- logger.atFine().log("Loading project list");
- return ImmutableSortedSet.copyOf(mgr.list());
+ try (TraceTimer timer = TraceContext.newTimer("Loading project list")) {
+ return ImmutableSortedSet.copyOf(mgr.list());
+ }
}
}
}
diff --git a/java/com/google/gerrit/sshd/SshKeyCacheImpl.java b/java/com/google/gerrit/sshd/SshKeyCacheImpl.java
index 81ce91d..fb0b8f6 100644
--- a/java/com/google/gerrit/sshd/SshKeyCacheImpl.java
+++ b/java/com/google/gerrit/sshd/SshKeyCacheImpl.java
@@ -24,6 +24,8 @@
import com.google.gerrit.server.account.externalids.ExternalId;
import com.google.gerrit.server.account.externalids.ExternalIds;
import com.google.gerrit.server.cache.CacheModule;
+import com.google.gerrit.server.logging.TraceContext;
+import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.ssh.SshKeyCache;
import com.google.gerrit.server.ssh.SshKeyCreator;
import com.google.inject.Inject;
@@ -103,24 +105,26 @@
@Override
public Iterable<SshKeyCacheEntry> load(String username) throws Exception {
- logger.atFine().log("Loading SSH keys for account with username %s", username);
-
- Optional<ExternalId> user = externalIds.get(ExternalId.Key.create(SCHEME_USERNAME, username));
- if (!user.isPresent()) {
- return NO_SUCH_USER;
- }
-
- List<SshKeyCacheEntry> kl = new ArrayList<>(4);
- for (AccountSshKey k : authorizedKeys.getKeys(user.get().accountId())) {
- if (k.valid()) {
- add(kl, k);
+ try (TraceTimer timer =
+ TraceContext.newTimer("Loading SSH keys for account with username %s", username)) {
+ Optional<ExternalId> user =
+ externalIds.get(ExternalId.Key.create(SCHEME_USERNAME, username));
+ if (!user.isPresent()) {
+ return NO_SUCH_USER;
}
- }
- if (kl.isEmpty()) {
- return NO_KEYS;
+ List<SshKeyCacheEntry> kl = new ArrayList<>(4);
+ for (AccountSshKey k : authorizedKeys.getKeys(user.get().accountId())) {
+ if (k.valid()) {
+ add(kl, k);
+ }
+ }
+
+ if (kl.isEmpty()) {
+ return NO_KEYS;
+ }
+ return Collections.unmodifiableList(kl);
}
- return Collections.unmodifiableList(kl);
}
private void add(List<SshKeyCacheEntry> kl, AccountSshKey k) {
