opendev/gerrit
Code Issues Proposed changes

Merge "Add support for tracing the execution time of operations"

Browse Source
This commit is contained in:
Edwin Kempin
2018-09-11 07:05:16 +00:00
committed by Gerrit Code Review
parent b0e2b3a6a1 36655f24a2
commit e350c2ab4c
5 changed files with 124 additions and 8 deletions
Download Patch File Download Diff File Expand all files Collapse all files

14
java/com/google/gerrit/server/index/account/AccountIndexerImpl.java
View File

@@ -23,6 +23,8 @@ import com.google.gerrit.index.Index;
import com.google.gerrit.reviewdb.client.Account;
import com.google.gerrit.server.account.AccountCache;
import com.google.gerrit.server.account.AccountState;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.inject.assistedinject.Assisted;
import com.google.inject.assistedinject.AssistedInject;
import java.io.IOException;
@@ -85,9 +87,17 @@ public class AccountIndexerImpl implements AccountIndexer {
for (Index<Account.Id, AccountState> i : getWriteIndexes()) {
// Evict the cache to get an up-to-date value for sure.
if (accountState.isPresent()) {
i.replace(accountState.get());
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Replacing account %d in index version %d", id.get(), i.getSchema().getVersion())) {
i.replace(accountState.get());
}
} else {
i.delete(id);
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Deleteing account %d in index version %d", id.get(), i.getSchema().getVersion())) {
i.delete(id);
}
}
}
fireAccountIndexedEvent(id.get());

15
java/com/google/gerrit/server/index/change/ChangeIndexer.java
View File

@@ -33,6 +33,8 @@ import com.google.gerrit.server.CurrentUser;
import com.google.gerrit.server.config.GerritServerConfig;
import com.google.gerrit.server.index.IndexExecutor;
import com.google.gerrit.server.index.IndexUtils;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.notedb.ChangeNotes;
import com.google.gerrit.server.notedb.NotesMigration;
import com.google.gerrit.server.project.NoSuchChangeException;
@@ -214,7 +216,12 @@ public class ChangeIndexer {
private void indexImpl(ChangeData cd) throws IOException {
logger.atInfo().log("Replace change %d in index.", cd.getId().get());
for (Index<?, ChangeData> i : getWriteIndexes()) {
i.replace(cd);
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Replacing change %d in index version %d",
cd.getId().get(), i.getSchema().getVersion())) {
i.replace(cd);
}
}
fireChangeIndexedEvent(cd.project().get(), cd.getId().get());
}
@@ -417,7 +424,11 @@ public class ChangeIndexer {
// Implementations should not need to access the DB in order to delete a
// change ID.
for (ChangeIndex i : getWriteIndexes()) {
i.delete(id);
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Deleteing change %d in index version %d", id.get(), i.getSchema().getVersion())) {
i.delete(id);
}
}
fireChangeDeletedFromIndexEvent(id.get());
return null;

14
java/com/google/gerrit/server/index/group/GroupIndexerImpl.java
View File

@@ -23,6 +23,8 @@ import com.google.gerrit.index.Index;
import com.google.gerrit.reviewdb.client.AccountGroup;
import com.google.gerrit.server.account.GroupCache;
import com.google.gerrit.server.group.InternalGroup;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.inject.assistedinject.Assisted;
import com.google.inject.assistedinject.AssistedInject;
import java.io.IOException;
@@ -85,9 +87,17 @@ public class GroupIndexerImpl implements GroupIndexer {
for (Index<AccountGroup.UUID, InternalGroup> i : getWriteIndexes()) {
if (internalGroup.isPresent()) {
i.replace(internalGroup.get());
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Replacing group %s in index version %d", uuid.get(), i.getSchema().getVersion())) {
i.replace(internalGroup.get());
}
} else {
i.delete(uuid);
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Deleting group %s in index version %d", uuid.get(), i.getSchema().getVersion())) {
i.delete(uuid);
}
}
}
fireGroupIndexedEvent(uuid.get());

16
java/com/google/gerrit/server/index/project/ProjectIndexerImpl.java
View File

@@ -24,6 +24,8 @@ import com.google.gerrit.index.project.ProjectIndex;
import com.google.gerrit.index.project.ProjectIndexCollection;
import com.google.gerrit.index.project.ProjectIndexer;
import com.google.gerrit.reviewdb.client.Project;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.project.ProjectCache;
import com.google.gerrit.server.project.ProjectState;
import com.google.inject.assistedinject.Assisted;
@@ -75,13 +77,23 @@ public class ProjectIndexerImpl implements ProjectIndexer {
logger.atInfo().log("Replace project %s in index", nameKey.get());
ProjectData projectData = projectState.toProjectData();
for (ProjectIndex i : getWriteIndexes()) {
i.replace(projectData);
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Replacing project %s in index version %d",
nameKey.get(), i.getSchema().getVersion())) {
i.replace(projectData);
}
}
fireProjectIndexedEvent(nameKey.get());
} else {
logger.atInfo().log("Delete project %s from index", nameKey.get());
for (ProjectIndex i : getWriteIndexes()) {
i.delete(nameKey);
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Deleting project %s in index version %d",
nameKey.get(), i.getSchema().getVersion())) {
i.delete(nameKey);
}
}
}
}

73
java/com/google/gerrit/server/logging/TraceContext.java
View File

@@ -16,11 +16,15 @@ package com.google.gerrit.server.logging;
import static com.google.common.base.Preconditions.checkNotNull;
import com.google.common.base.Stopwatch;
import com.google.common.base.Strings;
import com.google.common.collect.HashBasedTable;
import com.google.common.collect.Table;
import com.google.common.flogger.FluentLogger;
import com.google.gerrit.common.Nullable;
import java.util.Optional;
import java.util.concurrent.TimeUnit;
import java.util.function.Consumer;
/**
* TraceContext that allows to set logging tags and enforce logging.
@@ -149,6 +153,75 @@ public class TraceContext implements AutoCloseable {
void accept(String tagName, String traceId);
}
/**
* Opens a new timer that logs the time for an operation if request tracing is enabled.
*
* <p>If request tracing is not enabled this is a no-op.
*
* @param message the message
* @return the trace timer
*/
public static TraceTimer newTimer(String message) {
return new TraceTimer(message);
}
/**
* Opens a new timer that logs the time for an operation if request tracing is enabled.
*
* <p>If request tracing is not enabled this is a no-op.
*
* @param format the message format string
* @param arg argument for the message
* @return the trace timer
*/
public static TraceTimer newTimer(String format, Object arg) {
return new TraceTimer(format, arg);
}
/**
* Opens a new timer that logs the time for an operation if request tracing is enabled.
*
* <p>If request tracing is not enabled this is a no-op.
*
* @param format the message format string
* @param arg1 first argument for the message
* @param arg2 second argument for the message
* @return the trace timer
*/
public static TraceTimer newTimer(String format, Object arg1, Object arg2) {
return new TraceTimer(format, arg1, arg2);
}
public static class TraceTimer implements AutoCloseable {
private static final FluentLogger logger = FluentLogger.forEnclosingClass();
private final Consumer<Long> logFn;
private final Stopwatch stopwatch;
private TraceTimer(String message) {
this(elapsedMs -> logger.atFine().log(message + " (%d ms)", elapsedMs));
}
private TraceTimer(String format, @Nullable Object arg) {
this(elapsedMs -> logger.atFine().log(format + " (%d ms)", arg, elapsedMs));
}
private TraceTimer(String format, @Nullable Object arg1, @Nullable Object arg2) {
this(elapsedMs -> logger.atFine().log(format + " (%d ms)", arg1, arg2, elapsedMs));
}
private TraceTimer(Consumer<Long> logFn) {
this.logFn = logFn;
this.stopwatch = Stopwatch.createStarted();
}
@Override
public void close() {
stopwatch.stop();
logFn.accept(stopwatch.elapsed(TimeUnit.MILLISECONDS));
}
}
// Table<TAG_NAME, TAG_VALUE, REMOVE_ON_CLOSE>
private final Table<String, String, Boolean> tags = HashBasedTable.create();