From 94176a89595a9ec8ad6acefb354d8548571fc135 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Yoann=20Rodi=C3=A8re?= Date: Tue, 10 Sep 2024 15:38:03 +0200 Subject: [PATCH] Add .debugBytecode() and .traceCategories() to QuarkusUnitTest To ease debugging of such tests. --- .../src/main/asciidoc/writing-extensions.adoc | 61 +++++++++++++- .../PublicFieldAccessInheritanceTest.java | 38 +-------- .../java/io/quarkus/test/QuarkusUnitTest.java | 81 +++++++++++++++++++ 3 files changed, 143 insertions(+), 37 deletions(-) diff --git a/docs/src/main/asciidoc/writing-extensions.adoc b/docs/src/main/asciidoc/writing-extensions.adoc index cbcc824e82bfd..f00618776c6ae 100644 --- a/docs/src/main/asciidoc/writing-extensions.adoc +++ b/docs/src/main/asciidoc/writing-extensions.adoc @@ -1983,7 +1983,7 @@ to initiate a scan for changed files. Where extensions use an external service, adding a Dev Service can improve the user experience in development and test modes. See xref:extension-writing-dev-service.adoc[how to write a Dev Service] for more details. - +[[testing-extensions]] === Testing Extensions Testing of Quarkus extensions should be done with the `io.quarkus.test.QuarkusUnitTest` JUnit 5 extension. @@ -2296,6 +2296,65 @@ The property is also honored when running tests: Analogously, you can use the `quarkus.debug.transformed-classes-dir` and `quarkus.debug.generated-sources-dir` properties to dump the relevant output. +[[dump-generated-transformed-classes-with-quarkusunittest]] +==== Inspecting Generated/Transformed Classes in `QuarkusUnitTest` + +When <>, +as an alternative to <>, +you may simply call `QuarkusUnitTest#debugBytecode`: + +[source,java] +---- +public class MyTest { + + @RegisterExtension + static QuarkusUnitTest runner = new QuarkusUnitTest() + .withApplicationRoot((jar) -> jar + .addClass(MyEntity.class)) + .debugBytecode(true); + + // ... test methods go here ... + +} +---- + +This will automatically set up these configuration properties so that classes/sources +are dumped to `target/debug`, for that test class only, +in a subdirectory that is unique to each test execution. +See the javadoc of `QuarkusUnitTest#debugBytecode` for details. + +This is handy to debug flaky tests that happen only in the CI environment, in particular; +for example the GitHub Actions CI at https://github.com/quarkusio/quarkus/ +is set up so that such `target/debug` directories are +collected into build artifacts available for download after each CI run. + +[[troubleshooting-trace-logs]] +==== Enabling trace logs for a particular test only + +When <>, +if you need to enable trace logs for a particular test class, +you may simply call `QuarkusUnitTest#traceCategories` and pass the logging categories in argument: + +[source,java] +---- +public class MyTest { + + @RegisterExtension + static QuarkusUnitTest runner = new QuarkusUnitTest() + .withApplicationRoot((jar) -> jar + .addClass(MyEntity.class)) + .traceCategories("org.hibernate", "io.quarkus.hibernate", "io.quarkus.panache"); + + // ... test methods go here ... + +} +---- + +See the javadoc of `QuarkusUnitTest#traceCategories` for details. + +This is handy to debug flaky tests that happen only in the CI environment, in particular, +as this will only increase the verbosity of logs in the particular test where the option is enabled. + ==== Multi-module Maven Projects and the Development Mode It's not uncommon to develop an extension in a multi-module Maven project that also contains an "example" module. diff --git a/extensions/hibernate-orm/deployment/src/test/java/io/quarkus/hibernate/orm/applicationfieldaccess/PublicFieldAccessInheritanceTest.java b/extensions/hibernate-orm/deployment/src/test/java/io/quarkus/hibernate/orm/applicationfieldaccess/PublicFieldAccessInheritanceTest.java index 48b07f9779c35..d94cc54faa029 100644 --- a/extensions/hibernate-orm/deployment/src/test/java/io/quarkus/hibernate/orm/applicationfieldaccess/PublicFieldAccessInheritanceTest.java +++ b/extensions/hibernate-orm/deployment/src/test/java/io/quarkus/hibernate/orm/applicationfieldaccess/PublicFieldAccessInheritanceTest.java @@ -2,11 +2,6 @@ import static org.assertj.core.api.Assertions.assertThat; -import java.util.List; -import java.util.Map; -import java.util.UUID; -import java.util.logging.LogManager; - import jakarta.inject.Inject; import jakarta.persistence.Entity; import jakarta.persistence.EntityManager; @@ -21,7 +16,6 @@ import jakarta.transaction.UserTransaction; import org.hibernate.Hibernate; -import org.jboss.logmanager.Level; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.RegisterExtension; @@ -33,19 +27,6 @@ */ public class PublicFieldAccessInheritanceTest { - // FIXME Temporary debug options for https://github.com/quarkusio/quarkus/issues/42479 - // Needs to be set very early (e.g. as system properties) in order to affect the build; - // see https://quarkusio.zulipchat.com/#narrow/stream/187038-dev/topic/Build.20logs - private static final Map DEBUG_PROPERTIES = Map.of( - "quarkus.debug.transformed-classes-dir", "target/debug/${testRunId}/transformed-classes", - "quarkus.debug.generated-classes-dir", "target/debug/${testRunId}/generated-classes"); - // FIXME Temporary trace categories for https://github.com/quarkusio/quarkus/issues/42479 - // Needs to be set very early (e.g. programmatically) in order to affect the build; - // needs to be set programmatically in order to not leak to other tests. - // See https://quarkusio.zulipchat.com/#narrow/stream/187038-dev/topic/Build.20logs - // See https://github.com/quarkusio/quarkus/issues/43180 - private static final List TRACE_CATEGORIES = List.of("org.hibernate", "io.quarkus.hibernate", "io.quarkus.panache"); - @RegisterExtension static QuarkusUnitTest runner = new QuarkusUnitTest() .withApplicationRoot((jar) -> jar @@ -61,23 +42,8 @@ public class PublicFieldAccessInheritanceTest { // It's not necessary anyway as the only effect of this config property is to change // the logging level for a specific "org.hibernate.something" category, which we already do below. //.overrideConfigKey("quarkus.hibernate-orm.log.bind-parameters", "true") - .setBeforeAllCustomizer(() -> { - // Used to differentiate reruns of flaky tests in Maven - var testRunId = PublicFieldAccessInheritanceTest.class + "/" + UUID.randomUUID(); - System.out.println("Test run ID: " + testRunId); - DEBUG_PROPERTIES.forEach((key, value) -> System.setProperty(key, value.replace("${testRunId}", testRunId))); - for (String category : TRACE_CATEGORIES) { - LogManager.getLogManager().getLogger(category) - .setLevel(Level.TRACE); - } - }) - .setAfterAllCustomizer(() -> { - DEBUG_PROPERTIES.keySet().forEach(System::clearProperty); - for (String category : TRACE_CATEGORIES) { - LogManager.getLogManager().getLogger(category) - .setLevel(null); - } - }); + .debugBytecode(true) + .traceCategories("org.hibernate", "io.quarkus.hibernate", "io.quarkus.panache"); @Inject EntityManager em; diff --git a/test-framework/junit5-internal/src/main/java/io/quarkus/test/QuarkusUnitTest.java b/test-framework/junit5-internal/src/main/java/io/quarkus/test/QuarkusUnitTest.java index 3e0b9bb4d5747..3cbd7970eba85 100644 --- a/test-framework/junit5-internal/src/main/java/io/quarkus/test/QuarkusUnitTest.java +++ b/test-framework/junit5-internal/src/main/java/io/quarkus/test/QuarkusUnitTest.java @@ -27,6 +27,7 @@ import java.util.ServiceLoader; import java.util.Timer; import java.util.TimerTask; +import java.util.UUID; import java.util.function.Consumer; import java.util.function.Predicate; import java.util.function.Supplier; @@ -34,6 +35,7 @@ import java.util.logging.LogManager; import java.util.logging.LogRecord; +import org.jboss.logmanager.Level; import org.jboss.logmanager.Logger; import org.jboss.shrinkwrap.api.ShrinkWrap; import org.jboss.shrinkwrap.api.exporter.ExplodedExporter; @@ -137,6 +139,12 @@ public class QuarkusUnitTest private List> bootstrapCustomizers = new ArrayList<>(); + private boolean debugBytecode = false; + private List traceCategories = new ArrayList<>(); + + private Map systemPropertiesToRestore = new HashMap<>(); + private Map loggerLevelsToRestore = new HashMap<>(); + public QuarkusUnitTest setExpectedException(Class expectedException) { return setExpectedException(expectedException, false); } @@ -514,6 +522,25 @@ public void beforeAll(ExtensionContext extensionContext) throws Exception { if (beforeAllCustomizer != null) { beforeAllCustomizer.run(); } + if (debugBytecode) { + // Use a unique ID to avoid overriding dumps between test classes (and re-execution of flaky tests). + var testRunId = extensionContext.getRequiredTestClass().getName() + "/" + UUID.randomUUID(); + System.out.println("[QuarkusUnitTest] Debug dumps enabled. Test run ID: " + testRunId); + // This needs to be set as system properties; see BootstrapDebug.java. + // Note these paths are considered standard and may be taken advantage of in Quarkus CI (to collect dumps). + overrideSystemProperty("quarkus.debug.transformed-classes-dir", + "target/debug/" + testRunId + "/transformed-classes"); + overrideSystemProperty("quarkus.debug.generated-classes-dir", "target/debug/" + testRunId + "/generated-classes"); + overrideSystemProperty("quarkus.debug.generated-sources-dir", "target/debug/" + testRunId + "/generated-sources"); + } + if (!traceCategories.isEmpty()) { + // This needs to be set very early (e.g. as system properties) in order to affect the build; + // needs to be set programmatically in order to not leak to other tests (for some reason?). + // See https://quarkusio.zulipchat.com/#narrow/stream/187038-dev/topic/Build.20logs + for (String category : traceCategories) { + overrideLoggerLevel(category, Level.TRACE); + } + } originalClassLoader = Thread.currentThread().getContextClassLoader(); originalHandlers = rootLogger.getHandlers(); rootLogger.addHandler(inMemoryLogHandler); @@ -718,6 +745,20 @@ private Throwable unwrapException(Throwable cause) { return cause; } + private void overrideSystemProperty(String key, String value) { + // IMPORTANT: Not logging the value in case it's a secret. + System.out.printf("[QuarkusUnitTest] Overriding system property '%s'%n", key); + systemPropertiesToRestore.putIfAbsent(key, System.getProperty(key)); + System.setProperty(key, value); + } + + private void overrideLoggerLevel(String category, Level level) { + System.out.printf("[QuarkusUnitTest] Overriding logger category '%s'; setting level '%s'%n", category, level); + var logger = LogManager.getLogManager().getLogger(category); + loggerLevelsToRestore.putIfAbsent(category, logger.getLevel()); + logger.setLevel(level); + } + @Override public void afterAll(ExtensionContext extensionContext) throws Exception { actualTestClass = null; @@ -764,6 +805,16 @@ public void afterAll(ExtensionContext extensionContext) throws Exception { if (afterAllCustomizer != null) { afterAllCustomizer.run(); } + systemPropertiesToRestore.forEach((key, previousValue) -> { + if (previousValue == null) { + System.clearProperty(key); + } else { + System.setProperty(key, previousValue); + } + }); + systemPropertiesToRestore.clear(); + loggerLevelsToRestore.forEach((category, previousLevel) -> Logger.getLogger(category).setLevel(previousLevel)); + loggerLevelsToRestore.clear(); ClearCache.clearCaches(); TestConfigUtil.cleanUp(); } @@ -850,6 +901,36 @@ public QuarkusUnitTest overrideRuntimeConfigKey(final String propertyKey, final return this; } + /** + * Controls bytecode-related debug dumping. + *

+ * When enabled, each Quarkus startup will have configuration properties + * such as {@code quarkus.debug.generated-classes-dir} set + * so that generated code gets dumped in {@code target/debug}, + * within a unique subdirectory for each test execution. + *

+ * Look at the logs of a particular test to identify the corresponding dump directory. + * + * @param debugBytecode {@code true} if debug should be enabled + * @return {@code this}, for method chaining. + */ + public QuarkusUnitTest debugBytecode(boolean debugBytecode) { + this.debugBytecode = debugBytecode; + return this; + } + + /** + * Enables trace logs for the given categories, + * during both build and runtime. + * + * @param categories The categories for which to enable trace logging. + * @return {@code this}, for method chaining. + */ + public QuarkusUnitTest traceCategories(String... categories) { + Collections.addAll(this.traceCategories, categories); + return this; + } + @Override public boolean supportsParameter(ParameterContext parameterContext, ExtensionContext extensionContext) throws ParameterResolutionException {