From d92f6f754aa38b757d29b6679430570a59a7e1bc Mon Sep 17 00:00:00 2001 From: Edwin Kempin Date: Fri, 3 Aug 2018 09:00:08 +0200 Subject: [PATCH] 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 --- java/Main.java | 4 + .../gerrit/server/logging/LoggingContext.java | 78 +++++++++ .../gerrit/server/logging/MutableTags.java | 92 +++++++++++ .../gerrit/server/logging/TraceContext.java | 36 ++++ .../google/gerrit/testing/ConfigSuite.java | 3 + .../server/logging/MutableTagsTest.java | 154 ++++++++++++++++++ .../server/logging/TraceContextTest.java | 112 +++++++++++++ 7 files changed, 479 insertions(+) create mode 100644 java/com/google/gerrit/server/logging/LoggingContext.java create mode 100644 java/com/google/gerrit/server/logging/MutableTags.java create mode 100644 java/com/google/gerrit/server/logging/TraceContext.java create mode 100644 javatests/com/google/gerrit/server/logging/MutableTagsTest.java create mode 100644 javatests/com/google/gerrit/server/logging/TraceContextTest.java diff --git a/java/Main.java b/java/Main.java index f26b6dfa8c..11d8234c60 100644 --- a/java/Main.java +++ b/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; diff --git a/java/com/google/gerrit/server/logging/LoggingContext.java b/java/com/google/gerrit/server/logging/LoggingContext.java new file mode 100644 index 0000000000..c8620fa7c5 --- /dev/null +++ b/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. + * + *

To configure this logging context for Flogger set the following system property (also see + * {@link com.google.common.flogger.backend.system.DefaultPlatform}): + * + *

+ */ +public class LoggingContext extends com.google.common.flogger.backend.system.LoggingContext { + private static final LoggingContext INSTANCE = new LoggingContext(); + + private static final ThreadLocal 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; + } +} diff --git a/java/com/google/gerrit/server/logging/MutableTags.java b/java/com/google/gerrit/server/logging/MutableTags.java new file mode 100644 index 0000000000..5cf6621fff --- /dev/null +++ b/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 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(); + } +} diff --git a/java/com/google/gerrit/server/logging/TraceContext.java b/java/com/google/gerrit/server/logging/TraceContext.java new file mode 100644 index 0000000000..ad19082199 --- /dev/null +++ b/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); + } + } +} diff --git a/java/com/google/gerrit/testing/ConfigSuite.java b/java/com/google/gerrit/testing/ConfigSuite.java index b0229c3edc..ff87fd82b3 100644 --- a/java/com/google/gerrit/testing/ConfigSuite.java +++ b/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"; diff --git a/javatests/com/google/gerrit/server/logging/MutableTagsTest.java b/javatests/com/google/gerrit/server/logging/MutableTagsTest.java new file mode 100644 index 0000000000..fbe94bd2a6 --- /dev/null +++ b/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> expectedTagMap) { + SortedMap> actualTagMap = tags.getTags().asMap(); + assertThat(actualTagMap.keySet()).containsExactlyElementsIn(expectedTagMap.keySet()); + for (Map.Entry> 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); + } + } +} diff --git a/javatests/com/google/gerrit/server/logging/TraceContextTest.java b/javatests/com/google/gerrit/server/logging/TraceContextTest.java new file mode 100644 index 0000000000..04f9bef49b --- /dev/null +++ b/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> expectedTagMap) { + SortedMap> actualTagMap = + LoggingContext.getInstance().getTags().asMap(); + assertThat(actualTagMap.keySet()).containsExactlyElementsIn(expectedTagMap.keySet()); + for (Map.Entry> 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); + } + } +}