Add a config option to control whether performance logging should be done

Performance logging increases the memory footprint of requests which is
why it might be desired to turn it off.

Signed-off-by: Edwin Kempin <ekempin@google.com>
Change-Id: Ib04e7f55b7c9652df5d61f5684305306baec67e5

Documentation/config-gerrit.txt

@@ -4551,6 +4551,26 @@ used for suggesting accounts when adding members to a group.
 +
 By default 0.
 
+[[tracing]]
+=== Section tracing
+
+[[tracing.performanceLogging]]tracing.performanceLogging::
++
+Whether performance logging is enabled.
++
+When performance logging is enabled, performance events for some
+operations are collected in memory while a request is running. At the
+end of the request the performance events are handed over to the
+link:dev-plugins.html#performance-logger[PerformanceLogger] plugins.
+This means if performance logging is enabled, the memory footprint of
+requests is slightly increased.
++
+This setting has no effect if no
+link:dev-plugins.html#performance-logger[PerformanceLogger] plugins are
+installed, because then performance logging is always disabled.
++
+By default, true.
+
 [[trackingid]]
 === Section trackingid
 

java/com/google/gerrit/httpd/restapi/RestApiServlet.java

@@ -232,6 +232,7 @@ public class RestApiServlet extends HttpServlet {
     final RestApiMetrics metrics;
     final Pattern allowOrigin;
     final RestApiQuotaEnforcer quotaChecker;
+    final Config config;
     final DynamicSet<PerformanceLogger> performanceLoggers;
 
     @Inject
@@ -243,7 +244,7 @@ public class RestApiServlet extends HttpServlet {
         GroupAuditService auditService,
         RestApiMetrics metrics,
         RestApiQuotaEnforcer quotaChecker,
-        @GerritServerConfig Config cfg,
+        @GerritServerConfig Config config,
         DynamicSet<PerformanceLogger> performanceLoggers) {
       this.currentUser = currentUser;
       this.webSession = webSession;
@@ -252,8 +253,9 @@ public class RestApiServlet extends HttpServlet {
       this.auditService = auditService;
       this.metrics = metrics;
       this.quotaChecker = quotaChecker;
+      this.config = config;
       this.performanceLoggers = performanceLoggers;
-      allowOrigin = makeAllowOrigin(cfg);
+      allowOrigin = makeAllowOrigin(config);
     }
 
     private static Pattern makeAllowOrigin(Config cfg) {
@@ -306,7 +308,7 @@ public class RestApiServlet extends HttpServlet {
         // test performance logging from an acceptance test (see
         // TraceIT#performanceLoggingForRestCall()).
         try (PerformanceLogContext performanceLogContext =
-            new PerformanceLogContext(globals.performanceLoggers)) {
+            new PerformanceLogContext(globals.config, globals.performanceLoggers)) {
           logger.atFinest().log(
               "Received REST request: %s %s (parameters: %s)",
               req.getMethod(), req.getRequestURI(), getParameterNames(req));

java/com/google/gerrit/server/git/receive/ReceiveCommits.java

@@ -312,6 +312,7 @@ class ReceiveCommits {
   private final CommentsUtil commentsUtil;
   private final PluginSetContext<CommentValidator> commentValidators;
   private final BranchCommitValidator.Factory commitValidatorFactory;
+  private final Config config;
   private final CreateGroupPermissionSyncer createGroupPermissionSyncer;
   private final CreateRefControl createRefControl;
   private final DynamicMap<ProjectConfigEntry> pluginConfigEntries;
@@ -381,7 +382,7 @@ class ReceiveCommits {
       AllProjectsName allProjectsName,
       BatchUpdate.Factory batchUpdateFactory,
       ProjectConfig.Factory projectConfigFactory,
-      @GerritServerConfig Config cfg,
+      @GerritServerConfig Config config,
       ChangeEditUtil editUtil,
       ChangeIndexer indexer,
       ChangeInserter.Factory changeInserterFactory,
@@ -430,6 +431,7 @@ class ReceiveCommits {
     this.commentsUtil = commentsUtil;
     this.commentValidators = commentValidators;
     this.commitValidatorFactory = commitValidatorFactory;
+    this.config = config;
     this.createRefControl = createRefControl;
     this.createGroupPermissionSyncer = createGroupPermissionSyncer;
     this.editUtil = editUtil;
@@ -466,7 +468,7 @@ class ReceiveCommits {
     this.receivePack = rp;
 
     // Immutable fields derived from constructor arguments.
-    allowPushToRefsChanges = cfg.getBoolean("receive", "allowPushToRefsChanges", false);
+    allowPushToRefsChanges = config.getBoolean("receive", "allowPushToRefsChanges", false);
     repo = rp.getRepository();
     project = projectState.getProject();
     labelTypes = projectState.getLabelTypes();
@@ -481,7 +483,7 @@ class ReceiveCommits {
     updateGroups = new ArrayList<>();
 
     this.allowProjectOwnersToChangeParent =
-        cfg.getBoolean("receive", "allowProjectOwnersToChangeParent", false);
+        config.getBoolean("receive", "allowProjectOwnersToChangeParent", false);
 
     // Other settings populated during processing.
     newChangeForAllNotInTarget =
@@ -534,7 +536,7 @@ class ReceiveCommits {
                 (tagName, traceId) -> addMessage(tagName + ": " + traceId));
         TraceTimer traceTimer = newTimer("processCommands", "commandCount", commands.size());
         PerformanceLogContext performanceLogContext =
-            new PerformanceLogContext(performanceLoggers)) {
+            new PerformanceLogContext(config, performanceLoggers)) {
       traceContext.addTag(RequestId.Type.RECEIVE_ID, new RequestId(project.getNameKey().get()));
 
       // Log the push options here, rather than in parsePushOptions(), so that they are included

java/com/google/gerrit/server/logging/BUILD

@@ -13,5 +13,6 @@ java_library(
         "//lib/auto:auto-value-annotations",
         "//lib/flogger:api",
         "//lib/guice",
+        "//lib/jgit/org.eclipse.jgit:jgit",
     ],
 )

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

@@ -19,6 +19,7 @@ import com.google.common.collect.Iterables;
 import com.google.common.flogger.FluentLogger;
 import com.google.gerrit.extensions.registration.DynamicSet;
 import com.google.gerrit.extensions.registration.Extension;
+import org.eclipse.jgit.lib.Config;
 
 /**
  * Context for capturing performance log records. When the context is closed the performance log
@@ -43,7 +44,8 @@ public class PerformanceLogContext implements AutoCloseable {
   private final boolean oldPerformanceLogging;
   private final ImmutableList<PerformanceLogRecord> oldPerformanceLogRecords;
 
-  public PerformanceLogContext(DynamicSet<PerformanceLogger> performanceLoggers) {
+  public PerformanceLogContext(
+      Config gerritConfig, DynamicSet<PerformanceLogger> performanceLoggers) {
     this.performanceLoggers = performanceLoggers;
 
     // Just in case remember the old state and reset performance log entries.
@@ -51,9 +53,13 @@ public class PerformanceLogContext implements AutoCloseable {
     this.oldPerformanceLogRecords = LoggingContext.getInstance().getPerformanceLogRecords();
     LoggingContext.getInstance().clearPerformanceLogEntries();
 
-    // Do not create performance log entries if no PerformanceLogger is registered.
+    // Do not create performance log entries if performance logging is disabled or if no
+    // PerformanceLogger is registered.
+    boolean enablePerformanceLogging =
+        gerritConfig.getBoolean("tracing", "performanceLogging", true);
     LoggingContext.getInstance()
-        .performanceLogging(!Iterables.isEmpty(performanceLoggers.entries()));
+        .performanceLogging(
+            enablePerformanceLogging && !Iterables.isEmpty(performanceLoggers.entries()));
   }
 
   @Override

java/com/google/gerrit/sshd/SshCommand.java

@@ -16,6 +16,7 @@ package com.google.gerrit.sshd;
 
 import com.google.gerrit.extensions.registration.DynamicSet;
 import com.google.gerrit.server.AccessPath;
+import com.google.gerrit.server.config.GerritServerConfig;
 import com.google.gerrit.server.logging.PerformanceLogContext;
 import com.google.gerrit.server.logging.PerformanceLogger;
 import com.google.gerrit.server.logging.TraceContext;
@@ -23,10 +24,12 @@ import com.google.inject.Inject;
 import java.io.IOException;
 import java.io.PrintWriter;
 import org.apache.sshd.server.Environment;
+import org.eclipse.jgit.lib.Config;
 import org.kohsuke.args4j.Option;
 
 public abstract class SshCommand extends BaseCommand {
   @Inject private DynamicSet<PerformanceLogger> performanceLoggers;
+  @Inject @GerritServerConfig private Config config;
 
   @Option(name = "--trace", usage = "enable request tracing")
   private boolean trace;
@@ -46,7 +49,7 @@ public abstract class SshCommand extends BaseCommand {
           stderr = toPrintWriter(err);
           try (TraceContext traceContext = enableTracing();
               PerformanceLogContext performanceLogContext =
-                  new PerformanceLogContext(performanceLoggers)) {
+                  new PerformanceLogContext(config, performanceLoggers)) {
             SshCommand.this.run();
           } finally {
             stdout.flush();

javatests/com/google/gerrit/acceptance/rest/TraceIT.java

@@ -24,6 +24,7 @@ import com.google.common.collect.ImmutableSet;
 import com.google.common.collect.Iterables;
 import com.google.common.truth.Expect;
 import com.google.gerrit.acceptance.AbstractDaemonTest;
+import com.google.gerrit.acceptance.GerritConfig;
 import com.google.gerrit.acceptance.PushOneCommit;
 import com.google.gerrit.acceptance.RestResponse;
 import com.google.gerrit.extensions.registration.DynamicSet;
@@ -294,6 +295,19 @@ public class TraceIT extends AbstractDaemonTest {
     assertThat(testPerformanceLogger.logEntries()).isNotEmpty();
   }
 
+  @Test
+  @GerritConfig(name = "tracing.performanceLogging", value = "false")
+  public void noPerformanceLoggingIfDisabled() throws Exception {
+    RestResponse response = adminRestSession.put("/projects/new11");
+    assertThat(response.getStatusCode()).isEqualTo(SC_CREATED);
+
+    PushOneCommit push = pushFactory.create(admin.newIdent(), testRepo);
+    PushOneCommit.Result r = push.to("refs/heads/master");
+    r.assertOkStatus();
+
+    assertThat(testPerformanceLogger.logEntries()).isEmpty();
+  }
+
   private void assertForceLogging(boolean expected) {
     assertThat(LoggingContext.getInstance().shouldForceLogging(null, null, false))
         .isEqualTo(expected);

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

@@ -19,6 +19,7 @@ import static com.google.common.truth.Truth.assertThat;
 import com.google.common.truth.Expect;
 import com.google.gerrit.extensions.registration.DynamicSet;
 import com.google.gerrit.extensions.registration.RegistrationHandle;
+import com.google.gerrit.server.config.GerritServerConfig;
 import com.google.gerrit.testing.InMemoryModule;
 import com.google.inject.Guice;
 import com.google.inject.Inject;
@@ -29,6 +30,7 @@ import java.util.SortedMap;
 import java.util.SortedSet;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
+import org.eclipse.jgit.lib.Config;
 import org.junit.After;
 import org.junit.Before;
 import org.junit.Rule;
@@ -37,6 +39,7 @@ import org.junit.Test;
 public class LoggingContextAwareExecutorServiceTest {
   @Rule public final Expect expect = Expect.create();
 
+  @Inject @GerritServerConfig private Config config;
   @Inject private DynamicSet<PerformanceLogger> performanceLoggers;
 
   private PerformanceLogger testPerformanceLogger;
@@ -72,7 +75,7 @@ public class LoggingContextAwareExecutorServiceTest {
 
     try (TraceContext traceContext = TraceContext.open().forceLogging().addTag("foo", "bar");
         PerformanceLogContext performanceLogContext =
-            new PerformanceLogContext(performanceLoggers)) {
+            new PerformanceLogContext(config, performanceLoggers)) {
       // Create a performance log record.
       TraceContext.newTimer("test").close();
 

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

@@ -28,6 +28,7 @@ import com.google.gerrit.metrics.Timer0;
 import com.google.gerrit.metrics.Timer1;
 import com.google.gerrit.metrics.Timer2;
 import com.google.gerrit.metrics.Timer3;
+import com.google.gerrit.server.config.GerritServerConfig;
 import com.google.gerrit.testing.InMemoryModule;
 import com.google.inject.Guice;
 import com.google.inject.Inject;
@@ -36,11 +37,13 @@ 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;
 import org.junit.Test;
 
 public class PerformanceLogContextTest {
+  @Inject @GerritServerConfig private Config config;
   @Inject private DynamicSet<PerformanceLogger> performanceLoggers;
 
   // In this test setup this gets the DisabledMetricMaker injected. This means it doesn't record any
@@ -72,7 +75,8 @@ public class PerformanceLogContextTest {
     assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
     assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
 
-    try (PerformanceLogContext traceContext = new PerformanceLogContext(performanceLoggers)) {
+    try (PerformanceLogContext traceContext =
+        new PerformanceLogContext(config, performanceLoggers)) {
       assertThat(LoggingContext.getInstance().isPerformanceLogging()).isTrue();
 
       TraceContext.newTimer("test1").close();
@@ -122,7 +126,8 @@ public class PerformanceLogContextTest {
     assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
     assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
 
-    try (PerformanceLogContext traceContext = new PerformanceLogContext(performanceLoggers)) {
+    try (PerformanceLogContext traceContext =
+        new PerformanceLogContext(config, performanceLoggers)) {
       assertThat(LoggingContext.getInstance().isPerformanceLogging()).isTrue();
 
       TraceContext.newTimer("test1").close();
@@ -188,7 +193,8 @@ public class PerformanceLogContextTest {
     assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
     assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
 
-    try (PerformanceLogContext traceContext = new PerformanceLogContext(performanceLoggers)) {
+    try (PerformanceLogContext traceContext =
+        new PerformanceLogContext(config, performanceLoggers)) {
       assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
 
       TraceContext.newTimer("test1").close();
@@ -212,7 +218,8 @@ public class PerformanceLogContextTest {
     assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
     assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
 
-    try (PerformanceLogContext traceContext = new PerformanceLogContext(performanceLoggers)) {
+    try (PerformanceLogContext traceContext =
+        new PerformanceLogContext(config, performanceLoggers)) {
       assertThat(LoggingContext.getInstance().isPerformanceLogging()).isTrue();
 
       Timer0 timer0 =
@@ -274,7 +281,8 @@ public class PerformanceLogContextTest {
     assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
     assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
 
-    try (PerformanceLogContext traceContext = new PerformanceLogContext(performanceLoggers)) {
+    try (PerformanceLogContext traceContext =
+        new PerformanceLogContext(config, performanceLoggers)) {
       assertThat(LoggingContext.getInstance().isPerformanceLogging()).isTrue();
 
       Timer1<String> timer1 =
@@ -371,7 +379,8 @@ public class PerformanceLogContextTest {
     assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
     assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
 
-    try (PerformanceLogContext traceContext = new PerformanceLogContext(performanceLoggers)) {
+    try (PerformanceLogContext traceContext =
+        new PerformanceLogContext(config, performanceLoggers)) {
       assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
 
       Timer0 timer0 =
@@ -416,14 +425,16 @@ public class PerformanceLogContextTest {
     assertThat(LoggingContext.getInstance().isPerformanceLogging()).isFalse();
     assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
 
-    try (PerformanceLogContext traceContext1 = new PerformanceLogContext(performanceLoggers)) {
+    try (PerformanceLogContext traceContext1 =
+        new PerformanceLogContext(config, performanceLoggers)) {
       assertThat(LoggingContext.getInstance().isPerformanceLogging()).isTrue();
 
       TraceContext.newTimer("test1").close();
 
       assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).hasSize(1);
 
-      try (PerformanceLogContext traceContext2 = new PerformanceLogContext(performanceLoggers)) {
+      try (PerformanceLogContext traceContext2 =
+          new PerformanceLogContext(config, performanceLoggers)) {
         assertThat(LoggingContext.getInstance().getPerformanceLogRecords()).isEmpty();
         assertThat(LoggingContext.getInstance().isPerformanceLogging()).isTrue();