Log warning when LoggingContext of background thread is not initially empty
When we execute work in a background thread we copy the logging context
to it and unset it before we return it to the thread pool. If we get a
thread from the pool that has a non-empty logging context this is
unexpected and we want to know about it.
Also add a clear() method to LoggingContext to make unsetting the
logging context easier.
Signed-off-by: Edwin Kempin <ekempin@google.com>
Change-Id: Ic40ce525f5f4508fe4eb56d78a704256a98b8e0c
diff --git a/java/com/google/gerrit/server/logging/LoggingContext.java b/java/com/google/gerrit/server/logging/LoggingContext.java
index deb111a..7f5cee3 100644
--- a/java/com/google/gerrit/server/logging/LoggingContext.java
+++ b/java/com/google/gerrit/server/logging/LoggingContext.java
@@ -16,6 +16,7 @@
import static java.util.Objects.requireNonNull;
+import com.google.common.base.MoreObjects;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.ImmutableSetMultimap;
import com.google.common.flogger.backend.Tags;
@@ -79,6 +80,20 @@
callable, getInstance().getMutablePerformanceLogRecords());
}
+ public boolean isEmpty() {
+ return tags.get() == null
+ && forceLogging.get() == null
+ && performanceLogging.get() == null
+ && performanceLogRecords == null;
+ }
+
+ public void clear() {
+ tags.remove();
+ forceLogging.remove();
+ performanceLogging.remove();
+ performanceLogRecords.remove();
+ }
+
@Override
public boolean shouldForceLogging(String loggerName, Level level, boolean isEnabled) {
return isLoggingForced();
@@ -241,4 +256,14 @@
}
return records;
}
+
+ @Override
+ public String toString() {
+ return MoreObjects.toStringHelper(this)
+ .add("tags", tags.get())
+ .add("forceLogging", forceLogging.get())
+ .add("performanceLogging", performanceLogging.get())
+ .add("performanceLogRecords", performanceLogRecords.get())
+ .toString();
+ }
}
diff --git a/java/com/google/gerrit/server/logging/LoggingContextAwareCallable.java b/java/com/google/gerrit/server/logging/LoggingContextAwareCallable.java
index 63a1f88..d2701d7 100644
--- a/java/com/google/gerrit/server/logging/LoggingContextAwareCallable.java
+++ b/java/com/google/gerrit/server/logging/LoggingContextAwareCallable.java
@@ -15,6 +15,7 @@
package com.google.gerrit.server.logging;
import com.google.common.collect.ImmutableSetMultimap;
+import com.google.common.flogger.FluentLogger;
import java.util.concurrent.Callable;
/**
@@ -31,6 +32,8 @@
* @see LoggingContextAwareRunnable
*/
class LoggingContextAwareCallable<T> implements Callable<T> {
+ private static final FluentLogger logger = FluentLogger.forEnclosingClass();
+
private final Callable<T> callable;
private final Thread callingThread;
private final ImmutableSetMultimap<String, String> tags;
@@ -62,8 +65,13 @@
return callable.call();
}
- // propagate logging context
LoggingContext loggingCtx = LoggingContext.getInstance();
+
+ if (!loggingCtx.isEmpty()) {
+ logger.atWarning().log("Logging context is not empty: %s", loggingCtx);
+ }
+
+ // propagate logging context
loggingCtx.setTags(tags);
loggingCtx.forceLogging(forceLogging);
loggingCtx.performanceLogging(performanceLogging);
@@ -79,10 +87,7 @@
return callable.call();
} finally {
// Cleanup logging context. This is important if the thread is pooled and reused.
- loggingCtx.clearTags();
- loggingCtx.forceLogging(false);
- loggingCtx.performanceLogging(false);
- loggingCtx.clearPerformanceLogEntries();
+ loggingCtx.clear();
}
}
}
diff --git a/java/com/google/gerrit/server/logging/LoggingContextAwareRunnable.java b/java/com/google/gerrit/server/logging/LoggingContextAwareRunnable.java
index 9d9e8c5..23162b1 100644
--- a/java/com/google/gerrit/server/logging/LoggingContextAwareRunnable.java
+++ b/java/com/google/gerrit/server/logging/LoggingContextAwareRunnable.java
@@ -15,6 +15,7 @@
package com.google.gerrit.server.logging;
import com.google.common.collect.ImmutableSetMultimap;
+import com.google.common.flogger.FluentLogger;
/**
* Wrapper for a {@link Runnable} that copies the {@link LoggingContext} from the current thread to
@@ -49,6 +50,8 @@
* @see LoggingContextAwareCallable
*/
public class LoggingContextAwareRunnable implements Runnable {
+ private static final FluentLogger logger = FluentLogger.forEnclosingClass();
+
private final Runnable runnable;
private final Thread callingThread;
private final ImmutableSetMultimap<String, String> tags;
@@ -85,8 +88,13 @@
return;
}
- // propagate logging context
LoggingContext loggingCtx = LoggingContext.getInstance();
+
+ if (!loggingCtx.isEmpty()) {
+ logger.atWarning().log("Logging context is not empty: %s", loggingCtx);
+ }
+
+ // propagate logging context
loggingCtx.setTags(tags);
loggingCtx.forceLogging(forceLogging);
loggingCtx.performanceLogging(performanceLogging);
@@ -102,10 +110,7 @@
runnable.run();
} finally {
// Cleanup logging context. This is important if the thread is pooled and reused.
- loggingCtx.clearTags();
- loggingCtx.forceLogging(false);
- loggingCtx.performanceLogging(false);
- loggingCtx.clearPerformanceLogEntries();
+ loggingCtx.clear();
}
}
}
diff --git a/java/com/google/gerrit/server/logging/MutablePerformanceLogRecords.java b/java/com/google/gerrit/server/logging/MutablePerformanceLogRecords.java
index 02143f0..4ee70d7 100644
--- a/java/com/google/gerrit/server/logging/MutablePerformanceLogRecords.java
+++ b/java/com/google/gerrit/server/logging/MutablePerformanceLogRecords.java
@@ -14,6 +14,7 @@
package com.google.gerrit.server.logging;
+import com.google.common.base.MoreObjects;
import com.google.common.collect.ImmutableList;
import java.util.ArrayList;
import java.util.List;
@@ -44,4 +45,11 @@
public synchronized ImmutableList<PerformanceLogRecord> list() {
return ImmutableList.copyOf(performanceLogRecords);
}
+
+ @Override
+ public String toString() {
+ return MoreObjects.toStringHelper(this)
+ .add("performanceLogRecords", performanceLogRecords)
+ .toString();
+ }
}
diff --git a/java/com/google/gerrit/server/logging/MutableTags.java b/java/com/google/gerrit/server/logging/MutableTags.java
index f70a8db..83009a6 100644
--- a/java/com/google/gerrit/server/logging/MutableTags.java
+++ b/java/com/google/gerrit/server/logging/MutableTags.java
@@ -16,6 +16,7 @@
import static java.util.Objects.requireNonNull;
+import com.google.common.base.MoreObjects;
import com.google.common.collect.ImmutableSetMultimap;
import com.google.common.collect.MultimapBuilder;
import com.google.common.collect.SetMultimap;
@@ -110,4 +111,10 @@
tagMap.forEach(tagsBuilder::addTag);
tags = tagsBuilder.build();
}
+
+ @Override
+ public String toString() {
+ buildTags();
+ return MoreObjects.toStringHelper(this).add("tags", tags).toString();
+ }
}
