Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add .debugBytecode() and .traceCategories() to QuarkusUnitTest #43077

Merged
merged 1 commit into from
Sep 13, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
61 changes: 60 additions & 1 deletion docs/src/main/asciidoc/writing-extensions.adoc
Original file line number Diff line number Diff line change
Expand Up @@ -1983,7 +1983,7 @@
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.
Expand Down Expand Up @@ -2294,11 +2294,70 @@
./mvnw clean test -Dquarkus.debug.generated-classes-dir=target/dump-generated-classes
----

Analogously, you can use the `quarkus.debug.transformed-classes-dir` and `quarkus.debug.generated-sources-dir` properties to dump the relevant output.

Check warning on line 2297 in docs/src/main/asciidoc/writing-extensions.adoc

View workflow job for this annotation

GitHub Actions / Linting with Vale

[vale] reported by reviewdog 🐶 [Quarkus.Headings] Use sentence-style capitalization in '2.18.2. Inspecting Generated/Transformed Classes in'. Raw Output: {"message": "[Quarkus.Headings] Use sentence-style capitalization in '2.18.2. Inspecting Generated/Transformed Classes in'.", "location": {"path": "docs/src/main/asciidoc/writing-extensions.adoc", "range": {"start": {"line": 2297, "column": 84}}}, "severity": "INFO"}

[[dump-generated-transformed-classes-with-quarkusunittest]]
==== Inspecting Generated/Transformed Classes in `QuarkusUnitTest`

When <<testing-extensions,using `QuarkusUnitTest`>>,

Check warning on line 2302 in docs/src/main/asciidoc/writing-extensions.adoc

View workflow job for this annotation

GitHub Actions / Linting with Vale

[vale] reported by reviewdog 🐶 [Quarkus.TermsWarnings] Consider using 'might (for possibility)' or 'can (for ability)' rather than 'may' unless updating existing content that uses the term. Raw Output: {"message": "[Quarkus.TermsWarnings] Consider using 'might (for possibility)' or 'can (for ability)' rather than 'may' unless updating existing content that uses the term.", "location": {"path": "docs/src/main/asciidoc/writing-extensions.adoc", "range": {"start": {"line": 2302, "column": 8}}}, "severity": "WARNING"}
as an alternative to <<dump-the-generated-classes-to-the-file-system,setting `quarkus.debug.*-dir` manually>>,
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,

Check warning on line 2322 in docs/src/main/asciidoc/writing-extensions.adoc

View workflow job for this annotation

GitHub Actions / Linting with Vale

[vale] reported by reviewdog 🐶 [Quarkus.SentenceLength] Try to keep sentences to an average of 32 words or fewer. Raw Output: {"message": "[Quarkus.SentenceLength] Try to keep sentences to an average of 32 words or fewer.", "location": {"path": "docs/src/main/asciidoc/writing-extensions.adoc", "range": {"start": {"line": 2322, "column": 18}}}, "severity": "INFO"}
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.

Check warning on line 2329 in docs/src/main/asciidoc/writing-extensions.adoc

View workflow job for this annotation

GitHub Actions / Linting with Vale

[vale] reported by reviewdog 🐶 [Quarkus.Fluff] Depending on the context, consider using 'Rewrite the sentence, or use 'must', instead of' rather than 'need to'. Raw Output: {"message": "[Quarkus.Fluff] Depending on the context, consider using 'Rewrite the sentence, or use 'must', instead of' rather than 'need to'.", "location": {"path": "docs/src/main/asciidoc/writing-extensions.adoc", "range": {"start": {"line": 2329, "column": 58}}}, "severity": "INFO"}

[[troubleshooting-trace-logs]]
==== Enabling trace logs for a particular test only

Check warning on line 2332 in docs/src/main/asciidoc/writing-extensions.adoc

View workflow job for this annotation

GitHub Actions / Linting with Vale

[vale] reported by reviewdog 🐶 [Quarkus.TermsWarnings] Consider using 'might (for possibility)' or 'can (for ability)' rather than 'may' unless updating existing content that uses the term. Raw Output: {"message": "[Quarkus.TermsWarnings] Consider using 'might (for possibility)' or 'can (for ability)' rather than 'may' unless updating existing content that uses the term.", "location": {"path": "docs/src/main/asciidoc/writing-extensions.adoc", "range": {"start": {"line": 2332, "column": 12}}}, "severity": "WARNING"}

When <<testing-extensions,using `QuarkusUnitTest`>>,
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");

Check warning on line 2346 in docs/src/main/asciidoc/writing-extensions.adoc

View workflow job for this annotation

GitHub Actions / Linting with Vale

[vale] reported by reviewdog 🐶 [Quarkus.SentenceLength] Try to keep sentences to an average of 32 words or fewer. Raw Output: {"message": "[Quarkus.SentenceLength] Try to keep sentences to an average of 32 words or fewer.", "location": {"path": "docs/src/main/asciidoc/writing-extensions.adoc", "range": {"start": {"line": 2346, "column": 46}}}, "severity": "INFO"}

// ... test methods go here ...

}
----

Check warning on line 2351 in docs/src/main/asciidoc/writing-extensions.adoc

View workflow job for this annotation

GitHub Actions / Linting with Vale

[vale] reported by reviewdog 🐶 [Quarkus.TermsSuggestions] Depending on the context, consider using 'because' or 'while' rather than 'as'. Raw Output: {"message": "[Quarkus.TermsSuggestions] Depending on the context, consider using 'because' or 'while' rather than 'as'.", "location": {"path": "docs/src/main/asciidoc/writing-extensions.adoc", "range": {"start": {"line": 2351, "column": 3}}}, "severity": "INFO"}

See the javadoc of `QuarkusUnitTest#traceCategories` for details.

This is handy to debug flaky tests that happen only in the CI environment, in particular,

Check warning on line 2355 in docs/src/main/asciidoc/writing-extensions.adoc

View workflow job for this annotation

GitHub Actions / Linting with Vale

[vale] reported by reviewdog 🐶 [Quarkus.Headings] Use sentence-style capitalization in '2.18.4. Multi-module Maven Projects and the Development Mode'. Raw Output: {"message": "[Quarkus.Headings] Use sentence-style capitalization in '2.18.4. Multi-module Maven Projects and the Development Mode'.", "location": {"path": "docs/src/main/asciidoc/writing-extensions.adoc", "range": {"start": {"line": 2355, "column": 64}}}, "severity": "INFO"}

Check warning on line 2355 in docs/src/main/asciidoc/writing-extensions.adoc

View workflow job for this annotation

GitHub Actions / Linting with Vale

[vale] reported by reviewdog 🐶 [Quarkus.HeadingPunctuation] Do not use end punctuation in headings. Raw Output: {"message": "[Quarkus.HeadingPunctuation] Do not use end punctuation in headings.", "location": {"path": "docs/src/main/asciidoc/writing-extensions.adoc", "range": {"start": {"line": 2355, "column": 64}}}, "severity": "INFO"}
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.

Check warning on line 2360 in docs/src/main/asciidoc/writing-extensions.adoc

View workflow job for this annotation

GitHub Actions / Linting with Vale

[vale] reported by reviewdog 🐶 [Quarkus.TermsWarnings] Consider using 'to' rather than 'in order to' unless updating existing content that uses the term. Raw Output: {"message": "[Quarkus.TermsWarnings] Consider using 'to' rather than 'in order to' unless updating existing content that uses the term.", "location": {"path": "docs/src/main/asciidoc/writing-extensions.adoc", "range": {"start": {"line": 2360, "column": 67}}}, "severity": "WARNING"}
However, if you want to run the example in the development mode then the `-DnoDeps` system property must be used in order to exclude the local project dependencies.
Otherwise, Quarkus attempts to monitor the extension classes and this may result in weird class loading issues.

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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;

Expand All @@ -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<String, String> 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<String> TRACE_CATEGORIES = List.of("org.hibernate", "io.quarkus.hibernate", "io.quarkus.panache");

@RegisterExtension
static QuarkusUnitTest runner = new QuarkusUnitTest()
.withApplicationRoot((jar) -> jar
Expand All @@ -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;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -27,13 +27,15 @@
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;
import java.util.logging.Handler;
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;
Expand Down Expand Up @@ -137,6 +139,12 @@ public class QuarkusUnitTest

private List<Consumer<QuarkusBootstrap.Builder>> bootstrapCustomizers = new ArrayList<>();

private boolean debugBytecode = false;
private List<String> traceCategories = new ArrayList<>();

private Map<String, String> systemPropertiesToRestore = new HashMap<>();
private Map<String, java.util.logging.Level> loggerLevelsToRestore = new HashMap<>();

public QuarkusUnitTest setExpectedException(Class<? extends Throwable> expectedException) {
return setExpectedException(expectedException, false);
}
Expand Down Expand Up @@ -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);
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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();
}
Expand Down Expand Up @@ -850,6 +901,36 @@ public QuarkusUnitTest overrideRuntimeConfigKey(final String propertyKey, final
return this;
}

/**
* Controls bytecode-related debug dumping.
* <p>
* 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.
* <p>
* 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 {
Expand Down
Loading