Merge changes I1ca1ea03,Ifea7604c

* changes:
  ChangeJson: Write performance log for retrieving change data from plugins
  Provide the end time for operations to PerformanceLogger

java/com/google/gerrit/server/change/ChangeJson.java

diff --git a/java/com/google/gerrit/server/change/ChangeJson.java b/java/com/google/gerrit/server/change/ChangeJson.java
index d0f5d6b..d30e91a 100644
--- a/java/com/google/gerrit/server/change/ChangeJson.java
+++ b/java/com/google/gerrit/server/change/ChangeJson.java
@@ -1091,7 +1091,11 @@
   private ImmutableListMultimap<Change.Id, PluginDefinedInfo> getPluginInfos(
       Collection<ChangeData> cds) {
     if (pluginDefinedInfosFactory.isPresent()) {
-      return pluginDefinedInfosFactory.get().createPluginDefinedInfos(cds);
+      try (TraceTimer timer =
+          TraceContext.newTimer(
+              "Get plugin infos", Metadata.builder().resourceCount(cds.size()).build())) {
+        return pluginDefinedInfosFactory.get().createPluginDefinedInfos(cds);
+      }
     }
     return ImmutableListMultimap.of();
   }

java/com/google/gerrit/server/logging/PerformanceLogRecord.java

diff --git a/java/com/google/gerrit/server/logging/PerformanceLogRecord.java b/java/com/google/gerrit/server/logging/PerformanceLogRecord.java
index 046eeb3..07d9b90 100644
--- a/java/com/google/gerrit/server/logging/PerformanceLogRecord.java
+++ b/java/com/google/gerrit/server/logging/PerformanceLogRecord.java
@@ -15,6 +15,7 @@
 package com.google.gerrit.server.logging;
 
 import com.google.auto.value.AutoValue;
+import java.time.Instant;
 import java.util.Optional;
 
 /**
@@ -33,7 +34,8 @@
    * @return the performance log record
    */
   public static PerformanceLogRecord create(String operation, long durationMs) {
-    return new AutoValue_PerformanceLogRecord(operation, durationMs, Optional.empty());
+    return new AutoValue_PerformanceLogRecord(
+        operation, durationMs, Instant.now(), Optional.empty());
   }
 
   /**
@@ -45,20 +47,23 @@
    * @return the performance log record
    */
   public static PerformanceLogRecord create(String operation, long durationMs, Metadata metadata) {
-    return new AutoValue_PerformanceLogRecord(operation, durationMs, Optional.of(metadata));
+    return new AutoValue_PerformanceLogRecord(
+        operation, durationMs, Instant.now(), Optional.of(metadata));
   }
 
   public abstract String operation();
 
   public abstract long durationMs();
 
+  public abstract Instant endTime();
+
   public abstract Optional<Metadata> metadata();
 
   void writeTo(PerformanceLogger performanceLogger) {
     if (metadata().isPresent()) {
-      performanceLogger.log(operation(), durationMs(), metadata().get());
+      performanceLogger.log(operation(), durationMs(), endTime(), metadata().get());
     } else {
-      performanceLogger.log(operation(), durationMs());
+      performanceLogger.log(operation(), durationMs(), endTime());
     }
   }
 }

java/com/google/gerrit/server/logging/PerformanceLogger.java

diff --git a/java/com/google/gerrit/server/logging/PerformanceLogger.java b/java/com/google/gerrit/server/logging/PerformanceLogger.java
index 74a1684..bed53ba 100644
--- a/java/com/google/gerrit/server/logging/PerformanceLogger.java
+++ b/java/com/google/gerrit/server/logging/PerformanceLogger.java
@@ -15,6 +15,7 @@
 package com.google.gerrit.server.logging;
 
 import com.google.gerrit.extensions.annotations.ExtensionPoint;
+import java.time.Instant;
 
 /**
  * Extension point for logging performance records.
@@ -35,8 +36,8 @@
    * @param operation operation that was performed
    * @param durationMs time that the execution of the operation took (in milliseconds)
    */
-  default void log(String operation, long durationMs) {
-    log(operation, durationMs, Metadata.empty());
+  default void log(String operation, long durationMs, Instant endTime) {
+    log(operation, durationMs, endTime, Metadata.empty());
   }
 
   /**
@@ -46,5 +47,5 @@
    * @param durationMs time that the execution of the operation took (in milliseconds)
    * @param metadata metadata
    */
-  void log(String operation, long durationMs, Metadata metadata);
+  void log(String operation, long durationMs, Instant endTime, Metadata metadata);
 }

javatests/com/google/gerrit/acceptance/ssh/SshTraceIT.java

diff --git a/javatests/com/google/gerrit/acceptance/ssh/SshTraceIT.java b/javatests/com/google/gerrit/acceptance/ssh/SshTraceIT.java
index 84c3936..c4497dc 100644
--- a/javatests/com/google/gerrit/acceptance/ssh/SshTraceIT.java
+++ b/javatests/com/google/gerrit/acceptance/ssh/SshTraceIT.java
@@ -32,6 +32,7 @@
 import com.google.gerrit.server.validators.ProjectCreationValidationListener;
 import com.google.gerrit.server.validators.ValidationException;
 import com.google.inject.Inject;
+import java.time.Instant;
 import org.junit.Test;
 
 @UseSsh
@@ -123,8 +124,8 @@
     private ImmutableList.Builder<PerformanceLogEntry> logEntries = ImmutableList.builder();
 
     @Override
-    public void log(String operation, long durationMs, Metadata metadata) {
-      logEntries.add(PerformanceLogEntry.create(operation, metadata));
+    public void log(String operation, long durationMs, Instant endTime, Metadata metadata) {
+      logEntries.add(PerformanceLogEntry.create(operation, endTime, metadata));
     }
 
     ImmutableList<PerformanceLogEntry> logEntries() {
@@ -134,12 +135,14 @@
 
   @AutoValue
   abstract static class PerformanceLogEntry {
-    static PerformanceLogEntry create(String operation, Metadata metadata) {
-      return new AutoValue_SshTraceIT_PerformanceLogEntry(operation, metadata);
+    static PerformanceLogEntry create(String operation, Instant endTime, Metadata metadata) {
+      return new AutoValue_SshTraceIT_PerformanceLogEntry(operation, endTime, metadata);
     }
 
     abstract String operation();
 
+    abstract Instant endTime();
+
     abstract Metadata metadata();
   }
 }

javatests/com/google/gerrit/server/logging/LoggingContextAwareExecutorServiceTest.java

diff --git a/javatests/com/google/gerrit/server/logging/LoggingContextAwareExecutorServiceTest.java b/javatests/com/google/gerrit/server/logging/LoggingContextAwareExecutorServiceTest.java
index 1f0da16..c1b9f13 100644
--- a/javatests/com/google/gerrit/server/logging/LoggingContextAwareExecutorServiceTest.java
+++ b/javatests/com/google/gerrit/server/logging/LoggingContextAwareExecutorServiceTest.java
@@ -24,6 +24,7 @@
 import com.google.inject.Guice;
 import com.google.inject.Inject;
 import com.google.inject.Injector;
+import java.time.Instant;
 import java.util.Map;
 import java.util.Set;
 import java.util.concurrent.ExecutorService;
@@ -51,7 +52,7 @@
     testPerformanceLogger =
         new PerformanceLogger() {
           @Override
-          public void log(String operation, long durationMs, Metadata metadata) {
+          public void log(String operation, long durationMs, Instant endTime, Metadata metadata) {
             // do nothing
           }
         };

javatests/com/google/gerrit/server/logging/PerformanceLogContextTest.java

diff --git a/javatests/com/google/gerrit/server/logging/PerformanceLogContextTest.java b/javatests/com/google/gerrit/server/logging/PerformanceLogContextTest.java
index 512a1b1..c93061d 100644
--- a/javatests/com/google/gerrit/server/logging/PerformanceLogContextTest.java
+++ b/javatests/com/google/gerrit/server/logging/PerformanceLogContextTest.java
@@ -32,6 +32,7 @@
 import com.google.inject.Guice;
 import com.google.inject.Inject;
 import com.google.inject.Injector;
+import java.time.Instant;
 import java.util.concurrent.CopyOnWriteArrayList;
 import org.eclipse.jgit.lib.Config;
 import org.junit.After;
@@ -364,7 +365,7 @@
     private ImmutableList.Builder<PerformanceLogEntry> logEntries = ImmutableList.builder();
 
     @Override
-    public void log(String operation, long durationMs, Metadata metadata) {
+    public void log(String operation, long durationMs, Instant endTime, Metadata metadata) {
       logEntries.add(PerformanceLogEntry.create(operation, metadata));
     }