Add support for logging tags

By opening a TraceContext it is now possible to set a logging tag that
will be automatically included into all subsequent log statements that
are done by the same thread. When the TraceContext is closed the tag is
unset.

A tag has a name and a value. Having multiple tags with the same name
but different values is possible.

Adding a tag with the same name and same value a second time is possible
but has no effect.

With this change open TraceContexts are not propagated to newly started
threads that do work in the background. Support for this will be
implemented by the follow-up change.

Example:

  // Initially there are no tags
  logger.atSevere().log("log without tag");

  // a tag can be set by opening a TraceContext
  try (TraceContext ctx = new TraceContext("tag1", "value1")) {
    logger.atSevere().log("with tag1=value1");

    // by opening another TraceContext a another tag can be added
    try (TraceContext ctx2 = new TraceContext("tag2", "value2")) {
      logger.atSevere().log("log with tag1=value1 and tag2=value2");

      // it's possible to have same tag name with multiple values
      try (TraceContext ctx3 = new TraceContext("tag2", "value2a")) {
        logger.atSevere().log("log with tag1=value1, tag2=value2 and tag2=value2a");

        // adding a tag with the same name and value of an existing tag has no effect
        try (TraceContext ctx4 = new TraceContext("tag2", "value2a")) {
          logger.atSevere().log("log with tag1=value1, tag2=value2 and tag2=value2a");
        }

        // closing ctx4 didn't remove tag2=value2a since it was set before opening ctx4
        logger.atSevere().log("log with tag1=value1, tag2=value2 and tag2=value2a");
      }

      // closing ctx3 removed tag2=value2a
      logger.atSevere().log("log with tag1=value1 and tag2=value2");
    }

    // closing ctx2 removed tag2=value2
    logger.atSevere().log("with tag1=value1");
  }

  // closing ctx1 removed tag1=value1
  logger.atSevere().log("log without tag");

To support logging tags we must register a LoggingContext in Flogger.
This is done by setting the 'flogger.logging_context' system property.

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

java/Main.java

@@ -14,6 +14,7 @@
 
 public final class Main {
   private static final String FLOGGER_BACKEND_PROPERTY = "flogger.backend_factory";
+  private static final String FLOGGER_LOGGING_CONTEXT = "flogger.logging_context";
 
   // We don't do any real work here because we need to import
   // the archive lookup code and we cannot import a class in
@@ -42,6 +43,9 @@ public final class Main {
   }
 
   private static void configureFloggerBackend() {
+    System.setProperty(
+        FLOGGER_LOGGING_CONTEXT, "com.google.gerrit.server.logging.LoggingContext#getInstance");
+
     if (System.getProperty(FLOGGER_BACKEND_PROPERTY) != null) {
       // Flogger backend is already configured
       return;

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

@@ -0,0 +1,78 @@
+// Copyright (C) 2018 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.common.flogger.backend.Tags;
+import java.util.logging.Level;
+
+/**
+ * Logging context for Flogger.
+ *
+ * <p>To configure this logging context for Flogger set the following system property (also see
+ * {@link com.google.common.flogger.backend.system.DefaultPlatform}):
+ *
+ * <ul>
+ *   <li>{@code
+ *       flogger.logging_context=com.google.gerrit.server.logging.LoggingContext#getInstance}.
+ * </ul>
+ */
+public class LoggingContext extends com.google.common.flogger.backend.system.LoggingContext {
+  private static final LoggingContext INSTANCE = new LoggingContext();
+
+  private static final ThreadLocal<MutableTags> tags = new ThreadLocal<>();
+
+  private LoggingContext() {}
+
+  /** This method is expected to be called via reflection (and might otherwise be unused). */
+  public static LoggingContext getInstance() {
+    return INSTANCE;
+  }
+
+  @Override
+  public boolean shouldForceLogging(String loggerName, Level level, boolean isEnabled) {
+    return false;
+  }
+
+  @Override
+  public Tags getTags() {
+    MutableTags mutableTags = tags.get();
+    return mutableTags != null ? mutableTags.getTags() : Tags.empty();
+  }
+
+  boolean addTag(String name, String value) {
+    return getMutableTags().add(name, value);
+  }
+
+  void removeTag(String name, String value) {
+    MutableTags mutableTags = getMutableTags();
+    mutableTags.remove(name, value);
+    if (mutableTags.isEmpty()) {
+      tags.remove();
+    }
+  }
+
+  void clearTags() {
+    tags.remove();
+  }
+
+  private MutableTags getMutableTags() {
+    MutableTags mutableTags = tags.get();
+    if (mutableTags == null) {
+      mutableTags = new MutableTags();
+      tags.set(mutableTags);
+    }
+    return mutableTags;
+  }
+}

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

@@ -0,0 +1,92 @@
+// Copyright (C) 2018 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 static com.google.common.base.Preconditions.checkNotNull;
+
+import com.google.common.collect.MultimapBuilder;
+import com.google.common.collect.SetMultimap;
+import com.google.common.flogger.backend.Tags;
+
+public class MutableTags {
+  private final SetMultimap<String, String> tagMap =
+      MultimapBuilder.hashKeys().hashSetValues().build();
+  private Tags tags = Tags.empty();
+
+  public Tags getTags() {
+    return tags;
+  }
+
+  /**
+   * Adds a tag if a tag with the same name and value doesn't exist yet.
+   *
+   * @param name the name of the tag
+   * @param value the value of the tag
+   * @return {@code true} if the tag was added, {@code false} if the tag was not added because it
+   *     already exists
+   */
+  public boolean add(String name, String value) {
+    checkNotNull(name, "tag name is required");
+    checkNotNull(value, "tag value is required");
+    boolean ret = tagMap.put(name, value);
+    if (ret) {
+      buildTags();
+    }
+    return ret;
+  }
+
+  /**
+   * Removes the tag with the given name and value.
+   *
+   * @param name the name of the tag
+   * @param value the value of the tag
+   */
+  public void remove(String name, String value) {
+    checkNotNull(name, "tag name is required");
+    checkNotNull(value, "tag value is required");
+    if (tagMap.remove(name, value)) {
+      buildTags();
+    }
+  }
+
+  /**
+   * Checks if the contained tag map is empty.
+   *
+   * @return {@code true} if there are no tags, otherwise {@code false}
+   */
+  public boolean isEmpty() {
+    return tagMap.isEmpty();
+  }
+
+  /** Clears all tags. */
+  public void clear() {
+    tagMap.clear();
+    tags = Tags.empty();
+  }
+
+  private void buildTags() {
+    if (tagMap.isEmpty()) {
+      if (tags.isEmpty()) {
+        return;
+      }
+      tags = Tags.empty();
+      return;
+    }
+
+    Tags.Builder tagsBuilder = Tags.builder();
+    tagMap.forEach(tagsBuilder::addTag);
+    tags = tagsBuilder.build();
+  }
+}

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

@@ -0,0 +1,36 @@
+// Copyright (C) 2018 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 static com.google.common.base.Preconditions.checkNotNull;
+
+public class TraceContext implements AutoCloseable {
+  private final String tagName;
+  private final String tagValue;
+  private final boolean removeOnClose;
+
+  public TraceContext(String tagName, Object tagValue) {
+    this.tagName = checkNotNull(tagName, "tag name is required");
+    this.tagValue = checkNotNull(tagValue, "tag value is required").toString();
+    this.removeOnClose = LoggingContext.getInstance().addTag(this.tagName, this.tagValue);
+  }
+
+  @Override
+  public void close() {
+    if (removeOnClose) {
+      LoggingContext.getInstance().removeTag(tagName, tagValue);
+    }
+  }
+}

java/com/google/gerrit/testing/ConfigSuite.java

@@ -24,6 +24,7 @@ import com.google.common.base.MoreObjects;
 import com.google.common.collect.ImmutableMap;
 import com.google.common.collect.Iterables;
 import com.google.common.collect.Lists;
+import com.google.gerrit.server.logging.LoggingContext;
 import java.lang.annotation.Annotation;
 import java.lang.annotation.Retention;
 import java.lang.annotation.Target;
@@ -105,11 +106,13 @@ import org.junit.runners.model.InitializationError;
  */
 public class ConfigSuite extends Suite {
   private static final String FLOGGER_BACKEND_PROPERTY = "flogger.backend_factory";
+  private static final String FLOGGER_LOGGING_CONTEXT = "flogger.logging_context";
 
   static {
     System.setProperty(
         FLOGGER_BACKEND_PROPERTY,
         "com.google.common.flogger.backend.log4j.Log4jBackendFactory#getInstance");
+    System.setProperty(FLOGGER_LOGGING_CONTEXT, LoggingContext.class.getName() + "#getInstance");
   }
 
   public static final String DEFAULT = "default";

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

@@ -0,0 +1,154 @@
+// Copyright (C) 2018 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 static com.google.common.truth.Truth.assertThat;
+import static com.google.common.truth.Truth.assert_;
+
+import com.google.common.collect.ImmutableMap;
+import com.google.common.collect.ImmutableSet;
+import java.util.Map;
+import java.util.SortedMap;
+import java.util.SortedSet;
+import org.junit.Before;
+import org.junit.Test;
+
+public class MutableTagsTest {
+  private MutableTags tags;
+
+  @Before
+  public void setup() {
+    tags = new MutableTags();
+  }
+
+  @Test
+  public void addTag() {
+    assertThat(tags.add("name", "value")).isTrue();
+    assertTags(ImmutableMap.of("name", ImmutableSet.of("value")));
+  }
+
+  @Test
+  public void addTagsWithDifferentName() {
+    assertThat(tags.add("name1", "value1")).isTrue();
+    assertThat(tags.add("name2", "value2")).isTrue();
+    assertTags(
+        ImmutableMap.of("name1", ImmutableSet.of("value1"), "name2", ImmutableSet.of("value2")));
+  }
+
+  @Test
+  public void addTagsWithSameNameButDifferentValues() {
+    assertThat(tags.add("name", "value1")).isTrue();
+    assertThat(tags.add("name", "value2")).isTrue();
+    assertTags(ImmutableMap.of("name", ImmutableSet.of("value1", "value2")));
+  }
+
+  @Test
+  public void addTagsWithSameNameAndSameValue() {
+    assertThat(tags.add("name", "value")).isTrue();
+    assertThat(tags.add("name", "value")).isFalse();
+    assertTags(ImmutableMap.of("name", ImmutableSet.of("value")));
+  }
+
+  @Test
+  public void getEmptyTags() {
+    assertThat(tags.getTags().isEmpty()).isTrue();
+    assertTags(ImmutableMap.of());
+  }
+
+  @Test
+  public void isEmpty() {
+    assertThat(tags.isEmpty()).isTrue();
+
+    tags.add("foo", "bar");
+    assertThat(tags.isEmpty()).isFalse();
+
+    tags.remove("foo", "bar");
+    assertThat(tags.isEmpty()).isTrue();
+  }
+
+  @Test
+  public void removeTags() {
+    tags.add("name1", "value1");
+    tags.add("name1", "value2");
+    tags.add("name2", "value");
+    assertTags(
+        ImmutableMap.of(
+            "name1", ImmutableSet.of("value1", "value2"), "name2", ImmutableSet.of("value")));
+
+    tags.remove("name2", "value");
+    assertTags(ImmutableMap.of("name1", ImmutableSet.of("value1", "value2")));
+
+    tags.remove("name1", "value1");
+    assertTags(ImmutableMap.of("name1", ImmutableSet.of("value2")));
+
+    tags.remove("name1", "value2");
+    assertTags(ImmutableMap.of());
+  }
+
+  @Test
+  public void removeNonExistingTag() {
+    tags.add("name", "value");
+    assertTags(ImmutableMap.of("name", ImmutableSet.of("value")));
+
+    tags.remove("foo", "bar");
+    assertTags(ImmutableMap.of("name", ImmutableSet.of("value")));
+
+    tags.remove("name", "foo");
+    assertTags(ImmutableMap.of("name", ImmutableSet.of("value")));
+  }
+
+  @Test
+  public void clearTags() {
+    tags.add("name1", "value1");
+    tags.add("name1", "value2");
+    tags.add("name2", "value");
+    assertTags(
+        ImmutableMap.of(
+            "name1", ImmutableSet.of("value1", "value2"), "name2", ImmutableSet.of("value")));
+
+    tags.clear();
+    assertTags(ImmutableMap.of());
+  }
+
+  @Test
+  public void addInvalidTag() {
+    assertNullPointerException("tag name is required", () -> tags.add(null, "foo"));
+    assertNullPointerException("tag value is required", () -> tags.add("foo", null));
+  }
+
+  @Test
+  public void removeInvalidTag() {
+    assertNullPointerException("tag name is required", () -> tags.remove(null, "foo"));
+    assertNullPointerException("tag value is required", () -> tags.remove("foo", null));
+  }
+
+  private void assertTags(ImmutableMap<String, ImmutableSet<String>> expectedTagMap) {
+    SortedMap<String, SortedSet<Object>> actualTagMap = tags.getTags().asMap();
+    assertThat(actualTagMap.keySet()).containsExactlyElementsIn(expectedTagMap.keySet());
+    for (Map.Entry<String, ImmutableSet<String>> expectedEntry : expectedTagMap.entrySet()) {
+      assertThat(actualTagMap.get(expectedEntry.getKey()))
+          .containsExactlyElementsIn(expectedEntry.getValue());
+    }
+  }
+
+  private void assertNullPointerException(String expectedMessage, Runnable r) {
+    try {
+      r.run();
+      assert_().fail("expected NullPointerException");
+    } catch (NullPointerException e) {
+      assertThat(e.getMessage()).isEqualTo(expectedMessage);
+    }
+  }
+}

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

@@ -0,0 +1,112 @@
+// Copyright (C) 2018 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 static com.google.common.truth.Truth.assertThat;
+import static com.google.common.truth.Truth.assert_;
+
+import com.google.common.collect.ImmutableMap;
+import com.google.common.collect.ImmutableSet;
+import java.util.Map;
+import java.util.SortedMap;
+import java.util.SortedSet;
+import org.junit.After;
+import org.junit.Test;
+
+public class TraceContextTest {
+  @After
+  public void cleanup() {
+    LoggingContext.getInstance().clearTags();
+  }
+
+  @Test
+  public void openContext() {
+    assertTags(ImmutableMap.of());
+    try (TraceContext traceContext = new TraceContext("foo", "bar")) {
+      assertTags(ImmutableMap.of("foo", ImmutableSet.of("bar")));
+    }
+    assertTags(ImmutableMap.of());
+  }
+
+  @Test
+  public void openNestedContexts() {
+    assertTags(ImmutableMap.of());
+    try (TraceContext traceContext = new TraceContext("foo", "bar")) {
+      assertTags(ImmutableMap.of("foo", ImmutableSet.of("bar")));
+
+      try (TraceContext traceContext2 = new TraceContext("abc", "xyz")) {
+        assertTags(ImmutableMap.of("abc", ImmutableSet.of("xyz"), "foo", ImmutableSet.of("bar")));
+      }
+
+      assertTags(ImmutableMap.of("foo", ImmutableSet.of("bar")));
+    }
+    assertTags(ImmutableMap.of());
+  }
+
+  @Test
+  public void openNestedContextsWithSameTagName() {
+    assertTags(ImmutableMap.of());
+    try (TraceContext traceContext = new TraceContext("foo", "bar")) {
+      assertTags(ImmutableMap.of("foo", ImmutableSet.of("bar")));
+
+      try (TraceContext traceContext2 = new TraceContext("foo", "baz")) {
+        assertTags(ImmutableMap.of("foo", ImmutableSet.of("bar", "baz")));
+      }
+
+      assertTags(ImmutableMap.of("foo", ImmutableSet.of("bar")));
+    }
+    assertTags(ImmutableMap.of());
+  }
+
+  @Test
+  public void openNestedContextsWithSameTagNameAndValue() {
+    assertTags(ImmutableMap.of());
+    try (TraceContext traceContext = new TraceContext("foo", "bar")) {
+      assertTags(ImmutableMap.of("foo", ImmutableSet.of("bar")));
+
+      try (TraceContext traceContext2 = new TraceContext("foo", "bar")) {
+        assertTags(ImmutableMap.of("foo", ImmutableSet.of("bar")));
+      }
+
+      assertTags(ImmutableMap.of("foo", ImmutableSet.of("bar")));
+    }
+    assertTags(ImmutableMap.of());
+  }
+
+  @Test
+  public void cannotOpenContextWithInvalidTag() {
+    assertNullPointerException("tag name is required", () -> new TraceContext(null, "foo"));
+    assertNullPointerException("tag value is required", () -> new TraceContext("foo", null));
+  }
+
+  private void assertTags(ImmutableMap<String, ImmutableSet<String>> expectedTagMap) {
+    SortedMap<String, SortedSet<Object>> actualTagMap =
+        LoggingContext.getInstance().getTags().asMap();
+    assertThat(actualTagMap.keySet()).containsExactlyElementsIn(expectedTagMap.keySet());
+    for (Map.Entry<String, ImmutableSet<String>> expectedEntry : expectedTagMap.entrySet()) {
+      assertThat(actualTagMap.get(expectedEntry.getKey()))
+          .containsExactlyElementsIn(expectedEntry.getValue());
+    }
+  }
+
+  private void assertNullPointerException(String expectedMessage, Runnable r) {
+    try {
+      r.run();
+      assert_().fail("expected NullPointerException");
+    } catch (NullPointerException e) {
+      assertThat(e.getMessage()).isEqualTo(expectedMessage);
+    }
+  }
+}