Add a testing-internal module and functionality to SuppressLogger for… (open-telemetry#4130)

anuraaga · web-flow · commit 03c41ec94043 · 2022-02-01T16:04:39.000+09:00
* Improve behavior of some tests (open-telemetry#4123) * Optimize * Fix logging.properties * Clean
diff --git a/buildSrc/src/main/kotlin/otel.java-conventions.gradle.kts b/buildSrc/src/main/kotlin/otel.java-conventions.gradle.kts
@@ -196,11 +196,23 @@ dependencies {
   compileOnly("javax.annotation:javax.annotation-api")
 }
 
+class TestArgumentsProvider(
+  @InputFile
+  @PathSensitive(PathSensitivity.RELATIVE)
+  val loggingProperties: File,
+) : CommandLineArgumentProvider {
+  override fun asArguments() = listOf(
+    "-Djava.util.logging.config.file=${loggingProperties.absolutePath}",
+  )
+}
+
 testing {
   suites.withType(JvmTestSuite::class).configureEach {
     dependencies {
       implementation(project)
 
+      implementation(project(":testing-internal"))
+
       compileOnly("com.google.auto.value:auto-value-annotations")
       compileOnly("com.google.errorprone:error_prone_annotations")
       compileOnly("com.google.code.findbugs:jsr305")
@@ -216,5 +228,14 @@ testing {
 
       runtimeOnly("org.junit.jupiter:junit-jupiter-engine")
     }
+
+    targets {
+      all {
+        testTask.configure {
+          jvmArgumentProviders.add(TestArgumentsProvider(rootProject.file("buildscripts/test-logging.properties")))
+          systemProperty("org.slf4j.simpleLogger.defaultLogLevel", "warn")
+        }
+      }
+    }
   }
 }
diff --git a/buildscripts/test-logging.properties b/buildscripts/test-logging.properties
@@ -0,0 +1,7 @@
+handlers= java.util.logging.ConsoleHandler
+.level = INFO
+java.util.logging.ConsoleHandler.level = INFO
+java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter
+
+org.junit.platform.launcher.core.LauncherConfigurationParameters.level = WARNING
+org.junit.jupiter.engine.config.EnumConfigurationParameterConverter.level = WARNING
diff --git a/exporters/logging-otlp/src/test/java/io/opentelemetry/exporter/logging/otlp/OtlpJsonLoggingLogExporterTest.java b/exporters/logging-otlp/src/test/java/io/opentelemetry/exporter/logging/otlp/OtlpJsonLoggingLogExporterTest.java
@@ -15,6 +15,7 @@
 import io.opentelemetry.api.trace.SpanContext;
 import io.opentelemetry.api.trace.TraceFlags;
 import io.opentelemetry.api.trace.TraceState;
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.common.InstrumentationLibraryInfo;
 import io.opentelemetry.sdk.logs.data.LogData;
 import io.opentelemetry.sdk.logs.data.LogDataBuilder;
@@ -29,6 +30,7 @@
 import org.skyscreamer.jsonassert.JSONAssert;
 import org.slf4j.event.Level;
 
+@SuppressLogger(OtlpJsonLoggingLogExporter.class)
 class OtlpJsonLoggingLogExporterTest {
 
   private static final Resource RESOURCE =
diff --git a/exporters/logging-otlp/src/test/java/io/opentelemetry/exporter/logging/otlp/OtlpJsonLoggingMetricExporterTest.java b/exporters/logging-otlp/src/test/java/io/opentelemetry/exporter/logging/otlp/OtlpJsonLoggingMetricExporterTest.java
@@ -10,6 +10,7 @@
 
 import io.github.netmikey.logunit.api.LogCapturer;
 import io.opentelemetry.api.common.Attributes;
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.common.InstrumentationLibraryInfo;
 import io.opentelemetry.sdk.metrics.data.AggregationTemporality;
 import io.opentelemetry.sdk.metrics.data.DoublePointData;
@@ -24,6 +25,7 @@
 import org.skyscreamer.jsonassert.JSONAssert;
 import org.slf4j.event.Level;
 
+@SuppressLogger(OtlpJsonLoggingMetricExporter.class)
 class OtlpJsonLoggingMetricExporterTest {
 
   private static final Resource RESOURCE =
diff --git a/exporters/logging-otlp/src/test/java/io/opentelemetry/exporter/logging/otlp/OtlpJsonLoggingSpanExporterTest.java b/exporters/logging-otlp/src/test/java/io/opentelemetry/exporter/logging/otlp/OtlpJsonLoggingSpanExporterTest.java
@@ -16,6 +16,7 @@
 import io.opentelemetry.api.trace.SpanKind;
 import io.opentelemetry.api.trace.TraceFlags;
 import io.opentelemetry.api.trace.TraceState;
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.common.InstrumentationLibraryInfo;
 import io.opentelemetry.sdk.resources.Resource;
 import io.opentelemetry.sdk.testing.trace.TestSpanData;
@@ -31,6 +32,7 @@
 import org.skyscreamer.jsonassert.JSONAssert;
 import org.slf4j.event.Level;
 
+@SuppressLogger(OtlpJsonLoggingSpanExporter.class)
 class OtlpJsonLoggingSpanExporterTest {
 
   private static final Resource RESOURCE =
diff --git a/exporters/logging/src/test/java/io/opentelemetry/exporter/logging/LoggingMetricExporterTest.java b/exporters/logging/src/test/java/io/opentelemetry/exporter/logging/LoggingMetricExporterTest.java
@@ -9,6 +9,7 @@
 import static org.assertj.core.api.Assertions.assertThat;
 
 import io.opentelemetry.api.common.Attributes;
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.common.InstrumentationLibraryInfo;
 import io.opentelemetry.sdk.metrics.data.AggregationTemporality;
 import io.opentelemetry.sdk.metrics.data.DoublePointData;
@@ -32,7 +33,7 @@
 import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
 
-/** Tests for the {@link LoggingMetricExporter}. */
+@SuppressLogger(LoggingMetricExporter.class)
 class LoggingMetricExporterTest {
 
   LoggingMetricExporter exporter;
diff --git a/exporters/logging/src/test/java/io/opentelemetry/exporter/logging/LoggingSpanExporterTest.java b/exporters/logging/src/test/java/io/opentelemetry/exporter/logging/LoggingSpanExporterTest.java
@@ -17,6 +17,7 @@
 import io.opentelemetry.api.trace.SpanKind;
 import io.opentelemetry.api.trace.TraceFlags;
 import io.opentelemetry.api.trace.TraceState;
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.common.CompletableResultCode;
 import io.opentelemetry.sdk.common.InstrumentationLibraryInfo;
 import io.opentelemetry.sdk.testing.trace.TestSpanData;
@@ -38,7 +39,7 @@
 import org.junit.jupiter.api.extension.RegisterExtension;
 import org.slf4j.event.Level;
 
-/** Tests for the {@link LoggingSpanExporter}. */
+@SuppressLogger(LoggingSpanExporter.class)
 class LoggingSpanExporterTest {
 
   private static final SpanData SPAN1 =
diff --git a/exporters/zipkin/src/test/java/io/opentelemetry/exporter/zipkin/ZipkinSpanExporterTest.java b/exporters/zipkin/src/test/java/io/opentelemetry/exporter/zipkin/ZipkinSpanExporterTest.java
@@ -26,6 +26,7 @@
 import io.opentelemetry.api.trace.StatusCode;
 import io.opentelemetry.api.trace.TraceFlags;
 import io.opentelemetry.api.trace.TraceState;
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.common.CompletableResultCode;
 import io.opentelemetry.sdk.common.InstrumentationLibraryInfo;
 import io.opentelemetry.sdk.resources.Resource;
@@ -354,6 +355,7 @@ void testExport() {
   }
 
   @Test
+  @SuppressLogger(ZipkinSpanExporter.class)
   void testExport_failed() {
     ZipkinSpanExporter zipkinSpanExporter = new ZipkinSpanExporter(mockEncoder, mockSender);
 
diff --git a/sdk-extensions/aws/src/test/java/io/opentelemetry/sdk/extension/aws/resource/Ec2ResourceTest.java b/sdk-extensions/aws/src/test/java/io/opentelemetry/sdk/extension/aws/resource/Ec2ResourceTest.java
@@ -14,6 +14,7 @@
 import com.linecorp.armeria.common.MediaType;
 import com.linecorp.armeria.testing.junit5.server.mock.MockWebServerExtension;
 import io.opentelemetry.api.common.Attributes;
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.autoconfigure.spi.ResourceProvider;
 import io.opentelemetry.sdk.resources.Resource;
 import io.opentelemetry.semconv.resource.attributes.ResourceAttributes;
@@ -112,6 +113,7 @@ void imdsv1() {
   }
 
   @Test
+  @SuppressLogger(Ec2Resource.class)
   void badJson() {
     server.enqueue(HttpResponse.of(HttpStatus.NOT_FOUND));
     server.enqueue(HttpResponse.of(MediaType.JSON_UTF_8, "I'm not JSON"));
diff --git a/sdk-extensions/zpages/src/test/java/io/opentelemetry/sdk/extension/zpages/TraceConfigzZPageHandlerTest.java b/sdk-extensions/zpages/src/test/java/io/opentelemetry/sdk/extension/zpages/TraceConfigzZPageHandlerTest.java
@@ -8,6 +8,7 @@
 import static org.assertj.core.api.Assertions.assertThat;
 
 import com.google.common.collect.ImmutableMap;
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.trace.SpanLimits;
 import io.opentelemetry.sdk.trace.samplers.Sampler;
 import java.io.ByteArrayOutputStream;
@@ -199,6 +200,7 @@ void appliesChangesCorrectly_doNotCrashOnNullParameters() {
   }
 
   @Test
+  @SuppressLogger(TraceConfigzZPageHandler.class)
   void applyChanges_emitErrorOnInvalidInput() {
     // Invalid samplingProbability (not type of double)
     OutputStream output = new ByteArrayOutputStream();
diff --git a/sdk/all/src/test/resources/mockito-extensions/org.mockito.plugins.MockMaker b/sdk/all/src/test/resources/mockito-extensions/org.mockito.plugins.MockMaker
diff --git a/sdk/common/src/test/java/io/opentelemetry/sdk/internal/ThrottlingLoggerTest.java b/sdk/common/src/test/java/io/opentelemetry/sdk/internal/ThrottlingLoggerTest.java
@@ -11,6 +11,7 @@
 import static org.slf4j.event.Level.WARN;
 
 import io.github.netmikey.logunit.api.LogCapturer;
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.common.Clock;
 import io.opentelemetry.sdk.testing.time.TestClock;
 import java.time.Duration;
@@ -19,6 +20,7 @@
 import org.junit.jupiter.api.Test;
 import org.junit.jupiter.api.extension.RegisterExtension;
 
+@SuppressLogger(ThrottlingLoggerTest.class)
 class ThrottlingLoggerTest {
 
   private static final Logger realLogger = Logger.getLogger(ThrottlingLoggerTest.class.getName());
diff --git a/sdk/logs/src/test/resources/mockito-extensions/org.mockito.plugins.MockMaker b/sdk/logs/src/test/resources/mockito-extensions/org.mockito.plugins.MockMaker
diff --git a/sdk/metrics/src/test/java/io/opentelemetry/sdk/metrics/SdkMeterTest.java b/sdk/metrics/src/test/java/io/opentelemetry/sdk/metrics/SdkMeterTest.java
@@ -16,11 +16,13 @@
 import io.opentelemetry.api.metrics.LongHistogram;
 import io.opentelemetry.api.metrics.LongUpDownCounter;
 import io.opentelemetry.api.metrics.Meter;
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.metrics.internal.state.MeterSharedState;
 import io.opentelemetry.sdk.testing.exporter.InMemoryMetricReader;
 import org.junit.jupiter.api.Test;
 import org.junit.jupiter.api.extension.RegisterExtension;
 
+@SuppressLogger(MeterSharedState.class)
 class SdkMeterTest {
   // Meter must have an exporter configured to actual run.
   private final SdkMeterProvider testMeterProvider =
diff --git a/sdk/metrics/src/test/java/io/opentelemetry/sdk/metrics/export/PeriodicMetricReaderTest.java b/sdk/metrics/src/test/java/io/opentelemetry/sdk/metrics/export/PeriodicMetricReaderTest.java
@@ -15,6 +15,7 @@
 import static org.mockito.Mockito.when;
 
 import io.opentelemetry.api.common.Attributes;
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.common.CompletableResultCode;
 import io.opentelemetry.sdk.common.InstrumentationLibraryInfo;
 import io.opentelemetry.sdk.metrics.data.AggregationTemporality;
@@ -129,6 +130,7 @@ void flush() throws Exception {
 
   @Test
   @Timeout(2)
+  @SuppressLogger(PeriodicMetricReader.class)
   public void intervalExport_exporterThrowsException() throws Exception {
     WaitingMetricExporter waitingMetricExporter = new WaitingMetricExporter(/* shouldThrow=*/ true);
     MetricReaderFactory factory =
diff --git a/sdk/metrics/src/test/java/io/opentelemetry/sdk/metrics/internal/state/AsynchronousMetricStorageTest.java b/sdk/metrics/src/test/java/io/opentelemetry/sdk/metrics/internal/state/AsynchronousMetricStorageTest.java
@@ -10,6 +10,7 @@
 import io.github.netmikey.logunit.api.LogCapturer;
 import io.opentelemetry.api.common.Attributes;
 import io.opentelemetry.context.Context;
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.common.InstrumentationLibraryInfo;
 import io.opentelemetry.sdk.metrics.common.InstrumentType;
 import io.opentelemetry.sdk.metrics.common.InstrumentValueType;
@@ -162,6 +163,7 @@ void collectAndReset_IgnoresDuplicates() {
   }
 
   @Test
+  @SuppressLogger(AsynchronousMetricStorage.class)
   void collectAndReset_CallbackException() {
     MetricStorage metricStorage =
         AsynchronousMetricStorage.longAsynchronousAccumulator(
diff --git a/sdk/trace/src/test/java/io/opentelemetry/sdk/trace/export/MultiSpanExporterTest.java b/sdk/trace/src/test/java/io/opentelemetry/sdk/trace/export/MultiSpanExporterTest.java
@@ -9,6 +9,7 @@
 import static org.mockito.ArgumentMatchers.same;
 import static org.mockito.Mockito.when;
 
+import io.opentelemetry.internal.testing.slf4j.SuppressLogger;
 import io.opentelemetry.sdk.common.CompletableResultCode;
 import io.opentelemetry.sdk.trace.TestUtils;
 import io.opentelemetry.sdk.trace.data.SpanData;
@@ -104,6 +105,7 @@ void twoSpanExporter_OneReturnFailure() {
   }
 
   @Test
+  @SuppressLogger(MultiSpanExporter.class)
   void twoSpanExporter_FirstThrows() {
     SpanExporter multiSpanExporter =
         SpanExporter.composite(Arrays.asList(spanExporter1, spanExporter2));
diff --git a/sdk/trace/src/test/java/io/opentelemetry/sdk/trace/export/SimpleSpanProcessorTest.java b/sdk/trace/src/test/java/io/opentelemetry/sdk/trace/export/SimpleSpanProcessorTest.java
@@ -8,6 +8,7 @@
 import static org.assertj.core.api.Assertions.assertThat;
 import static org.assertj.core.api.Assertions.assertThatThrownBy;
 import static org.mockito.ArgumentMatchers.any;
+import static org.mockito.ArgumentMatchers.anyCollection;
 import static org.mockito.ArgumentMatchers.anyList;
 import static org.mockito.Mockito.never;
 import static org.mockito.Mockito.times;
@@ -65,6 +66,7 @@ class SimpleSpanProcessorTest {
   @BeforeEach
   void setUp() {
     simpleSampledSpansProcessor = SimpleSpanProcessor.create(spanExporter);
+    when(spanExporter.export(anyCollection())).thenReturn(CompletableResultCode.ofSuccess());
     when(spanExporter.shutdown()).thenReturn(CompletableResultCode.ofSuccess());
   }
 
diff --git a/settings.gradle.kts b/settings.gradle.kts
@@ -74,6 +74,7 @@ include(":sdk-extensions:tracing-incubator")
 include(":sdk-extensions:jaeger-remote-sampler")
 include(":sdk-extensions:jfr-events")
 include(":sdk-extensions:zpages")
+include(":testing-internal")
 
 val isCI = System.getenv("CI") != null
 gradleEnterprise {
diff --git a/testing-internal/build.gradle.kts b/testing-internal/build.gradle.kts
@@ -0,0 +1,10 @@
+plugins {
+  id("otel.java-conventions")
+}
+
+description = "OpenTelemetry Testing (Internal)"
+otelJava.moduleName.set("io.opentelemetry.internal.testing")
+
+dependencies {
+  api("org.junit.jupiter:junit-jupiter-api")
+}
diff --git a/testing-internal/src/main/java/io/opentelemetry/internal/testing/slf4j/LoggerExtension.java b/testing-internal/src/main/java/io/opentelemetry/internal/testing/slf4j/LoggerExtension.java
@@ -0,0 +1,56 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.internal.testing.slf4j;
+
+import java.util.Arrays;
+import java.util.List;
+import java.util.logging.Logger;
+import java.util.stream.Collectors;
+import java.util.stream.Stream;
+import org.junit.jupiter.api.extension.AfterTestExecutionCallback;
+import org.junit.jupiter.api.extension.BeforeTestExecutionCallback;
+import org.junit.jupiter.api.extension.ExtensionContext;
+
+/**
+ * JUnit5 extension to enable the {@link SuppressLogger} annotation which can suppress output of log
+ * messages during test execution, i.e. when the log messages are expected.
+ */
+public final class LoggerExtension
+    implements BeforeTestExecutionCallback, AfterTestExecutionCallback {
+
+  private static final ExtensionContext.Namespace NAMESPACE =
+      ExtensionContext.Namespace.create(LoggerExtension.class);
+
+  @Override
+  public void beforeTestExecution(ExtensionContext context) {
+    List<Logger> loggers =
+        Stream.concat(
+                Arrays.stream(
+                    context.getRequiredTestMethod().getAnnotationsByType(SuppressLogger.class)),
+                Arrays.stream(
+                    context.getRequiredTestClass().getAnnotationsByType(SuppressLogger.class)))
+            .map(suppression -> Logger.getLogger(suppression.value().getName()))
+            .collect(Collectors.toList());
+    if (loggers.isEmpty()) {
+      return;
+    }
+
+    loggers.forEach(logger -> logger.setUseParentHandlers(false));
+    context
+        .getStore(NAMESPACE)
+        .put(
+            LoggerExtension.class,
+            (Runnable) () -> loggers.forEach(logger -> logger.setUseParentHandlers(true)));
+  }
+
+  @Override
+  public void afterTestExecution(ExtensionContext context) {
+    Runnable restore = context.getStore(NAMESPACE).get(LoggerExtension.class, Runnable.class);
+    if (restore != null) {
+      restore.run();
+    }
+  }
+}
diff --git a/testing-internal/src/main/java/io/opentelemetry/internal/testing/slf4j/SuppressLogger.java b/testing-internal/src/main/java/io/opentelemetry/internal/testing/slf4j/SuppressLogger.java
@@ -0,0 +1,26 @@
+/*
+ * Copyright The OpenTelemetry Authors
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+package io.opentelemetry.internal.testing.slf4j;
+
+import java.lang.annotation.Repeatable;
+import java.lang.annotation.Retention;
+import java.lang.annotation.RetentionPolicy;
+
+/**
+ * Suppresses console output of the named {@link java.util.logging.Logger}. This can be added on
+ * either a test method or a test class, and log messages within that scope will be suppressed.
+ */
+@Retention(RetentionPolicy.RUNTIME)
+@Repeatable(SuppressLogger.SuppressLoggers.class)
+public @interface SuppressLogger {
+  /** The class whose {@link java.util.logging.Logger} will be suppressed. */
+  Class<?> value();
+
+  @Retention(RetentionPolicy.RUNTIME)
+  @interface SuppressLoggers {
+    SuppressLogger[] value();
+  }
+}
diff --git a/testing-internal/src/main/resources/META-INF/services/org.junit.jupiter.api.extension.Extension b/testing-internal/src/main/resources/META-INF/services/org.junit.jupiter.api.extension.Extension
@@ -0,0 +1 @@
+io.opentelemetry.internal.testing.slf4j.LoggerExtension
diff --git a/testing-internal/src/main/resources/junit-platform.properties b/testing-internal/src/main/resources/junit-platform.properties
@@ -0,0 +1 @@
+junit.jupiter.extensions.autodetection.enabled = true
diff --git a/testing-internal/src/main/resources/mockito-extensions/org.mockito.plugins.MockMaker b/testing-internal/src/main/resources/mockito-extensions/org.mockito.plugins.MockMaker
