Add a request listener that sets a logging tag with the project
If a request is done for a project we are now setting a logging tag with
the project name that is associated with each log that is done for the
request. This way one can easily see for all errors/warnings in the log
for which project they occurred.
Future changes may add advanced tracing capabilities to the newly added
TraceRequestListener. E.g. there could be configuration that enables
tracing for a certain user or project. TraceRequestListener could read
the config and then enable the tracing if the user/project matches.
Signed-off-by: Edwin Kempin <ekempin@google.com>
Change-Id: I7401c1bcef5c16039401013445dea32432d9098e
diff --git a/java/com/google/gerrit/server/TraceRequestListener.java b/java/com/google/gerrit/server/TraceRequestListener.java
new file mode 100644
index 0000000..1ae39e1
--- /dev/null
+++ b/java/com/google/gerrit/server/TraceRequestListener.java
@@ -0,0 +1,25 @@
+// 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;
+
+import com.google.inject.Singleton;
+
+@Singleton
+public class TraceRequestListener implements RequestListener {
+ @Override
+ public void onRequest(RequestInfo requestInfo) {
+ requestInfo.project().ifPresent(p -> requestInfo.traceContext().addTag("project", p));
+ }
+}
diff --git a/java/com/google/gerrit/server/config/GerritGlobalModule.java b/java/com/google/gerrit/server/config/GerritGlobalModule.java
index 276b3fc..bbc5748 100644
--- a/java/com/google/gerrit/server/config/GerritGlobalModule.java
+++ b/java/com/google/gerrit/server/config/GerritGlobalModule.java
@@ -80,6 +80,7 @@
import com.google.gerrit.server.DynamicOptions;
import com.google.gerrit.server.IdentifiedUser;
import com.google.gerrit.server.RequestListener;
+import com.google.gerrit.server.TraceRequestListener;
import com.google.gerrit.server.account.AccountCacheImpl;
import com.google.gerrit.server.account.AccountControl;
import com.google.gerrit.server.account.AccountDeactivator;
@@ -386,6 +387,7 @@
DynamicSet.setOf(binder(), QuotaEnforcer.class);
DynamicSet.setOf(binder(), PerformanceLogger.class);
DynamicSet.setOf(binder(), RequestListener.class);
+ DynamicSet.bind(binder(), RequestListener.class).to(TraceRequestListener.class);
DynamicMap.mapOf(binder(), MailFilter.class);
bind(MailFilter.class).annotatedWith(Exports.named("ListMailFilter")).to(ListMailFilter.class);
diff --git a/javatests/com/google/gerrit/acceptance/rest/TraceIT.java b/javatests/com/google/gerrit/acceptance/rest/TraceIT.java
index e587a27..50d6dff 100644
--- a/javatests/com/google/gerrit/acceptance/rest/TraceIT.java
+++ b/javatests/com/google/gerrit/acceptance/rest/TraceIT.java
@@ -16,16 +16,20 @@
import static com.google.common.truth.Truth.assertThat;
import static org.apache.http.HttpStatus.SC_CREATED;
+import static org.apache.http.HttpStatus.SC_OK;
import com.google.auto.value.AutoValue;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.ImmutableSet;
+import com.google.common.collect.ImmutableSetMultimap;
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.api.changes.ReviewInput;
+import com.google.gerrit.extensions.events.ChangeIndexedListener;
import com.google.gerrit.extensions.registration.DynamicSet;
import com.google.gerrit.extensions.registration.RegistrationHandle;
import com.google.gerrit.httpd.restapi.ParameterParser;
@@ -73,6 +77,7 @@
@Inject private DynamicSet<ProjectCreationValidationListener> projectCreationValidationListeners;
@Inject private DynamicSet<CommitValidationListener> commitValidationListeners;
+ @Inject private DynamicSet<ChangeIndexedListener> changeIndexedListeners;
@Inject private DynamicSet<PerformanceLogger> performanceLoggers;
@Inject private WorkQueue workQueue;
@@ -109,6 +114,29 @@
assertThat(response.getHeader(RestApiServlet.X_GERRIT_TRACE)).isNull();
assertThat(projectCreationListener.traceId).isNull();
assertThat(projectCreationListener.isLoggingForced).isFalse();
+
+ // The logging tag with the project name is also set if tracing is off.
+ assertThat(projectCreationListener.tags.get("project")).containsExactly("new1");
+ }
+
+ @Test
+ public void restCallForChangeSetsProjectTag() throws Exception {
+ String changeId = createChange().getChangeId();
+
+ TraceChangeIndexedListener changeIndexedListener = new TraceChangeIndexedListener();
+ RegistrationHandle registrationHandle =
+ changeIndexedListeners.add("gerrit", changeIndexedListener);
+ try {
+ RestResponse response =
+ adminRestSession.post(
+ "/changes/" + changeId + "/revisions/current/review", ReviewInput.approve());
+ assertThat(response.getStatusCode()).isEqualTo(SC_OK);
+
+ // The logging tag with the project name is also set if tracing is off.
+ assertThat(changeIndexedListener.tags.get("project")).containsExactly(project.get());
+ } finally {
+ registrationHandle.remove();
+ }
}
@Test
@@ -119,6 +147,7 @@
assertThat(response.getHeader(RestApiServlet.X_GERRIT_TRACE)).isNotNull();
assertThat(projectCreationListener.traceId).isNotNull();
assertThat(projectCreationListener.isLoggingForced).isTrue();
+ assertThat(projectCreationListener.tags.get("project")).containsExactly("new2");
}
@Test
@@ -129,6 +158,7 @@
assertThat(response.getHeader(RestApiServlet.X_GERRIT_TRACE)).isEqualTo("issue/123");
assertThat(projectCreationListener.traceId).isEqualTo("issue/123");
assertThat(projectCreationListener.isLoggingForced).isTrue();
+ assertThat(projectCreationListener.tags.get("project")).containsExactly("new3");
}
@Test
@@ -140,6 +170,7 @@
assertThat(response.getHeader(RestApiServlet.X_GERRIT_TRACE)).isNotNull();
assertThat(projectCreationListener.traceId).isNotNull();
assertThat(projectCreationListener.isLoggingForced).isTrue();
+ assertThat(projectCreationListener.tags.get("project")).containsExactly("new4");
}
@Test
@@ -151,6 +182,7 @@
assertThat(response.getHeader(RestApiServlet.X_GERRIT_TRACE)).isEqualTo("issue/123");
assertThat(projectCreationListener.traceId).isEqualTo("issue/123");
assertThat(projectCreationListener.isLoggingForced).isTrue();
+ assertThat(projectCreationListener.tags.get("project")).containsExactly("new5");
}
@Test
@@ -163,6 +195,7 @@
assertThat(response.getHeader(RestApiServlet.X_GERRIT_TRACE)).isEqualTo("issue/123");
assertThat(projectCreationListener.traceId).isEqualTo("issue/123");
assertThat(projectCreationListener.isLoggingForced).isTrue();
+ assertThat(projectCreationListener.tags.get("project")).containsExactly("new6");
// trace ID only specified by trace request parameter
response =
@@ -172,6 +205,7 @@
assertThat(response.getHeader(RestApiServlet.X_GERRIT_TRACE)).isEqualTo("issue/123");
assertThat(projectCreationListener.traceId).isEqualTo("issue/123");
assertThat(projectCreationListener.isLoggingForced).isTrue();
+ assertThat(projectCreationListener.tags.get("project")).containsExactly("new7");
// same trace ID specified by trace header and trace request parameter
response =
@@ -182,6 +216,7 @@
assertThat(response.getHeader(RestApiServlet.X_GERRIT_TRACE)).isEqualTo("issue/123");
assertThat(projectCreationListener.traceId).isEqualTo("issue/123");
assertThat(projectCreationListener.isLoggingForced).isTrue();
+ assertThat(projectCreationListener.tags.get("project")).containsExactly("new8");
// different trace IDs specified by trace header and trace request parameter
response =
@@ -193,6 +228,7 @@
.containsExactly("issue/123", "issue/456");
assertThat(projectCreationListener.traceIds).containsExactly("issue/123", "issue/456");
assertThat(projectCreationListener.isLoggingForced).isTrue();
+ assertThat(projectCreationListener.tags.get("project")).containsExactly("new9");
}
@Test
@@ -202,6 +238,9 @@
r.assertOkStatus();
assertThat(commitValidationListener.traceId).isNull();
assertThat(commitValidationListener.isLoggingForced).isFalse();
+
+ // The logging tag with the project name is also set if tracing is off.
+ assertThat(commitValidationListener.tags.get("project")).containsExactly(project.get());
}
@Test
@@ -212,6 +251,7 @@
r.assertOkStatus();
assertThat(commitValidationListener.traceId).isNotNull();
assertThat(commitValidationListener.isLoggingForced).isTrue();
+ assertThat(commitValidationListener.tags.get("project")).containsExactly(project.get());
}
@Test
@@ -222,6 +262,7 @@
r.assertOkStatus();
assertThat(commitValidationListener.traceId).isEqualTo("issue/123");
assertThat(commitValidationListener.isLoggingForced).isTrue();
+ assertThat(commitValidationListener.tags.get("project")).containsExactly(project.get());
}
@Test
@@ -231,6 +272,9 @@
r.assertOkStatus();
assertThat(commitValidationListener.traceId).isNull();
assertThat(commitValidationListener.isLoggingForced).isFalse();
+
+ // The logging tag with the project name is also set if tracing is off.
+ assertThat(commitValidationListener.tags.get("project")).containsExactly(project.get());
}
@Test
@@ -241,6 +285,7 @@
r.assertOkStatus();
assertThat(commitValidationListener.traceId).isNotNull();
assertThat(commitValidationListener.isLoggingForced).isTrue();
+ assertThat(commitValidationListener.tags.get("project")).containsExactly(project.get());
}
@Test
@@ -251,6 +296,7 @@
r.assertOkStatus();
assertThat(commitValidationListener.traceId).isEqualTo("issue/123");
assertThat(commitValidationListener.isLoggingForced).isTrue();
+ assertThat(commitValidationListener.tags.get("project")).containsExactly(project.get());
}
@Test
@@ -331,6 +377,7 @@
String traceId;
ImmutableSet<String> traceIds;
Boolean isLoggingForced;
+ ImmutableSetMultimap<String, String> tags;
@Override
public void validateNewProject(CreateProjectArgs args) throws ValidationException {
@@ -338,12 +385,14 @@
Iterables.getFirst(LoggingContext.getInstance().getTagsAsMap().get("TRACE_ID"), null);
this.traceIds = LoggingContext.getInstance().getTagsAsMap().get("TRACE_ID");
this.isLoggingForced = LoggingContext.getInstance().shouldForceLogging(null, null, false);
+ this.tags = LoggingContext.getInstance().getTagsAsMap();
}
}
private static class TraceValidatingCommitValidationListener implements CommitValidationListener {
String traceId;
Boolean isLoggingForced;
+ ImmutableSetMultimap<String, String> tags;
@Override
public List<CommitValidationMessage> onCommitReceived(CommitReceivedEvent receiveEvent)
@@ -351,10 +400,23 @@
this.traceId =
Iterables.getFirst(LoggingContext.getInstance().getTagsAsMap().get("TRACE_ID"), null);
this.isLoggingForced = LoggingContext.getInstance().shouldForceLogging(null, null, false);
+ this.tags = LoggingContext.getInstance().getTagsAsMap();
return ImmutableList.of();
}
}
+ private static class TraceChangeIndexedListener implements ChangeIndexedListener {
+ ImmutableSetMultimap<String, String> tags;
+
+ @Override
+ public void onChangeIndexed(String projectName, int id) {
+ this.tags = LoggingContext.getInstance().getTagsAsMap();
+ }
+
+ @Override
+ public void onChangeDeleted(int id) {}
+ }
+
private static class TestPerformanceLogger implements PerformanceLogger {
private List<PerformanceLogEntry> logEntries = new ArrayList<>();
