Have a dedicated class for metadata that is provided to TraceTimer and PerformanceLogger

Currently all metadata are key-value pairs, where both keys and values
are strings. This leads to an API that is difficult to use:

* change I776138eaa had to fix callers which forgot to specify metadata
  keys
* change I758660f8b had to make metadata keys consistent
* there are many similar methods with different numbers of key-value
  pairs for metadata

This change introduces a dedicated Metadata class that is used in the
API instead of key-value pairs that are strings. The Metadata class
contains dedicated fields for all known metadata types. Using the
Metadata.Builder it's now easy to provide metadata consistenly in all
places (there are dedicated methods to set pieces of metadata, so that
there is no longer a need to provide string keys for them).

For plugins that want to provide metadata for which Gerrit core doesn't
provide a suitable metadata field, Metadata contains a pluginMetadata
field in which arbitrary key-value pairs can be stored. That should only
be used for plugins. If Gerrit core needs additional metadata fields the
Metadata class should be extended.

The fields in Metadata only use basic Java types because the logging
package, that contains the Metadata class, should not have any
dependency on the large Gerrit packages that define the Gerrit types
(e.g. Project.NameKey).

For PerformanceLoggers it is important to know about the semantics of
the provided metadata, as some of the metadata may be considered
sensitive and must not end up in a performance log. Having the Metadata
class allows PerformanceLogger implementations to decide which metadata
they want to log and which metadata they want to omit.

A speciality is the recording of performance log entries from metric
timers. Whenever a metric timer is used we automatically report the
measured time as a performance log record. As metadata we provide the
value of the metric fields which are used for bucketing. As metadata
keys we used the field names. To properly populate the metadata in the
new Metadata type now, the definition of the metric fields must do the
mapping of the field value to a field in the Metadata class. For this a
MetadataMapper must be provided when the field is created.

Change-Id: Idedf6368365cd7b54a78c86457d26933746477e8
Signed-off-by: Edwin Kempin <ekempin@google.com>
This commit is contained in:
Edwin Kempin
2019-06-26 13:57:38 +02:00
parent c90dc3af6d
commit 103c5d14fe
50 changed files with 594 additions and 788 deletions

View File

@@ -18,6 +18,7 @@ import com.google.gerrit.metrics.Counter1;
import com.google.gerrit.metrics.Description;
import com.google.gerrit.metrics.Field;
import com.google.gerrit.metrics.MetricMaker;
import com.google.gerrit.server.logging.Metadata;
import com.google.inject.Inject;
import com.google.inject.Singleton;
@@ -29,7 +30,9 @@ public class RequestMetrics {
@Inject
public RequestMetrics(MetricMaker metricMaker) {
Field<Integer> statusCodeField =
Field.ofInteger("status").description("HTTP status code").build();
Field.ofInteger("status", Metadata.Builder::httpStatus)
.description("HTTP status code")
.build();
errors =
metricMaker.newCounter(

View File

@@ -25,6 +25,7 @@ import com.google.gerrit.metrics.Field;
import com.google.gerrit.metrics.Histogram1;
import com.google.gerrit.metrics.MetricMaker;
import com.google.gerrit.metrics.Timer1;
import com.google.gerrit.server.logging.Metadata;
import com.google.inject.Inject;
import com.google.inject.Singleton;
@@ -42,7 +43,9 @@ public class RestApiMetrics {
@Inject
RestApiMetrics(MetricMaker metrics) {
Field<String> viewField =
Field.ofString("view").description("view implementation class").build();
Field.ofString("view", Metadata.Builder::className)
.description("view implementation class")
.build();
count =
metrics.newCounter(
"http/server/rest_api/count",
@@ -54,7 +57,9 @@ public class RestApiMetrics {
"http/server/rest_api/error_count",
new Description("REST API errors by view").setRate(),
viewField,
Field.ofInteger("error_code").description("HTTP status code").build());
Field.ofInteger("error_code", Metadata.Builder::httpStatus)
.description("HTTP status code")
.build());
serverLatency =
metrics.newTimer(

View File

@@ -38,6 +38,7 @@ import com.google.gerrit.metrics.Field;
import com.google.gerrit.metrics.MetricMaker;
import com.google.gerrit.metrics.Timer1;
import com.google.gerrit.server.logging.CallerFinder;
import com.google.gerrit.server.logging.Metadata;
import java.util.ArrayList;
import java.util.List;
import java.util.Optional;
@@ -66,7 +67,9 @@ public abstract class QueryProcessor<T> {
new Description("Successful query latency, accumulated over the life of the process")
.setCumulative()
.setUnit(Description.Units.MILLISECONDS),
Field.ofString("index").description("index name").build());
Field.ofString("index", Metadata.Builder::indexName)
.description("index name")
.build());
}
}

View File

@@ -17,7 +17,9 @@ package com.google.gerrit.metrics;
import static com.google.common.base.Preconditions.checkArgument;
import com.google.auto.value.AutoValue;
import com.google.gerrit.server.logging.Metadata;
import java.util.Optional;
import java.util.function.BiConsumer;
import java.util.function.Function;
/**
@@ -27,17 +29,23 @@ import java.util.function.Function;
*/
@AutoValue
public abstract class Field<T> {
public static <T> BiConsumer<Metadata.Builder, T> ignoreMetadata() {
return (metadataBuilder, fieldValue) -> {};
}
/**
* Break down metrics by boolean true/false.
*
* @param name field name
* @return builder for the boolean field
*/
public static Field.Builder<Boolean> ofBoolean(String name) {
public static Field.Builder<Boolean> ofBoolean(
String name, BiConsumer<Metadata.Builder, Boolean> metadataMapper) {
return new AutoValue_Field.Builder<Boolean>()
.valueType(Boolean.class)
.formatter(Object::toString)
.name(name);
.name(name)
.metadataMapper(metadataMapper);
}
/**
@@ -47,8 +55,15 @@ public abstract class Field<T> {
* @param name field name
* @return builder for the enum field
*/
public static <E extends Enum<E>> Field.Builder<E> ofEnum(Class<E> enumType, String name) {
return new AutoValue_Field.Builder<E>().valueType(enumType).formatter(Enum::name).name(name);
public static <E extends Enum<E>> Field.Builder<E> ofEnum(
Class<E> enumType, String name, BiConsumer<Metadata.Builder, String> metadataMapper) {
return new AutoValue_Field.Builder<E>()
.valueType(enumType)
.formatter(Enum::name)
.name(name)
.metadataMapper(
(metadataBuilder, fieldValue) ->
metadataMapper.accept(metadataBuilder, fieldValue.name()));
}
/**
@@ -60,11 +75,13 @@ public abstract class Field<T> {
* @param name field name
* @return builder for the integer field
*/
public static Field.Builder<Integer> ofInteger(String name) {
public static Field.Builder<Integer> ofInteger(
String name, BiConsumer<Metadata.Builder, Integer> metadataMapper) {
return new AutoValue_Field.Builder<Integer>()
.valueType(Integer.class)
.formatter(Object::toString)
.name(name);
.name(name)
.metadataMapper(metadataMapper);
}
/**
@@ -76,11 +93,13 @@ public abstract class Field<T> {
* @param name field name
* @return builder for the string field
*/
public static Field.Builder<String> ofString(String name) {
public static Field.Builder<String> ofString(
String name, BiConsumer<Metadata.Builder, String> metadataMapper) {
return new AutoValue_Field.Builder<String>()
.valueType(String.class)
.formatter(s -> s)
.name(name);
.name(name)
.metadataMapper(metadataMapper);
}
/** @return name of this field within the metric. */
@@ -89,6 +108,9 @@ public abstract class Field<T> {
/** @return type of value used within the field. */
public abstract Class<T> valueType();
/** @return mapper that maps a field value to a field in the {@link Metadata} class. */
public abstract BiConsumer<Metadata.Builder, T> metadataMapper();
/** @return description text for the field explaining its range of values. */
public abstract Optional<String> description();
@@ -103,6 +125,8 @@ public abstract class Field<T> {
abstract Builder<T> formatter(Function<T, String> formatter);
abstract Builder<T> metadataMapper(BiConsumer<Metadata.Builder, T> metadataMapper);
public abstract Builder<T> description(String description);
abstract Field<T> autoBuild();

View File

@@ -19,6 +19,7 @@ import static java.util.concurrent.TimeUnit.NANOSECONDS;
import com.google.common.flogger.FluentLogger;
import com.google.gerrit.extensions.registration.RegistrationHandle;
import com.google.gerrit.server.logging.LoggingContext;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.logging.PerformanceLogRecord;
import java.util.concurrent.TimeUnit;
@@ -80,9 +81,12 @@ public abstract class Timer1<F1> implements RegistrationHandle {
public final void record(F1 fieldValue, long value, TimeUnit unit) {
long durationMs = unit.toMillis(value);
Metadata.Builder metadataBuilder = Metadata.builder();
field.metadataMapper().accept(metadataBuilder, fieldValue);
Metadata metadata = metadataBuilder.build();
LoggingContext.getInstance()
.addPerformanceLogRecord(
() -> PerformanceLogRecord.create(name, durationMs, field.name(), fieldValue));
.addPerformanceLogRecord(() -> PerformanceLogRecord.create(name, durationMs, metadata));
logger.atFinest().log("%s (%s = %s) took %dms", name, field.name(), fieldValue, durationMs);
doRecord(fieldValue, value, unit);

View File

@@ -19,6 +19,7 @@ import static java.util.concurrent.TimeUnit.NANOSECONDS;
import com.google.common.flogger.FluentLogger;
import com.google.gerrit.extensions.registration.RegistrationHandle;
import com.google.gerrit.server.logging.LoggingContext;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.logging.PerformanceLogRecord;
import java.util.concurrent.TimeUnit;
@@ -87,11 +88,13 @@ public abstract class Timer2<F1, F2> implements RegistrationHandle {
public final void record(F1 fieldValue1, F2 fieldValue2, long value, TimeUnit unit) {
long durationMs = unit.toMillis(value);
Metadata.Builder metadataBuilder = Metadata.builder();
field1.metadataMapper().accept(metadataBuilder, fieldValue1);
field2.metadataMapper().accept(metadataBuilder, fieldValue2);
Metadata metadata = metadataBuilder.build();
LoggingContext.getInstance()
.addPerformanceLogRecord(
() ->
PerformanceLogRecord.create(
name, durationMs, field1.name(), fieldValue1, field2.name(), fieldValue2));
.addPerformanceLogRecord(() -> PerformanceLogRecord.create(name, durationMs, metadata));
logger.atFinest().log(
"%s (%s = %s, %s = %s) took %dms",

View File

@@ -19,6 +19,7 @@ import static java.util.concurrent.TimeUnit.NANOSECONDS;
import com.google.common.flogger.FluentLogger;
import com.google.gerrit.extensions.registration.RegistrationHandle;
import com.google.gerrit.server.logging.LoggingContext;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.logging.PerformanceLogRecord;
import java.util.concurrent.TimeUnit;
@@ -95,18 +96,14 @@ public abstract class Timer3<F1, F2, F3> implements RegistrationHandle {
F1 fieldValue1, F2 fieldValue2, F3 fieldValue3, long value, TimeUnit unit) {
long durationMs = unit.toMillis(value);
Metadata.Builder metadataBuilder = Metadata.builder();
field1.metadataMapper().accept(metadataBuilder, fieldValue1);
field2.metadataMapper().accept(metadataBuilder, fieldValue2);
field3.metadataMapper().accept(metadataBuilder, fieldValue3);
Metadata metadata = metadataBuilder.build();
LoggingContext.getInstance()
.addPerformanceLogRecord(
() ->
PerformanceLogRecord.create(
name,
durationMs,
field1.name(),
fieldValue1,
field2.name(),
fieldValue2,
field3.name(),
fieldValue3));
.addPerformanceLogRecord(() -> PerformanceLogRecord.create(name, durationMs, metadata));
logger.atFinest().log(
"%s (%s = %s, %s = %s, %s = %s) took %dms",

View File

@@ -23,6 +23,7 @@ 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.server.logging.Metadata;
import java.lang.management.GarbageCollectorMXBean;
import java.lang.management.ManagementFactory;
import java.lang.management.MemoryMXBean;
@@ -149,7 +150,9 @@ public class ProcMetricModule extends MetricModule {
private void procJvmGc(MetricMaker metrics) {
Field<String> gcNameField =
Field.ofString("gc_name").description("The name of the garbage collector").build();
Field.ofString("gc_name", Metadata.Builder::garbageCollectorName)
.description("The name of the garbage collector")
.build();
CallbackMetric1<String, Long> gcCount =
metrics.newCallbackMetric(

View File

@@ -42,6 +42,7 @@ import com.google.gerrit.server.extensions.events.GitReferenceUpdated;
import com.google.gerrit.server.git.GitRepositoryManager;
import com.google.gerrit.server.index.change.ChangeField;
import com.google.gerrit.server.index.change.ChangeIndexer;
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.project.NoSuchChangeException;
@@ -376,7 +377,9 @@ public class StarredChangesUtil {
}
public static StarRef readLabels(Repository repo, String refName) throws IOException {
try (TraceTimer traceTimer = TraceContext.newTimer("Read star labels", "ref", refName)) {
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Read star labels", Metadata.builder().noteDbRefName(refName).build())) {
Ref ref = repo.exactRef(refName);
if (ref == null) {
return StarRef.MISSING;
@@ -451,7 +454,8 @@ public class StarredChangesUtil {
throws IOException, InvalidLabelsException {
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Update star labels", "ref", refName, "labelCount", labels.size());
"Update star labels",
Metadata.builder().noteDbRefName(refName).resourceCount(labels.size()).build());
RevWalk rw = new RevWalk(repo)) {
RefUpdate u = repo.updateRef(refName);
u.setExpectedOldObjectId(oldObjectId);
@@ -488,7 +492,9 @@ public class StarredChangesUtil {
return;
}
try (TraceTimer traceTimer = TraceContext.newTimer("Delete star labels", "ref", refName)) {
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Delete star labels", Metadata.builder().noteDbRefName(refName).build())) {
RefUpdate u = repo.updateRef(refName);
u.setForceUpdate(true);
u.setExpectedOldObjectId(oldObjectId);

View File

@@ -27,6 +27,7 @@ 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.config.AllUsersName;
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.util.time.TimeUtil;
@@ -183,7 +184,9 @@ public class AccountCacheImpl implements AccountCache {
@Override
public Optional<AccountState> load(Account.Id who) throws Exception {
try (TraceTimer timer = TraceContext.newTimer("Loading account", "accountId", who)) {
try (TraceTimer timer =
TraceContext.newTimer(
"Loading account", Metadata.builder().accountId(who.get()).build())) {
return accounts.get(who);
}
}

View File

@@ -21,6 +21,7 @@ import com.google.gerrit.reviewdb.client.AccountGroup;
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.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.query.group.InternalGroupQuery;
@@ -149,7 +150,9 @@ public class GroupCacheImpl implements GroupCache {
@Override
public Optional<InternalGroup> load(AccountGroup.Id key) throws Exception {
try (TraceTimer timer = TraceContext.newTimer("Loading group by ID", "groupId", key)) {
try (TraceTimer timer =
TraceContext.newTimer(
"Loading group by ID", Metadata.builder().groupId(key.get()).build())) {
return groupQueryProvider.get().byId(key);
}
}
@@ -165,7 +168,9 @@ public class GroupCacheImpl implements GroupCache {
@Override
public Optional<InternalGroup> load(String name) throws Exception {
try (TraceTimer timer = TraceContext.newTimer("Loading group by name", "groupName", name)) {
try (TraceTimer timer =
TraceContext.newTimer(
"Loading group by name", Metadata.builder().groupName(name).build())) {
return groupQueryProvider.get().byName(AccountGroup.nameKey(name));
}
}
@@ -181,7 +186,9 @@ public class GroupCacheImpl implements GroupCache {
@Override
public Optional<InternalGroup> load(String uuid) throws Exception {
try (TraceTimer timer = TraceContext.newTimer("Loading group by UUID", "groupUuid", uuid)) {
try (TraceTimer timer =
TraceContext.newTimer(
"Loading group by UUID", Metadata.builder().groupUuid(uuid).build())) {
return groups.getGroup(AccountGroup.uuid(uuid));
}
}

View File

@@ -27,6 +27,7 @@ import com.google.gerrit.reviewdb.client.AccountGroup;
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.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.query.group.InternalGroupQuery;
@@ -153,7 +154,8 @@ public class GroupIncludeCacheImpl implements GroupIncludeCache {
@Override
public ImmutableSet<AccountGroup.UUID> load(Account.Id memberId) {
try (TraceTimer timer =
TraceContext.newTimer("Loading groups with member", "memberId", memberId)) {
TraceContext.newTimer(
"Loading groups with member", Metadata.builder().accountId(memberId.get()).build())) {
return groupQueryProvider.get().byMember(memberId).stream()
.map(InternalGroup::getGroupUUID)
.collect(toImmutableSet());
@@ -172,7 +174,9 @@ public class GroupIncludeCacheImpl implements GroupIncludeCache {
@Override
public ImmutableList<AccountGroup.UUID> load(AccountGroup.UUID key) {
try (TraceTimer timer = TraceContext.newTimer("Loading parent groups", "groupUuid", key)) {
try (TraceTimer timer =
TraceContext.newTimer(
"Loading parent groups", Metadata.builder().groupUuid(key.get()).build())) {
return groupQueryProvider.get().bySubgroup(key).stream()
.map(InternalGroup::getGroupUUID)
.collect(toImmutableList());

View File

@@ -22,6 +22,7 @@ import com.google.common.collect.MultimapBuilder;
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.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.inject.Inject;
@@ -157,7 +158,9 @@ class ExternalIdCacheImpl implements ExternalIdCache {
@Override
public AllExternalIds load(ObjectId notesRev) throws Exception {
try (TraceTimer timer = TraceContext.newTimer("Loading external IDs", "revision", notesRev)) {
try (TraceTimer timer =
TraceContext.newTimer(
"Loading external IDs", Metadata.builder().revision(notesRev.name()).build())) {
ImmutableSet<ExternalId> externalIds = externalIdReader.all(notesRev);
externalIds.forEach(ExternalId::checkThatBlobIdIsSet);
return AllExternalIds.create(externalIds);

View File

@@ -37,6 +37,7 @@ import com.google.gerrit.server.auth.AuthenticationUnavailableException;
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.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.inject.Inject;
@@ -354,7 +355,8 @@ class LdapRealm extends AbstractRealm {
@Override
public Optional<Account.Id> load(String username) throws Exception {
try (TraceTimer timer =
TraceContext.newTimer("Loading account for username", "username", username)) {
TraceContext.newTimer(
"Loading account for username", Metadata.builder().username(username).build())) {
return externalIds
.get(ExternalId.Key.create(SCHEME_GERRIT, username))
.map(ExternalId::accountId);
@@ -373,7 +375,9 @@ class LdapRealm extends AbstractRealm {
@Override
public Set<AccountGroup.UUID> load(String username) throws Exception {
try (TraceTimer timer =
TraceContext.newTimer("Loading group for member with username", "username", username)) {
TraceContext.newTimer(
"Loading group for member with username",
Metadata.builder().username(username).build())) {
final DirContext ctx = helper.open();
try {
return helper.queryForGroups(ctx, username, null);
@@ -394,7 +398,9 @@ class LdapRealm extends AbstractRealm {
@Override
public Boolean load(String groupDn) throws Exception {
try (TraceTimer timer = TraceContext.newTimer("Loading groupDn", "groupDn", groupDn)) {
try (TraceTimer timer =
TraceContext.newTimer(
"Loading groupDn", Metadata.builder().authDomainName(groupDn).build())) {
final DirContext ctx = helper.open();
try {
Name compositeGroupName = new CompositeName().add(groupDn);

View File

@@ -25,6 +25,7 @@ import com.google.gerrit.metrics.CallbackMetric1;
import com.google.gerrit.metrics.Description;
import com.google.gerrit.metrics.Field;
import com.google.gerrit.metrics.MetricMaker;
import com.google.gerrit.server.logging.Metadata;
import com.google.inject.Inject;
import com.google.inject.Singleton;
import java.util.Set;
@@ -33,7 +34,7 @@ import java.util.Set;
public class CacheMetrics {
@Inject
public CacheMetrics(MetricMaker metrics, DynamicMap<Cache<?, ?>> cacheMap) {
Field<String> F_NAME = Field.ofString("cache_name").build();
Field<String> F_NAME = Field.ofString("cache_name", Metadata.Builder::cacheName).build();
CallbackMetric1<String, Long> memEnt =
metrics.newCallbackMetric(

View File

@@ -26,6 +26,7 @@ import com.google.common.hash.BloomFilter;
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.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.util.time.TimeUtil;
@@ -237,7 +238,9 @@ public class H2CacheImpl<K, V> extends AbstractLoadingCache<K, V> implements Per
@Override
public ValueHolder<V> load(K key) throws Exception {
try (TraceTimer timer = TraceContext.newTimer("Loading value from cache", "key", key)) {
try (TraceTimer timer =
TraceContext.newTimer(
"Loading value from cache", Metadata.builder().cacheKey(key.toString()).build())) {
if (store.mightContain(key)) {
ValueHolder<V> h = store.getIfPresent(key);
if (h != null) {

View File

@@ -34,6 +34,7 @@ import com.google.gerrit.reviewdb.client.Project;
import com.google.gerrit.server.cache.CacheModule;
import com.google.gerrit.server.config.ConfigUtil;
import com.google.gerrit.server.config.GerritServerConfig;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.notedb.ChangeNotes;
import com.google.gerrit.server.project.NoSuchChangeException;
import com.google.gerrit.server.query.change.ChangeData;
@@ -98,7 +99,8 @@ public class ChangeFinder {
new Description("Total number of API calls per identifier type.")
.setRate()
.setUnit("requests"),
Field.ofEnum(ChangeIdType.class, "change_id_type").build());
Field.ofEnum(ChangeIdType.class, "change_id_type", Metadata.Builder::changeIdType)
.build());
List<ChangeIdType> configuredChangeIdTypes =
ConfigUtil.getEnumList(config, "change", "api", "allowedIdentifier", ChangeIdType.ALL);
// Ensure that PROJECT_NUMERIC_ID can't be removed

View File

@@ -18,6 +18,7 @@ import com.google.gerrit.metrics.Counter1;
import com.google.gerrit.metrics.Description;
import com.google.gerrit.metrics.Field;
import com.google.gerrit.metrics.MetricMaker;
import com.google.gerrit.server.logging.Metadata;
import com.google.inject.Inject;
import com.google.inject.Singleton;
@@ -31,7 +32,7 @@ public class EventsMetrics implements EventListener {
metricMaker.newCounter(
"events",
new Description("Triggered events").setRate().setUnit("triggered events"),
Field.ofString("type").build());
Field.ofString("type", Metadata.Builder::eventType).build());
}
@Override

View File

@@ -37,6 +37,7 @@ 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.gerrit.server.logging.Metadata;
import com.google.gerrit.server.permissions.GlobalPermission;
import com.google.gerrit.server.permissions.PermissionBackend;
import com.google.gerrit.server.permissions.PermissionBackendCondition;
@@ -71,7 +72,7 @@ public class UiActions {
new com.google.gerrit.metrics.Description("Latency for RestView#getDescription calls")
.setCumulative()
.setUnit(Units.MILLISECONDS),
Field.ofString("view").build());
Field.ofString("view", Metadata.Builder::restViewName).build());
}
public <R extends RestResource> Iterable<UiAction.Description> from(

View File

@@ -27,6 +27,7 @@ import com.google.gerrit.server.cache.proto.Cache.PureRevertKeyProto;
import com.google.gerrit.server.cache.serialize.BooleanCacheSerializer;
import com.google.gerrit.server.cache.serialize.ObjectIdConverter;
import com.google.gerrit.server.cache.serialize.ProtobufSerializer;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.notedb.ChangeNotes;
import com.google.gerrit.server.project.ProjectCache;
@@ -151,7 +152,9 @@ public class PureRevertCache {
@Override
public Boolean load(PureRevertKeyProto key) throws BadRequestException, IOException {
try (TraceContext.TraceTimer ignored =
TraceContext.newTimer("Loading pure revert", "key", key)) {
TraceContext.newTimer(
"Loading pure revert",
Metadata.builder().cacheKey(key.toString()).projectName(key.getProject()).build())) {
ObjectId original = ObjectIdConverter.create().fromByteString(key.getClaimedOriginal());
ObjectId revert = ObjectIdConverter.create().fromByteString(key.getClaimedRevert());
Project.NameKey project = Project.nameKey(key.getProject());

View File

@@ -28,6 +28,7 @@ import com.google.gerrit.reviewdb.client.RefNames;
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.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.query.change.ChangeData;
@@ -153,7 +154,8 @@ public class SearchingChangeCacheImpl implements GitReferenceUpdatedListener {
@Override
public List<CachedChange> load(Project.NameKey key) throws Exception {
try (TraceTimer timer =
TraceContext.newTimer("Loading changes of project", "projectName", key);
TraceContext.newTimer(
"Loading changes of project", Metadata.builder().projectName(key.get()).build());
ManualRequestContext ctx = requestContext.open()) {
List<ChangeData> cds =
queryProvider

View File

@@ -23,6 +23,7 @@ import com.google.gerrit.metrics.Field;
import com.google.gerrit.metrics.Histogram1;
import com.google.gerrit.metrics.MetricMaker;
import com.google.gerrit.metrics.Timer1;
import com.google.gerrit.server.logging.Metadata;
import com.google.inject.Inject;
import com.google.inject.Singleton;
import org.eclipse.jgit.storage.pack.PackStatistics;
@@ -43,7 +44,8 @@ public class UploadPackMetricsHook implements PostUploadHook {
@Inject
UploadPackMetricsHook(MetricMaker metricMaker) {
Field<Operation> operationField = Field.ofEnum(Operation.class, "operation").build();
Field<Operation> operationField =
Field.ofEnum(Operation.class, "operation", Metadata.Builder::gitOperation).build();
requestCount =
metricMaker.newCounter(
"git/upload-pack/request_count",

View File

@@ -21,6 +21,7 @@ import com.google.gerrit.common.Nullable;
import com.google.gerrit.git.LockFailureException;
import com.google.gerrit.git.ObjectIds;
import com.google.gerrit.reviewdb.client.Project;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import java.io.BufferedReader;
@@ -500,14 +501,12 @@ public abstract class VersionedMetaData {
try (TraceTimer timer =
TraceContext.newTimer(
"Read file",
"fileName",
fileName,
"ref",
getRefName(),
"projectName",
projectName,
"revision",
revision.name());
Metadata.builder()
.projectName(projectName.get())
.noteDbRefName(getRefName())
.revision(revision.name())
.noteDbFileName(fileName)
.build());
TreeWalk tw = TreeWalk.forPath(reader, fileName, revision.getTree())) {
if (tw != null) {
ObjectLoader obj = reader.open(tw.getObjectId(0), Constants.OBJ_BLOB);
@@ -582,7 +581,12 @@ public abstract class VersionedMetaData {
protected void saveFile(String fileName, byte[] raw) throws IOException {
try (TraceTimer timer =
TraceContext.newTimer(
"Save file", "fileName", fileName, "ref", getRefName(), "projectName", projectName)) {
"Save file",
Metadata.builder()
.projectName(projectName.get())
.noteDbRefName(getRefName())
.noteDbFileName(fileName)
.build())) {
DirCacheEditor editor = newTree.editor();
if (raw != null && 0 < raw.length) {
final ObjectId blobId = inserter.insert(Constants.OBJ_BLOB, raw);

View File

@@ -38,6 +38,7 @@ import com.google.gerrit.server.config.ReceiveCommitsExecutor;
import com.google.gerrit.server.git.MultiProgressMonitor;
import com.google.gerrit.server.git.ProjectRunnable;
import com.google.gerrit.server.git.TransferConfig;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.permissions.PermissionBackend;
import com.google.gerrit.server.permissions.PermissionBackendException;
import com.google.gerrit.server.permissions.ProjectPermission;
@@ -199,12 +200,12 @@ public class AsyncReceiveCommits implements PreReceiveHook {
metricMaker.newHistogram(
"receivecommits/changes_per_push",
new Description("number of changes uploaded in a single push.").setCumulative(),
Field.ofEnum(PushType.class, "type")
Field.ofEnum(PushType.class, "type", Metadata.Builder::pushType)
.description("type of push (create/replace, autoclose)")
.build());
Field<PushType> pushTypeField =
Field.ofEnum(PushType.class, "type")
Field.ofEnum(PushType.class, "type", Metadata.Builder::pushType)
.description("type of push (create/replace, autoclose, normal)")
.build();

View File

@@ -125,6 +125,7 @@ import com.google.gerrit.server.git.validators.RefOperationValidationException;
import com.google.gerrit.server.git.validators.RefOperationValidators;
import com.google.gerrit.server.git.validators.ValidationMessage;
import com.google.gerrit.server.index.change.ChangeIndexer;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.logging.PerformanceLogContext;
import com.google.gerrit.server.logging.PerformanceLogger;
import com.google.gerrit.server.logging.RequestId;
@@ -525,12 +526,14 @@ class ReceiveCommits {
void processCommands(Collection<ReceiveCommand> commands, MultiProgressMonitor progress) {
parsePushOptions();
int commandCount = commands.size();
try (TraceContext traceContext =
TraceContext.newTrace(
tracePushOption.isPresent(),
tracePushOption.orElse(null),
(tagName, traceId) -> addMessage(tagName + ": " + traceId));
TraceTimer traceTimer = newTimer("processCommands", "commandCount", commands.size());
TraceTimer traceTimer =
newTimer("processCommands", Metadata.builder().resourceCount(commandCount));
PerformanceLogContext performanceLogContext =
new PerformanceLogContext(config, performanceLoggers)) {
traceContext.addTag(RequestId.Type.RECEIVE_ID, new RequestId(project.getNameKey().get()));
@@ -644,7 +647,8 @@ class ReceiveCommits {
private void handleRegularCommands(List<ReceiveCommand> cmds, MultiProgressMonitor progress)
throws PermissionBackendException, IOException, NoSuchProjectException {
try (TraceTimer traceTimer = newTimer("handleRegularCommands", "commandCount", cmds.size())) {
try (TraceTimer traceTimer =
newTimer("handleRegularCommands", Metadata.builder().resourceCount(cmds.size()))) {
resultChangeIds.setMagicPush(false);
for (ReceiveCommand cmd : cmds) {
parseRegularCommand(cmd);
@@ -828,7 +832,8 @@ class ReceiveCommits {
private void insertChangesAndPatchSets(List<CreateRequest> newChanges, Task replaceProgress) {
try (TraceTimer traceTimer =
newTimer("insertChangesAndPatchSets", "changeCount", newChanges.size())) {
newTimer(
"insertChangesAndPatchSets", Metadata.builder().resourceCount(newChanges.size()))) {
ReceiveCommand magicBranchCmd = magicBranch != null ? magicBranch.cmd : null;
if (magicBranchCmd != null && magicBranchCmd.getResult() != NOT_ATTEMPTED) {
logger.atWarning().log(
@@ -1891,7 +1896,8 @@ class ReceiveCommits {
// looking to see if we can compute a merge base between the new
// commits and the target branch head.
private boolean validateConnected(ReceiveCommand cmd, BranchNameKey dest, RevCommit tip) {
try (TraceTimer traceTimer = newTimer("validateConnected", "branch", dest.branch())) {
try (TraceTimer traceTimer =
newTimer("validateConnected", Metadata.builder().branchName(dest.branch()))) {
RevWalk walk = receivePack.getRevWalk();
try {
Ref targetRef = receivePack.getAdvertisedRefs().get(dest.branch());
@@ -2383,7 +2389,8 @@ class ReceiveCommits {
// Mark all branch tips as uninteresting in the given revwalk,
// so we get only the new commits when walking rw.
private void markHeadsAsUninteresting(RevWalk rw, @Nullable String forRef) {
try (TraceTimer traceTimer = newTimer("markHeadsAsUninteresting", "forRef", forRef)) {
try (TraceTimer traceTimer =
newTimer("markHeadsAsUninteresting", Metadata.builder().branchName(forRef))) {
int i = 0;
for (Ref ref : allRefs().values()) {
if ((ref.getName().startsWith(R_HEADS) || ref.getName().equals(forRef))
@@ -2587,7 +2594,8 @@ class ReceiveCommits {
private void preparePatchSetsForReplace(List<CreateRequest> newChanges) {
try (TraceTimer traceTimer =
newTimer("preparePatchSetsForReplace", "changeCount", newChanges.size())) {
newTimer(
"preparePatchSetsForReplace", Metadata.builder().resourceCount(newChanges.size()))) {
try {
readChangesForReplace();
for (ReplaceRequest req : replaceByChange.values()) {
@@ -3111,7 +3119,7 @@ class ReceiveCommits {
private void validateRegularPushCommits(BranchNameKey branch, ReceiveCommand cmd)
throws PermissionBackendException {
try (TraceTimer traceTimer =
newTimer("validateRegularPushCommits", "branch", branch.branch())) {
newTimer("validateRegularPushCommits", Metadata.builder().branchName(branch.branch()))) {
boolean skipValidation =
!RefNames.REFS_CONFIG.equals(cmd.getRefName())
&& !(MagicBranch.isMagicBranch(cmd.getRefName())
@@ -3313,7 +3321,8 @@ class ReceiveCommits {
}
private Map<Change.Key, ChangeNotes> openChangesByKeyByBranch(BranchNameKey branch) {
try (TraceTimer traceTimer = newTimer("openChangesByKeyByBranch", "branch", branch.branch())) {
try (TraceTimer traceTimer =
newTimer("openChangesByKeyByBranch", Metadata.builder().branchName(branch.branch()))) {
Map<Change.Key, ChangeNotes> r = new HashMap<>();
for (ChangeData cd : queryProvider.get().byBranchOpen(branch)) {
try {
@@ -3338,16 +3347,16 @@ class ReceiveCommits {
}
private TraceTimer newTimer(Class<?> clazz, String name) {
return TraceContext.newTimer(clazz.getSimpleName() + "#" + name, "projectName", project);
return newTimer(clazz, name, Metadata.builder());
}
private TraceTimer newTimer(String name, String key, @Nullable Object value) {
return newTimer(getClass(), name, key, value);
private TraceTimer newTimer(String name, Metadata.Builder metadataBuilder) {
return newTimer(getClass(), name, metadataBuilder);
}
private TraceTimer newTimer(Class<?> clazz, String name, String key, @Nullable Object value) {
return TraceContext.newTimer(
clazz.getSimpleName() + "#" + name, "projectName", project, key, value);
private TraceTimer newTimer(Class<?> clazz, String name, Metadata.Builder metadataBuilder) {
metadataBuilder.projectName(project.getName());
return TraceContext.newTimer(clazz.getSimpleName() + "#" + name, metadataBuilder.build());
}
private static void reject(ReceiveCommand cmd, String why) {

View File

@@ -42,6 +42,7 @@ import com.google.gerrit.server.git.meta.MetaDataUpdate;
import com.google.gerrit.server.group.GroupAuditService;
import com.google.gerrit.server.group.InternalGroup;
import com.google.gerrit.server.index.group.GroupIndexer;
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.update.RetryHelper;
@@ -266,8 +267,9 @@ public class GroupsUpdate {
try (TraceTimer timer =
TraceContext.newTimer(
"Creating group",
"groupName",
groupUpdate.getName().orElseGet(groupCreation::getNameKey))) {
Metadata.builder()
.groupName(groupUpdate.getName().orElseGet(groupCreation::getNameKey).get())
.build())) {
InternalGroup createdGroup = createGroupInNoteDbWithRetry(groupCreation, groupUpdate);
evictCachesOnGroupCreation(createdGroup);
dispatchAuditEventsOnGroupCreation(createdGroup);
@@ -287,7 +289,9 @@ public class GroupsUpdate {
*/
public void updateGroup(AccountGroup.UUID groupUuid, InternalGroupUpdate groupUpdate)
throws DuplicateKeyException, IOException, NoSuchGroupException, ConfigInvalidException {
try (TraceTimer timer = TraceContext.newTimer("Updating group", "groupUuid", groupUuid)) {
try (TraceTimer timer =
TraceContext.newTimer(
"Updating group", Metadata.builder().groupUuid(groupUuid.get()).build())) {
Optional<Timestamp> updatedOn = groupUpdate.getUpdatedOn();
if (!updatedOn.isPresent()) {
updatedOn = Optional.of(TimeUtil.nowTs());

View File

@@ -23,6 +23,7 @@ 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.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.plugincontext.PluginSetContext;
@@ -91,20 +92,20 @@ public class AccountIndexerImpl implements AccountIndexer {
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Replacing account in index",
"accountId",
id.get(),
"indexVersion",
i.getSchema().getVersion())) {
Metadata.builder()
.accountId(id.get())
.indexVersion(i.getSchema().getVersion())
.build())) {
i.replace(accountState.get());
}
} else {
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Deleting account in index",
"accountId",
id.get(),
"indexVersion",
i.getSchema().getVersion())) {
Metadata.builder()
.accountId(id.get())
.indexVersion(i.getSchema().getVersion())
.build())) {
i.delete(id);
}
}

View File

@@ -28,6 +28,7 @@ import com.google.gerrit.reviewdb.client.Change;
import com.google.gerrit.reviewdb.client.Project;
import com.google.gerrit.server.config.GerritServerConfig;
import com.google.gerrit.server.index.IndexExecutor;
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.plugincontext.PluginSetContext;
@@ -187,10 +188,10 @@ public class ChangeIndexer {
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Replacing change in index",
"changeId",
cd.getId().get(),
"indexVersion",
i.getSchema().getVersion())) {
Metadata.builder()
.changeId(cd.getId().get())
.indexVersion(i.getSchema().getVersion())
.build())) {
i.replace(cd);
}
}
@@ -378,10 +379,10 @@ public class ChangeIndexer {
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Deleting change in index",
"changeId",
id.get(),
"indexVersion",
i.getSchema().getVersion())) {
Metadata.builder()
.changeId(id.get())
.indexVersion(i.getSchema().getVersion())
.build())) {
i.delete(id);
}
}

View File

@@ -23,6 +23,7 @@ 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.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.plugincontext.PluginSetContext;
@@ -91,20 +92,20 @@ public class GroupIndexerImpl implements GroupIndexer {
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Replacing group",
"groupUuid",
uuid.get(),
"indexVersion",
i.getSchema().getVersion())) {
Metadata.builder()
.groupUuid(uuid.get())
.indexVersion(i.getSchema().getVersion())
.build())) {
i.replace(internalGroup.get());
}
} else {
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Deleting group",
"groupUuid",
uuid.get(),
"indexVersion",
i.getSchema().getVersion())) {
Metadata.builder()
.groupUuid(uuid.get())
.indexVersion(i.getSchema().getVersion())
.build())) {
i.delete(uuid);
}
}

View File

@@ -23,6 +23,7 @@ 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.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.plugincontext.PluginSetContext;
@@ -79,10 +80,10 @@ public class ProjectIndexerImpl implements ProjectIndexer {
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Replacing project",
"projectName",
nameKey.get(),
"indexVersion",
i.getSchema().getVersion())) {
Metadata.builder()
.projectName(nameKey.get())
.indexVersion(i.getSchema().getVersion())
.build())) {
i.replace(projectData);
}
}
@@ -93,10 +94,10 @@ public class ProjectIndexerImpl implements ProjectIndexer {
try (TraceTimer traceTimer =
TraceContext.newTimer(
"Deleting project",
"projectName",
nameKey.get(),
"indexVersion",
i.getSchema().getVersion())) {
Metadata.builder()
.projectName(nameKey.get())
.indexVersion(i.getSchema().getVersion())
.build())) {
i.delete(nameKey);
}
}

View File

@@ -0,0 +1,208 @@
// Copyright (C) 2019 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.logging;
import com.google.auto.value.AutoValue;
import com.google.common.collect.ImmutableList;
import com.google.gerrit.common.Nullable;
import java.util.Optional;
/** Metadata that is provided to {@link PerformanceLogger}s as context for performance records. */
@AutoValue
public abstract class Metadata {
// The numeric ID of an account.
public abstract Optional<Integer> accountId();
// The type of an action (ACCOUNT_UPDATE, CHANGE_UPDATE, GROUP_UPDATE, INDEX_QUERY,
// PLUGIN_UPDATE).
public abstract Optional<String> actionType();
// An authentication domain name.
public abstract Optional<String> authDomainName();
// The name of a branch.
public abstract Optional<String> branchName();
// Key of an entity in a cache.
public abstract Optional<String> cacheKey();
// The name of a cache.
public abstract Optional<String> cacheName();
// The name of the implementation class.
public abstract Optional<String> className();
// The numeric ID of a change.
public abstract Optional<Integer> changeId();
// The type of change ID which the user used to identify a change (e.g. numeric ID, triplet etc.).
public abstract Optional<String> changeIdType();
// The type of an event.
public abstract Optional<String> eventType();
// The value of the @Export annotation which was used to register a plugin extension.
public abstract Optional<String> exportValue();
// Garbage collector name.
public abstract Optional<String> garbageCollectorName();
// Git operation (CLONE, FETCH).
public abstract Optional<String> gitOperation();
// The numeric ID of an internal group.
public abstract Optional<Integer> groupId();
// The name of a group.
public abstract Optional<String> groupName();
// The UUID of a group.
public abstract Optional<String> groupUuid();
// HTTP status response code.
public abstract Optional<Integer> httpStatus();
// The name of a secondary index.
public abstract Optional<String> indexName();
// The version of a secondary index.
public abstract Optional<Integer> indexVersion();
// The name of the implementation method.
public abstract Optional<String> methodName();
// Boolean: one or more
public abstract Optional<Boolean> multiple();
// Name of a metadata file in NoteDb.
public abstract Optional<String> noteDbFileName();
// Name of a metadata ref in NoteDb.
public abstract Optional<String> noteDbRefName();
// Type of a sequence in NoteDb (ACCOUNTS, CHANGES, GROUPS).
public abstract Optional<String> noteDbSequenceType();
// Name of a "table" in NoteDb (if set, always CHANGES).
public abstract Optional<String> noteDbTable();
// Plugin metadata that doesn't fit into any other category.
public abstract ImmutableList<PluginMetadata> pluginMetadata();
// The name of a plugin.
public abstract Optional<String> pluginName();
// The name of a Gerrit project (aka Git repository).
public abstract Optional<String> projectName();
// The type of a Git push to Gerrit (CREATE_REPLACE, NORMAL, AUTOCLOSE).
public abstract Optional<String> pushType();
// The number of resources that is processed.
public abstract Optional<Integer> resourceCount();
// The name of a REST view.
public abstract Optional<String> restViewName();
// The SHA1 of Git commit.
public abstract Optional<String> revision();
// The username of an account.
public abstract Optional<String> username();
public static Metadata.Builder builder() {
return new AutoValue_Metadata.Builder();
}
public static Metadata empty() {
return builder().build();
}
@AutoValue.Builder
public abstract static class Builder {
public abstract Builder accountId(int accountId);
public abstract Builder actionType(@Nullable String actionType);
public abstract Builder authDomainName(@Nullable String authDomainName);
public abstract Builder branchName(@Nullable String branchName);
public abstract Builder cacheKey(@Nullable String cacheKey);
public abstract Builder cacheName(@Nullable String cacheName);
public abstract Builder className(@Nullable String className);
public abstract Builder changeId(int changeId);
public abstract Builder changeIdType(@Nullable String changeIdType);
public abstract Builder eventType(@Nullable String eventType);
public abstract Builder exportValue(@Nullable String exportValue);
public abstract Builder garbageCollectorName(@Nullable String garbageCollectorName);
public abstract Builder gitOperation(@Nullable String gitOperation);
public abstract Builder groupId(int groupId);
public abstract Builder groupName(@Nullable String groupName);
public abstract Builder groupUuid(@Nullable String groupUuid);
public abstract Builder httpStatus(int httpStatus);
public abstract Builder indexName(@Nullable String indexName);
public abstract Builder indexVersion(int indexVersion);
public abstract Builder methodName(@Nullable String methodName);
public abstract Builder multiple(boolean multiple);
public abstract Builder noteDbFileName(@Nullable String noteDbFileName);
public abstract Builder noteDbRefName(@Nullable String noteDbRefName);
public abstract Builder noteDbSequenceType(@Nullable String noteDbSequenceType);
public abstract Builder noteDbTable(@Nullable String noteDbTable);
abstract ImmutableList.Builder<PluginMetadata> pluginMetadataBuilder();
public Builder addPluginMetadata(PluginMetadata pluginMetadata) {
pluginMetadataBuilder().add(pluginMetadata);
return this;
}
public abstract Builder pluginName(@Nullable String pluginName);
public abstract Builder projectName(@Nullable String projectName);
public abstract Builder pushType(@Nullable String pushType);
public abstract Builder resourceCount(int resourceCount);
public abstract Builder restViewName(@Nullable String restViewName);
public abstract Builder revision(@Nullable String revision);
public abstract Builder username(@Nullable String username);
public abstract Metadata build();
}
}

View File

@@ -14,16 +14,14 @@
package com.google.gerrit.server.logging;
import static java.util.Objects.requireNonNull;
import com.google.auto.value.AutoValue;
import com.google.gerrit.common.Nullable;
import java.util.Optional;
/**
* The record of an operation for which the execution time was measured.
*
* <p>Meta data is stored in separate key/value fields to avoid expensive instantiations of Map
* objects.
* <p>Metadata to provide additional context can be included by providing a {@link Metadata}
* instance.
*/
@AutoValue
public abstract class PerformanceLogRecord {
@@ -35,8 +33,7 @@ public abstract class PerformanceLogRecord {
* @return the performance log record
*/
public static PerformanceLogRecord create(String operation, long durationMs) {
return new AutoValue_PerformanceLogRecord(
operation, durationMs, null, null, null, null, null, null, null, null);
return new AutoValue_PerformanceLogRecord(operation, durationMs, Optional.empty());
}
/**
@@ -44,175 +41,22 @@ public abstract class PerformanceLogRecord {
*
* @param operation the name of operation the is was performed
* @param durationMs the execution time in milliseconds
* @param key meta data key
* @param value meta data value
* @param metadata metadata
* @return the performance log record
*/
public static PerformanceLogRecord create(
String operation, long durationMs, String key, @Nullable Object value) {
return new AutoValue_PerformanceLogRecord(
operation, durationMs, requireNonNull(key), value, null, null, null, null, null, null);
}
/**
* Creates a performance log record with meta data.
*
* @param operation the name of operation the is was performed
* @param durationMs the execution time in milliseconds
* @param key1 first meta data key
* @param value1 first meta data value
* @param key2 second meta data key
* @param value2 second meta data value
* @return the performance log record
*/
public static PerformanceLogRecord create(
String operation,
long durationMs,
String key1,
@Nullable Object value1,
String key2,
@Nullable Object value2) {
return new AutoValue_PerformanceLogRecord(
operation,
durationMs,
requireNonNull(key1),
value1,
requireNonNull(key2),
value2,
null,
null,
null,
null);
}
/**
* Creates a performance log record with meta data.
*
* @param operation the name of operation the is was performed
* @param durationMs the execution time in milliseconds
* @param key1 first meta data key
* @param value1 first meta data value
* @param key2 second meta data key
* @param value2 second meta data value
* @param key3 third meta data key
* @param value3 third meta data value
* @return the performance log record
*/
public static PerformanceLogRecord create(
String operation,
long durationMs,
String key1,
@Nullable Object value1,
String key2,
@Nullable Object value2,
String key3,
@Nullable Object value3) {
return new AutoValue_PerformanceLogRecord(
operation,
durationMs,
requireNonNull(key1),
value1,
requireNonNull(key2),
value2,
requireNonNull(key3),
value3,
null,
null);
}
/**
* Creates a performance log record with meta data.
*
* @param operation the name of operation the is was performed
* @param durationMs the execution time in milliseconds
* @param key1 first meta data key
* @param value1 first meta data value
* @param key2 second meta data key
* @param value2 second meta data value
* @param key3 third meta data key
* @param value3 third meta data value
* @param key4 forth meta data key
* @param value4 forth meta data value
* @return the performance log record
*/
public static PerformanceLogRecord create(
String operation,
long durationMs,
String key1,
@Nullable Object value1,
String key2,
@Nullable Object value2,
String key3,
@Nullable Object value3,
String key4,
@Nullable Object value4) {
return new AutoValue_PerformanceLogRecord(
operation,
durationMs,
requireNonNull(key1),
value1,
requireNonNull(key2),
value2,
requireNonNull(key3),
value3,
requireNonNull(key4),
value4);
public static PerformanceLogRecord create(String operation, long durationMs, Metadata metadata) {
return new AutoValue_PerformanceLogRecord(operation, durationMs, Optional.of(metadata));
}
public abstract String operation();
public abstract long durationMs();
@Nullable
public abstract String key1();
@Nullable
public abstract Object value1();
@Nullable
public abstract String key2();
@Nullable
public abstract Object value2();
@Nullable
public abstract String key3();
@Nullable
public abstract Object value3();
@Nullable
public abstract String key4();
@Nullable
public abstract Object value4();
public abstract Optional<Metadata> metadata();
void writeTo(PerformanceLogger performanceLogger) {
if (key4() != null) {
requireNonNull(key1());
requireNonNull(key2());
requireNonNull(key3());
performanceLogger.log(
operation(),
durationMs(),
key1(),
value1(),
key2(),
value2(),
key3(),
value3(),
key4(),
value4());
} else if (key3() != null) {
requireNonNull(key1());
requireNonNull(key2());
performanceLogger.log(
operation(), durationMs(), key1(), value1(), key2(), value2(), key3(), value3());
} else if (key2() != null) {
requireNonNull(key1());
performanceLogger.log(operation(), durationMs(), key1(), value1(), key2(), value2());
} else if (key1() != null) {
performanceLogger.log(operation(), durationMs(), key1(), value1());
if (metadata().isPresent()) {
performanceLogger.log(operation(), durationMs(), metadata().get());
} else {
performanceLogger.log(operation(), durationMs());
}

View File

@@ -14,11 +14,7 @@
package com.google.gerrit.server.logging;
import com.google.common.collect.ImmutableMap;
import com.google.gerrit.common.Nullable;
import com.google.gerrit.extensions.annotations.ExtensionPoint;
import java.util.Map;
import java.util.Optional;
/**
* Extension point for logging performance records.
@@ -29,7 +25,7 @@ import java.util.Optional;
* performance log for further analysis.
*
* <p>For optimal performance implementors should overwrite the default <code>log</code> methods to
* avoid unneeded instantiation of Map objects.
* avoid an unneeded instantiation of Metadata.
*/
@ExtensionPoint
public interface PerformanceLogger {
@@ -40,7 +36,7 @@ public interface PerformanceLogger {
* @param durationMs time that the execution of the operation took (in milliseconds)
*/
default void log(String operation, long durationMs) {
log(operation, durationMs, ImmutableMap.of());
log(operation, durationMs, Metadata.empty());
}
/**
@@ -48,117 +44,7 @@ public interface PerformanceLogger {
*
* @param operation operation that was performed
* @param durationMs time that the execution of the operation took (in milliseconds)
* @param key meta data key
* @param value meta data value
* @param metadata metadata
*/
default void log(String operation, long durationMs, String key, @Nullable Object value) {
log(operation, durationMs, ImmutableMap.of(key, Optional.ofNullable(value)));
}
/**
* Record the execution time of an operation in a performance log.
*
* @param operation operation that was performed
* @param durationMs time that the execution of the operation took (in milliseconds)
* @param key1 first meta data key
* @param value1 first meta data value
* @param key2 second meta data key
* @param value2 second meta data value
*/
default void log(
String operation,
long durationMs,
String key1,
@Nullable Object value1,
String key2,
@Nullable Object value2) {
log(
operation,
durationMs,
ImmutableMap.of(key1, Optional.ofNullable(value1), key2, Optional.ofNullable(value2)));
}
/**
* Record the execution time of an operation in a performance log.
*
* @param operation operation that was performed
* @param durationMs time that the execution of the operation took (in milliseconds)
* @param key1 first meta data key
* @param value1 first meta data value
* @param key2 second meta data key
* @param value2 second meta data value
* @param key3 third meta data key
* @param value3 third meta data value
*/
default void log(
String operation,
long durationMs,
String key1,
@Nullable Object value1,
String key2,
@Nullable Object value2,
String key3,
@Nullable Object value3) {
log(
operation,
durationMs,
ImmutableMap.of(
key1,
Optional.ofNullable(value1),
key2,
Optional.ofNullable(value2),
key3,
Optional.ofNullable(value3)));
}
/**
* Record the execution time of an operation in a performance log.
*
* @param operation operation that was performed
* @param durationMs time that the execution of the operation took (in milliseconds)
* @param key1 first meta data key
* @param value1 first meta data value
* @param key2 second meta data key
* @param value2 second meta data value
* @param key3 third meta data key
* @param value3 third meta data value
* @param key4 fourth meta data key
* @param value4 fourth meta data value
*/
default void log(
String operation,
long durationMs,
String key1,
@Nullable Object value1,
String key2,
@Nullable Object value2,
String key3,
@Nullable Object value3,
String key4,
@Nullable Object value4) {
log(
operation,
durationMs,
ImmutableMap.of(
key1,
Optional.ofNullable(value1),
key2,
Optional.ofNullable(value2),
key3,
Optional.ofNullable(value3),
key4,
Optional.ofNullable(value4)));
}
/**
* Record the execution time of an operation in a performance log.
*
* <p>For small numbers of meta data entries the instantiation of a map should avoided by using
* one of the <code>log</code> methods that allows to pass in meta data entries directly.
*
* @param operation operation that was performed
* @param durationMs time that the execution of the operation took (in milliseconds)
* @param metaData key-value map with meta data
*/
void log(String operation, long durationMs, Map<String, Optional<Object>> metaData);
void log(String operation, long durationMs, Metadata metadata);
}

View File

@@ -0,0 +1,39 @@
// Copyright (C) 2019 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.logging;
import com.google.auto.value.AutoValue;
import com.google.gerrit.common.Nullable;
import java.util.Optional;
/**
* Key-value pair for custom metadata that is provided by plugins.
*
* <p>PluginMetadata allows plugins to include custom metadata into the {@link Metadata} instances
* that are provided as context for performance tracing.
*
* <p>Plugins should use PluginMetadata only for metadata kinds that are not known to Gerrit core
* (metadata for which {@link Metadata} doesn't have a dedicated field).
*/
@AutoValue
public abstract class PluginMetadata {
public static PluginMetadata create(String key, @Nullable String value) {
return new AutoValue_PluginMetadata(key, Optional.ofNullable(value));
}
public abstract String key();
public abstract Optional<String> value();
}

View File

@@ -166,105 +166,13 @@ public class TraceContext implements AutoCloseable {
* Opens a new timer that logs the time for an operation if request tracing is enabled.
*
* @param operation the name of operation the is being performed
* @param key meta data key
* @param value meta data value
* @param metadata metadata
* @return the trace timer
*/
public static TraceTimer newTimer(String operation, String key, @Nullable Object value) {
public static TraceTimer newTimer(String operation, Metadata metadata) {
return new TraceTimer(
requireNonNull(operation, "operation is required"),
requireNonNull(key, "key is required"),
value);
}
/**
* Opens a new timer that logs the time for an operation if request tracing is enabled.
*
* @param operation the name of operation the is being performed
* @param key1 first meta data key
* @param value1 first meta data value
* @param key2 second meta data key
* @param value2 second meta data value
* @return the trace timer
*/
public static TraceTimer newTimer(
String operation,
String key1,
@Nullable Object value1,
String key2,
@Nullable Object value2) {
return new TraceTimer(
requireNonNull(operation, "operation is required"),
requireNonNull(key1, "key1 is required"),
value1,
requireNonNull(key2, "key2 is required"),
value2);
}
/**
* Opens a new timer that logs the time for an operation if request tracing is enabled.
*
* @param operation the name of operation the is being performed
* @param key1 first meta data key
* @param value1 first meta data value
* @param key2 second meta data key
* @param value2 second meta data value
* @param key3 third meta data key
* @param value3 third meta data value
* @return the trace timer
*/
public static TraceTimer newTimer(
String operation,
String key1,
@Nullable Object value1,
String key2,
@Nullable Object value2,
String key3,
@Nullable Object value3) {
return new TraceTimer(
requireNonNull(operation, "operation is required"),
requireNonNull(key1, "key1 is required"),
value1,
requireNonNull(key2, "key2 is required"),
value2,
requireNonNull(key3, "key3 is required"),
value3);
}
/**
* Opens a new timer that logs the time for an operation if request tracing is enabled.
*
* @param operation the name of operation the is being performed
* @param key1 first meta data key
* @param value1 first meta data value
* @param key2 second meta data key
* @param value2 second meta data value
* @param key3 third meta data key
* @param value3 third meta data value
* @param key4 fourth meta data key
* @param value4 fourth meta data value
* @return the trace timer
*/
public static TraceTimer newTimer(
String operation,
String key1,
@Nullable Object value1,
String key2,
@Nullable Object value2,
String key3,
@Nullable Object value3,
String key4,
@Nullable Object value4) {
return new TraceTimer(
requireNonNull(operation, "operation is required"),
requireNonNull(key1, "key1 is required"),
value1,
requireNonNull(key2, "key2 is required"),
value2,
requireNonNull(key3, "key3 is required"),
value3,
requireNonNull(key4, "key4 is required"),
value4);
requireNonNull(metadata, "metadata is required"));
}
public static class TraceTimer implements AutoCloseable {
@@ -282,76 +190,13 @@ public class TraceContext implements AutoCloseable {
});
}
private TraceTimer(String operation, String key, @Nullable Object value) {
private TraceTimer(String operation, Metadata metadata) {
this(
elapsedMs -> {
LoggingContext.getInstance()
.addPerformanceLogRecord(
() -> PerformanceLogRecord.create(operation, elapsedMs, key, value));
logger.atFine().log("%s (%s=%s) (%d ms)", operation, key, value, elapsedMs);
});
}
private TraceTimer(
String operation,
String key1,
@Nullable Object value1,
String key2,
@Nullable Object value2) {
this(
elapsedMs -> {
LoggingContext.getInstance()
.addPerformanceLogRecord(
() ->
PerformanceLogRecord.create(
operation, elapsedMs, key1, value1, key2, value2));
logger.atFine().log(
"%s (%s=%s, %s=%s) (%d ms)", operation, key1, value1, key2, value2, elapsedMs);
});
}
private TraceTimer(
String operation,
String key1,
@Nullable Object value1,
String key2,
@Nullable Object value2,
String key3,
@Nullable Object value3) {
this(
elapsedMs -> {
LoggingContext.getInstance()
.addPerformanceLogRecord(
() ->
PerformanceLogRecord.create(
operation, elapsedMs, key1, value1, key2, value2, key3, value3));
logger.atFine().log(
"%s (%s=%s, %s=%s, %s=%s) (%d ms)",
operation, key1, value1, key2, value2, key3, value3, elapsedMs);
});
}
private TraceTimer(
String operation,
String key1,
@Nullable Object value1,
String key2,
@Nullable Object value2,
String key3,
@Nullable Object value3,
String key4,
@Nullable Object value4) {
this(
elapsedMs -> {
LoggingContext.getInstance()
.addPerformanceLogRecord(
() ->
PerformanceLogRecord.create(
operation, elapsedMs, key1, value1, key2, value2, key3, value3, key4,
value4));
logger.atFine().log(
"%s (%s=%s, %s=%s, %s=%s, %s=%s) (%d ms)",
operation, key1, value1, key2, value2, key3, value3, key4, value4, elapsedMs);
() -> PerformanceLogRecord.create(operation, elapsedMs, metadata));
logger.atFine().log("%s (%s) (%d ms)", operation, metadata, elapsedMs);
});
}

View File

@@ -19,6 +19,7 @@ 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.gerrit.server.logging.Metadata;
import com.google.inject.Inject;
import com.google.inject.Singleton;
@@ -45,7 +46,8 @@ class NoteDbMetrics {
@Inject
NoteDbMetrics(MetricMaker metrics) {
Field<NoteDbTable> tableField = Field.ofEnum(NoteDbTable.class, "table").build();
Field<NoteDbTable> tableField =
Field.ofEnum(NoteDbTable.class, "table", Metadata.Builder::noteDbTable).build();
updateLatency =
metrics.newTimer(

View File

@@ -25,6 +25,7 @@ import com.google.gerrit.server.config.AllUsersName;
import com.google.gerrit.server.config.GerritServerConfig;
import com.google.gerrit.server.extensions.events.GitReferenceUpdated;
import com.google.gerrit.server.git.GitRepositoryManager;
import com.google.gerrit.server.logging.Metadata;
import com.google.inject.Inject;
import com.google.inject.Singleton;
import org.eclipse.jgit.lib.Config;
@@ -95,8 +96,9 @@ public class Sequences {
new Description("Latency of requesting IDs from repo sequences")
.setCumulative()
.setUnit(Units.MILLISECONDS),
Field.ofEnum(SequenceType.class, "sequence").build(),
Field.ofBoolean("multiple").build());
Field.ofEnum(SequenceType.class, "sequence", Metadata.Builder::noteDbSequenceType)
.build(),
Field.ofBoolean("multiple", Metadata.Builder::multiple).build());
}
public int nextAccountId() {

View File

@@ -30,6 +30,7 @@ import com.google.gerrit.metrics.DisabledMetricMaker;
import com.google.gerrit.metrics.Field;
import com.google.gerrit.metrics.MetricMaker;
import com.google.gerrit.metrics.Timer3;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.inject.Inject;
import com.google.inject.Singleton;
@@ -118,9 +119,12 @@ public class PluginContext<T> {
@Inject
PluginMetrics(MetricMaker metricMaker) {
Field<String> pluginNameField = Field.ofString("plugin_name").build();
Field<String> classNameField = Field.ofString("class_name").build();
Field<String> exportNameField = Field.ofString("export_name").build();
Field<String> pluginNameField =
Field.ofString("plugin_name", Metadata.Builder::pluginName).build();
Field<String> classNameField =
Field.ofString("class_name", Metadata.Builder::className).build();
Field<String> exportValueField =
Field.ofString("export_value", Metadata.Builder::exportValue).build();
this.latency =
metricMaker.newTimer(
@@ -130,14 +134,14 @@ public class PluginContext<T> {
.setUnit(Units.MILLISECONDS),
pluginNameField,
classNameField,
exportNameField);
exportValueField);
this.errorCount =
metricMaker.newCounter(
"plugin/error_count",
new Description("Number of plugin errors").setCumulative().setUnit("errors"),
pluginNameField,
classNameField,
exportNameField);
exportValueField);
}
Timer3.Context<String, String, String> startLatency(Extension<?> extension) {

View File

@@ -36,6 +36,7 @@ import com.google.gerrit.server.cache.CacheModule;
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.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.inject.Inject;
@@ -294,7 +295,8 @@ public class ProjectCacheImpl implements ProjectCache {
@Override
public ProjectState load(String projectName) throws Exception {
try (TraceTimer timer =
TraceContext.newTimer("Loading project", "projectName", projectName)) {
TraceContext.newTimer(
"Loading project", Metadata.builder().projectName(projectName).build())) {
long now = clock.read();
Project.NameKey key = Project.nameKey(projectName);
try (Repository git = mgr.openRepository(key)) {

View File

@@ -48,6 +48,7 @@ import com.google.gerrit.server.config.AllUsersName;
import com.google.gerrit.server.git.BranchOrderSection;
import com.google.gerrit.server.git.GitRepositoryManager;
import com.google.gerrit.server.git.TransferConfig;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.notedb.ChangeNotes;
import com.google.inject.Inject;
import com.google.inject.assistedinject.Assisted;
@@ -135,7 +136,7 @@ public class ProjectState {
new Description("Latency for access computations in ProjectState")
.setCumulative()
.setUnit(Units.NANOSECONDS),
Field.ofString("method").build());
Field.ofString("method", Metadata.Builder::methodName).build());
if (isAllProjects && !Permission.canBeOnAllProjects(AccessSection.ALL, Permission.OWNER)) {
localOwners = Collections.emptySet();

View File

@@ -39,6 +39,7 @@ import com.google.gerrit.metrics.Description;
import com.google.gerrit.metrics.Field;
import com.google.gerrit.metrics.MetricMaker;
import com.google.gerrit.server.config.GerritServerConfig;
import com.google.gerrit.server.logging.Metadata;
import com.google.inject.Inject;
import com.google.inject.Singleton;
import java.time.Duration;
@@ -111,7 +112,8 @@ public class RetryHelper {
@Inject
Metrics(MetricMaker metricMaker) {
Field<ActionType> actionTypeField = Field.ofEnum(ActionType.class, "action_type").build();
Field<ActionType> actionTypeField =
Field.ofEnum(ActionType.class, "action_type", Metadata.Builder::actionType).build();
attemptCounts =
metricMaker.newCounter(
"action/retry_attempt_count",

View File

@@ -24,6 +24,7 @@ import com.google.gerrit.server.account.VersionedAuthorizedKeys;
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.Metadata;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.logging.TraceContext.TraceTimer;
import com.google.gerrit.server.ssh.SshKeyCache;
@@ -107,7 +108,8 @@ public class SshKeyCacheImpl implements SshKeyCache {
public Iterable<SshKeyCacheEntry> load(String username) throws Exception {
try (TraceTimer timer =
TraceContext.newTimer(
"Loading SSH keys for account with username", "username", username)) {
"Loading SSH keys for account with username",
Metadata.builder().username(username).build())) {
Optional<ExternalId> user =
externalIds.get(ExternalId.Key.create(SCHEME_USERNAME, username));
if (!user.isPresent()) {

View File

@@ -19,7 +19,6 @@ import static org.apache.http.HttpStatus.SC_CREATED;
import com.google.auto.value.AutoValue;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.ImmutableMap;
import com.google.common.collect.ImmutableSet;
import com.google.common.collect.Iterables;
import com.google.common.truth.Expect;
@@ -37,6 +36,7 @@ import com.google.gerrit.server.git.validators.CommitValidationException;
import com.google.gerrit.server.git.validators.CommitValidationListener;
import com.google.gerrit.server.git.validators.CommitValidationMessage;
import com.google.gerrit.server.logging.LoggingContext;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.logging.PerformanceLogger;
import com.google.gerrit.server.logging.TraceContext;
import com.google.gerrit.server.project.CreateProjectArgs;
@@ -45,8 +45,6 @@ import com.google.gerrit.server.validators.ValidationException;
import com.google.inject.Inject;
import java.util.ArrayList;
import java.util.List;
import java.util.Map;
import java.util.Optional;
import java.util.SortedMap;
import java.util.SortedSet;
import org.apache.http.message.BasicHeader;
@@ -346,8 +344,8 @@ public class TraceIT extends AbstractDaemonTest {
private List<PerformanceLogEntry> logEntries = new ArrayList<>();
@Override
public void log(String operation, long durationMs, Map<String, Optional<Object>> metaData) {
logEntries.add(PerformanceLogEntry.create(operation, metaData));
public void log(String operation, long durationMs, Metadata metadata) {
logEntries.add(PerformanceLogEntry.create(operation, metadata));
}
ImmutableList<PerformanceLogEntry> logEntries() {
@@ -357,12 +355,12 @@ public class TraceIT extends AbstractDaemonTest {
@AutoValue
abstract static class PerformanceLogEntry {
static PerformanceLogEntry create(String operation, Map<String, Optional<Object>> metaData) {
return new AutoValue_TraceIT_PerformanceLogEntry(operation, ImmutableMap.copyOf(metaData));
static PerformanceLogEntry create(String operation, Metadata metadata) {
return new AutoValue_TraceIT_PerformanceLogEntry(operation, metadata);
}
abstract String operation();
abstract ImmutableMap<String, Object> metaData();
abstract Metadata metadata();
}
}

View File

@@ -18,13 +18,13 @@ import static com.google.common.truth.Truth.assertThat;
import com.google.auto.value.AutoValue;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.ImmutableMap;
import com.google.common.collect.Iterables;
import com.google.gerrit.acceptance.AbstractDaemonTest;
import com.google.gerrit.acceptance.UseSsh;
import com.google.gerrit.extensions.registration.DynamicSet;
import com.google.gerrit.extensions.registration.RegistrationHandle;
import com.google.gerrit.server.logging.LoggingContext;
import com.google.gerrit.server.logging.Metadata;
import com.google.gerrit.server.logging.PerformanceLogger;
import com.google.gerrit.server.logging.RequestId;
import com.google.gerrit.server.project.CreateProjectArgs;
@@ -33,8 +33,6 @@ import com.google.gerrit.server.validators.ValidationException;
import com.google.inject.Inject;
import java.util.ArrayList;
import java.util.List;
import java.util.Map;
import java.util.Optional;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
@@ -129,8 +127,8 @@ public class SshTraceIT extends AbstractDaemonTest {
private List<PerformanceLogEntry> logEntries = new ArrayList<>();
@Override
public void log(String operation, long durationMs, Map<String, Optional<Object>> metaData) {
logEntries.add(PerformanceLogEntry.create(operation, metaData));
public void log(String operation, long durationMs, Metadata metadata) {
logEntries.add(PerformanceLogEntry.create(operation, metadata));
}
ImmutableList<PerformanceLogEntry> logEntries() {
@@ -140,12 +138,12 @@ public class SshTraceIT extends AbstractDaemonTest {
@AutoValue
abstract static class PerformanceLogEntry {
static PerformanceLogEntry create(String operation, Map<String, Optional<Object>> metaData) {
return new AutoValue_SshTraceIT_PerformanceLogEntry(operation, ImmutableMap.copyOf(metaData));
static PerformanceLogEntry create(String operation, Metadata metadata) {
return new AutoValue_SshTraceIT_PerformanceLogEntry(operation, metadata);
}
abstract String operation();
abstract ImmutableMap<String, Object> metaData();
abstract Metadata metadata();
}
}

View File

@@ -82,7 +82,7 @@ public class ProcMetricModuleTest {
metrics.newCounter(
"test/count",
new Description("simple test").setCumulative(),
Field.ofString("action").build());
Field.ofString("action", Field.ignoreMetadata()).build());
Counter total = get("test/count_total", Counter.class);
assertThat(total.getCount()).isEqualTo(0);
@@ -107,7 +107,7 @@ public class ProcMetricModuleTest {
new Description("simple test")
.setCumulative()
.setFieldOrdering(FieldOrdering.PREFIX_FIELDS_BASENAME),
Field.ofString("action").build());
Field.ofString("action", Field.ignoreMetadata()).build());
Counter total = get("test/count_total", Counter.class);
assertThat(total.getCount()).isEqualTo(0);

View File

@@ -24,8 +24,6 @@ import com.google.gerrit.testing.InMemoryModule;
import com.google.inject.Guice;
import com.google.inject.Inject;
import com.google.inject.Injector;
import java.util.Map;
import java.util.Optional;
import java.util.SortedMap;
import java.util.SortedSet;
import java.util.concurrent.ExecutorService;
@@ -53,8 +51,7 @@ public class LoggingContextAwareExecutorServiceTest {
testPerformanceLogger =
new PerformanceLogger() {
@Override
public void log(
String operation, long durationMs, Map<String, Optional<Object>> metaData) {
public void log(String operation, long durationMs, Metadata metadata) {
// do nothing
}
};

View File

@@ -18,7 +18,6 @@ import static com.google.common.truth.Truth.assertThat;
import com.google.auto.value.AutoValue;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.ImmutableMap;
import com.google.gerrit.extensions.registration.DynamicSet;
import com.google.gerrit.extensions.registration.RegistrationHandle;
import com.google.gerrit.metrics.Description;
@@ -35,8 +34,6 @@ import com.google.inject.Inject;
import com.google.inject.Injector;
import java.util.ArrayList;
import java.util.List;
import java.util.Map;
import java.util.Optional;
import org.eclipse.jgit.lib.Config;
import org.junit.After;
import org.junit.Before;
@@ -80,87 +77,17 @@ public class PerformanceLogContextTest {
assertThat(LoggingContext.getInstance().isPerformanceLogging()).isTrue();
TraceContext.newTimer("test1").close();
TraceContext.newTimer("test2", "foo", "bar").close();
TraceContext.newTimer("test3", "foo1", "bar1", "foo2", "bar2").close();
TraceContext.newTimer("test4", "foo1", "bar1", "foo2", "bar2", "foo3", "bar3").close();
TraceContext.newTimer("test5", "foo1", "bar1", "foo2", "bar2", "foo3", "bar3", "foo4", "bar4")
TraceContext.newTimer("test2", Metadata.builder().accountId(1000000).changeId(123).build())
.close();
assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).hasSize(5);
assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).hasSize(2);
}
assertThat(testPerformanceLogger.logEntries())
.containsExactly(
PerformanceLogEntry.create("test1", ImmutableMap.of()),
PerformanceLogEntry.create("test2", ImmutableMap.of("foo", Optional.of("bar"))),
PerformanceLogEntry.create("test1", Metadata.empty()),
PerformanceLogEntry.create(
"test3", ImmutableMap.of("foo1", Optional.of("bar1"), "foo2", Optional.of("bar2"))),
PerformanceLogEntry.create(
"test4",
ImmutableMap.of(
"foo1",
Optional.of("bar1"),
"foo2",
Optional.of("bar2"),
"foo3",
Optional.of("bar3"))),
PerformanceLogEntry.create(
"test5",
ImmutableMap.of(
"foo1",
Optional.of("bar1"),
"foo2",
Optional.of("bar2"),
"foo3",
Optional.of("bar3"),
"foo4",
Optional.of("bar4"))))
.inOrder();
assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
}
@Test
public void traceTimersInsidePerformanceLogContextCreatePerformanceLogNullValuesAllowed() {
assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
try (PerformanceLogContext traceContext =
new PerformanceLogContext(config, performanceLoggers)) {
assertThat(LoggingContext.getInstance().isPerformanceLogging()).isTrue();
TraceContext.newTimer("test1").close();
TraceContext.newTimer("test2", "foo", null).close();
TraceContext.newTimer("test3", "foo1", null, "foo2", null).close();
TraceContext.newTimer("test4", "foo1", null, "foo2", null, "foo3", null).close();
TraceContext.newTimer("test5", "foo1", null, "foo2", null, "foo3", null, "foo4", null)
.close();
assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).hasSize(5);
}
assertThat(testPerformanceLogger.logEntries())
.containsExactly(
PerformanceLogEntry.create("test1", ImmutableMap.of()),
PerformanceLogEntry.create("test2", ImmutableMap.of("foo", Optional.empty())),
PerformanceLogEntry.create(
"test3", ImmutableMap.of("foo1", Optional.empty(), "foo2", Optional.empty())),
PerformanceLogEntry.create(
"test4",
ImmutableMap.of(
"foo1", Optional.empty(), "foo2", Optional.empty(), "foo3", Optional.empty())),
PerformanceLogEntry.create(
"test5",
ImmutableMap.of(
"foo1",
Optional.empty(),
"foo2",
Optional.empty(),
"foo3",
Optional.empty(),
"foo4",
Optional.empty())))
"test2", Metadata.builder().accountId(1000000).changeId(123).build()))
.inOrder();
assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
@@ -173,10 +100,7 @@ public class PerformanceLogContextTest {
assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
TraceContext.newTimer("test1").close();
TraceContext.newTimer("test2", "foo", "bar").close();
TraceContext.newTimer("test3", "foo1", "bar1", "foo2", "bar2").close();
TraceContext.newTimer("test4", "foo1", "bar1", "foo2", "bar2", "foo3", "bar3").close();
TraceContext.newTimer("test5", "foo1", "bar1", "foo2", "bar2", "foo3", "bar3", "foo4", "bar4")
TraceContext.newTimer("test2", Metadata.builder().accountId(1000000).changeId(123).build())
.close();
assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
@@ -198,10 +122,7 @@ public class PerformanceLogContextTest {
assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
TraceContext.newTimer("test1").close();
TraceContext.newTimer("test2", "foo", "bar").close();
TraceContext.newTimer("test3", "foo1", "bar1", "foo2", "bar2").close();
TraceContext.newTimer("test4", "foo1", "bar1", "foo2", "bar2", "foo3", "bar3").close();
TraceContext.newTimer("test5", "foo1", "bar1", "foo2", "bar2", "foo3", "bar3", "foo4", "bar4")
TraceContext.newTimer("test2", Metadata.builder().accountId(1000000).changeId(123).build())
.close();
assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
@@ -226,50 +147,43 @@ public class PerformanceLogContextTest {
metricMaker.newTimer("test1/latency", new Description("Latency metric for testing"));
timer0.start().close();
Timer1<String> timer1 =
Timer1<Integer> timer1 =
metricMaker.newTimer(
"test2/latency",
new Description("Latency metric for testing"),
Field.ofString("foo").build());
timer1.start("value1").close();
Field.ofInteger("account", Metadata.Builder::accountId).build());
timer1.start(1000000).close();
Timer2<String, String> timer2 =
Timer2<Integer, Integer> timer2 =
metricMaker.newTimer(
"test3/latency",
new Description("Latency metric for testing"),
Field.ofString("foo").build(),
Field.ofString("bar").build());
timer2.start("value1", "value2").close();
Field.ofInteger("account", Metadata.Builder::accountId).build(),
Field.ofInteger("change", Metadata.Builder::changeId).build());
timer2.start(1000000, 123).close();
Timer3<String, String, String> timer3 =
Timer3<Integer, Integer, String> timer3 =
metricMaker.newTimer(
"test4/latency",
new Description("Latency metric for testing"),
Field.ofString("foo").build(),
Field.ofString("bar").build(),
Field.ofString("baz").build());
timer3.start("value1", "value2", "value3").close();
Field.ofInteger("account", Metadata.Builder::accountId).build(),
Field.ofInteger("change", Metadata.Builder::changeId).build(),
Field.ofString("project", Metadata.Builder::projectName).build());
timer3.start(1000000, 123, "foo/bar").close();
assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).hasSize(4);
}
assertThat(testPerformanceLogger.logEntries())
.containsExactly(
PerformanceLogEntry.create("test1/latency", ImmutableMap.of()),
PerformanceLogEntry.create("test1/latency", Metadata.empty()),
PerformanceLogEntry.create(
"test2/latency", ImmutableMap.of("foo", Optional.of("value1"))),
"test2/latency", Metadata.builder().accountId(1000000).build()),
PerformanceLogEntry.create(
"test3/latency",
ImmutableMap.of("foo", Optional.of("value1"), "bar", Optional.of("value2"))),
"test3/latency", Metadata.builder().accountId(1000000).changeId(123).build()),
PerformanceLogEntry.create(
"test4/latency",
ImmutableMap.of(
"foo",
Optional.of("value1"),
"bar",
Optional.of("value2"),
"baz",
Optional.of("value3"))))
Metadata.builder().accountId(1000000).changeId(123).projectName("foo/bar").build()))
.inOrder();
assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
@@ -289,24 +203,24 @@ public class PerformanceLogContextTest {
metricMaker.newTimer(
"test1/latency",
new Description("Latency metric for testing"),
Field.ofString("foo").build());
Field.ofString("project", Metadata.Builder::projectName).build());
timer1.start(null).close();
Timer2<String, String> timer2 =
metricMaker.newTimer(
"test2/latency",
new Description("Latency metric for testing"),
Field.ofString("foo").build(),
Field.ofString("bar").build());
Field.ofString("project", Metadata.Builder::projectName).build(),
Field.ofString("branch", Metadata.Builder::branchName).build());
timer2.start(null, null).close();
Timer3<String, String, String> timer3 =
metricMaker.newTimer(
"test3/latency",
new Description("Latency metric for testing"),
Field.ofString("foo").build(),
Field.ofString("bar").build(),
Field.ofString("baz").build());
Field.ofString("project", Metadata.Builder::projectName).build(),
Field.ofString("branch", Metadata.Builder::branchName).build(),
Field.ofString("revision", Metadata.Builder::revision).build());
timer3.start(null, null, null).close();
assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).hasSize(3);
@@ -314,13 +228,9 @@ public class PerformanceLogContextTest {
assertThat(testPerformanceLogger.logEntries())
.containsExactly(
PerformanceLogEntry.create("test1/latency", ImmutableMap.of("foo", Optional.empty())),
PerformanceLogEntry.create(
"test2/latency", ImmutableMap.of("foo", Optional.empty(), "bar", Optional.empty())),
PerformanceLogEntry.create(
"test3/latency",
ImmutableMap.of(
"foo", Optional.empty(), "bar", Optional.empty(), "baz", Optional.empty())))
PerformanceLogEntry.create("test1/latency", Metadata.empty()),
PerformanceLogEntry.create("test2/latency", Metadata.empty()),
PerformanceLogEntry.create("test3/latency", Metadata.empty()))
.inOrder();
assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
@@ -336,29 +246,29 @@ public class PerformanceLogContextTest {
metricMaker.newTimer("test1/latency", new Description("Latency metric for testing"));
timer0.start().close();
Timer1<String> timer1 =
Timer1<Integer> timer1 =
metricMaker.newTimer(
"test2/latency",
new Description("Latency metric for testing"),
Field.ofString("foo").build());
timer1.start("value1").close();
Field.ofInteger("account", Metadata.Builder::accountId).build());
timer1.start(1000000).close();
Timer2<String, String> timer2 =
Timer2<Integer, Integer> timer2 =
metricMaker.newTimer(
"test3/latency",
new Description("Latency metric for testing"),
Field.ofString("foo").build(),
Field.ofString("bar").build());
timer2.start("value1", "value2").close();
Field.ofInteger("account", Metadata.Builder::accountId).build(),
Field.ofInteger("change", Metadata.Builder::changeId).build());
timer2.start(1000000, 123).close();
Timer3<String, String, String> timer3 =
Timer3<Integer, Integer, String> timer3 =
metricMaker.newTimer(
"test4/latency",
new Description("Latency metric for testing"),
Field.ofString("foo").build(),
Field.ofString("bar").build(),
Field.ofString("baz").build());
timer3.start("value1", "value2", "value3").close();
Field.ofInteger("account", Metadata.Builder::accountId).build(),
Field.ofInteger("change", Metadata.Builder::changeId).build(),
Field.ofString("project", Metadata.Builder::projectName).build());
timer3.start(1000000, 123, "value3").close();
assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
@@ -382,29 +292,29 @@ public class PerformanceLogContextTest {
metricMaker.newTimer("test1/latency", new Description("Latency metric for testing"));
timer0.start().close();
Timer1<String> timer1 =
Timer1<Integer> timer1 =
metricMaker.newTimer(
"test2/latency",
new Description("Latency metric for testing"),
Field.ofString("foo").build());
timer1.start("value1").close();
Field.ofInteger("accoutn", Metadata.Builder::accountId).build());
timer1.start(1000000).close();
Timer2<String, String> timer2 =
Timer2<Integer, Integer> timer2 =
metricMaker.newTimer(
"test3/latency",
new Description("Latency metric for testing"),
Field.ofString("foo").build(),
Field.ofString("bar").build());
timer2.start("value1", "value2").close();
Field.ofInteger("account", Metadata.Builder::accountId).build(),
Field.ofInteger("change", Metadata.Builder::changeId).build());
timer2.start(1000000, 123).close();
Timer3<String, String, String> timer3 =
Timer3<Integer, Integer, String> timer3 =
metricMaker.newTimer(
"test4/latency",
new Description("Latency metric for testing"),
Field.ofString("foo").build(),
Field.ofString("bar").build(),
Field.ofString("baz").build());
timer3.start("value1", "value2", "value3").close();
Field.ofInteger("account", Metadata.Builder::accountId).build(),
Field.ofInteger("change", Metadata.Builder::changeId).build(),
Field.ofString("project", Metadata.Builder::projectName).build());
timer3.start(1000000, 123, "foo/bar").close();
assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
}
@@ -450,8 +360,8 @@ public class PerformanceLogContextTest {
private List<PerformanceLogEntry> logEntries = new ArrayList<>();
@Override
public void log(String operation, long durationMs, Map<String, Optional<Object>> metaData) {
logEntries.add(PerformanceLogEntry.create(operation, metaData));
public void log(String operation, long durationMs, Metadata metadata) {
logEntries.add(PerformanceLogEntry.create(operation, metadata));
}
ImmutableList<PerformanceLogEntry> logEntries() {
@@ -461,13 +371,12 @@ public class PerformanceLogContextTest {
@AutoValue
abstract static class PerformanceLogEntry {
static PerformanceLogEntry create(String operation, Map<String, Optional<Object>> metaData) {
return new AutoValue_PerformanceLogContextTest_PerformanceLogEntry(
operation, ImmutableMap.copyOf(metaData));
static PerformanceLogEntry create(String operation, Metadata metadata) {
return new AutoValue_PerformanceLogContextTest_PerformanceLogEntry(operation, metadata);
}
abstract String operation();
abstract ImmutableMap<String, Object> metaData();
abstract Metadata metadata();
}
}

View File

@@ -240,58 +240,17 @@ public class TraceContextTest {
@Test
public void operationForTraceTimerCannotBeNull() throws Exception {
assertThrows(NullPointerException.class, () -> TraceContext.newTimer(null));
assertThrows(NullPointerException.class, () -> TraceContext.newTimer(null, "foo", "bar"));
assertThrows(
NullPointerException.class,
() -> TraceContext.newTimer(null, "foo1", "bar1", "foo2", "bar2"));
assertThrows(
NullPointerException.class,
() -> TraceContext.newTimer(null, "foo1", "bar1", "foo2", "bar2", "foo3", "bar3"));
assertThrows(NullPointerException.class, () -> TraceContext.newTimer(null, Metadata.empty()));
assertThrows(
NullPointerException.class,
() ->
TraceContext.newTimer(
null, "foo1", "bar1", "foo2", "bar2", "foo3", "bar3", "foo4", "bar4"));
null, Metadata.builder().accountId(1000000).changeId(123).build()));
}
@Test
public void keysForTraceTimerCannotBeNull() throws Exception {
assertThrows(NullPointerException.class, () -> TraceContext.newTimer("test", null, "bar"));
assertThrows(
NullPointerException.class,
() -> TraceContext.newTimer("test", null, "bar1", "foo2", "bar2"));
assertThrows(
NullPointerException.class,
() -> TraceContext.newTimer("test", "foo1", "bar1", null, "bar2"));
assertThrows(
NullPointerException.class,
() -> TraceContext.newTimer("test", null, "bar1", "foo2", "bar2", "foo3", "bar3"));
assertThrows(
NullPointerException.class,
() -> TraceContext.newTimer("test", "foo1", "bar1", null, "bar2", "foo3", "bar3"));
assertThrows(
NullPointerException.class,
() -> TraceContext.newTimer("test", "foo1", "bar1", "foo2", "bar2", null, "bar3"));
assertThrows(
NullPointerException.class,
() ->
TraceContext.newTimer(
"test", null, "bar1", "foo2", "bar2", "foo3", "bar3", "foo4", "bar4"));
assertThrows(
NullPointerException.class,
() ->
TraceContext.newTimer(
"test", "foo1", "bar1", null, "bar2", "foo3", "bar3", "foo4", "bar4"));
assertThrows(
NullPointerException.class,
() ->
TraceContext.newTimer(
"test", "foo1", "bar1", "foo2", "bar2", null, "bar3", "foo4", "bar4"));
assertThrows(
NullPointerException.class,
() ->
TraceContext.newTimer(
"test", "foo1", "bar1", "foo2", "bar2", "foo3", "bar3", null, "bar4"));
public void metadataForTraceTimerCannotBeNull() throws Exception {
assertThrows(NullPointerException.class, () -> TraceContext.newTimer("test", null));
}
private void assertTags(ImmutableMap<String, ImmutableSet<String>> expectedTagMap) {