From e09bda37b5a4fc2e7d01e9a47ab2a1595e0ae8bb Mon Sep 17 00:00:00 2001 From: Daniel Wagner-Hall Date: Wed, 17 Jan 2024 17:52:37 +0000 Subject: [PATCH] Represent test timeouts in XML This creates similar output as https://github.com/bazelbuild/bazel/commit/7b091c1397a82258e26ab5336df6c8dae1d97384 --- .../junit5/ActualRunner.java | 7 ++ .../junit5/BazelJUnitOutputListener.java | 90 ++++++++++++++----- .../junit5/TestCaseXmlRenderer.java | 37 +++++--- .../contrib_rules_jvm/junit5/TestData.java | 21 ++++- .../junit5/TestSuiteXmlRenderer.java | 27 +++--- .../junit5/BazelJUnitOuputListenerTest.java | 45 ++++++++++ 6 files changed, 177 insertions(+), 50 deletions(-) diff --git a/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/ActualRunner.java b/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/ActualRunner.java index 11d074ce..a8c1c717 100644 --- a/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/ActualRunner.java +++ b/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/ActualRunner.java @@ -44,6 +44,13 @@ public boolean run(String testClassName) { } try (BazelJUnitOutputListener bazelJUnitXml = new BazelJUnitOutputListener(xmlOut)) { + Runtime.getRuntime() + .addShutdownHook( + new Thread( + () -> { + bazelJUnitXml.closeForInterrupt(); + })); + CommandLineSummary summary = new CommandLineSummary(); FailFastExtension failFastExtension = new FailFastExtension(); diff --git a/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/BazelJUnitOutputListener.java b/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/BazelJUnitOutputListener.java index 8a6b577e..a16566a1 100644 --- a/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/BazelJUnitOutputListener.java +++ b/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/BazelJUnitOutputListener.java @@ -12,6 +12,7 @@ import java.util.List; import java.util.Map; import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.atomic.AtomicBoolean; import java.util.logging.Level; import java.util.logging.Logger; import java.util.stream.Collectors; @@ -30,9 +31,21 @@ public class BazelJUnitOutputListener implements TestExecutionListener, Closeabl public static final Logger LOG = Logger.getLogger(BazelJUnitOutputListener.class.getName()); private final XMLStreamWriter xml; + private final Object resultsLock = new Object(); + // Commented out to avoid adding a dependency to building the test runner. + // This is really just documentation until someone actually turns on a static analyser. + // If they do, we can decide whether we want to pick up the dependency. + // @GuardedBy("resultsLock") private final Map results = new ConcurrentHashMap<>(); private TestPlan testPlan; + // If we have already closed this listener, we shouldn't write any more XML. + private final AtomicBoolean hasClosed = new AtomicBoolean(); + // Whether test-running was interrupted (e.g. because our tests timed out and we got SIGTERM'd) + // and when writing results we want to flush any pending tests as interrupted, + // rather than ignoring them because they're incomplete. + private final AtomicBoolean wasInterrupted = new AtomicBoolean(); + public BazelJUnitOutputListener(Path xmlOut) { try { Files.createDirectories(xmlOut.getParent()); @@ -72,7 +85,12 @@ public void testPlanExecutionFinished(TestPlan testPlan) { this.testPlan = null; } - private Map> matchTestCasesToSuites(List testCases) { + // Requires the caller to have acquired resultsLock. + // Commented out to avoid adding a dependency to building the test runner. + // This is really just documentation until someone actually turns on a static analyser. + // If they do, we can decide whether we want to pick up the dependency. + // @GuardedBy("resultsLock") + private Map> matchTestCasesToSuites_locked(List testCases, boolean includeIncompleteTests) { Map> knownSuites = new HashMap<>(); // Find the containing test suites for the test cases. @@ -84,14 +102,20 @@ private Map> matchTestCasesToSuites(List test LOG.warning("Unable to find parent test for " + testCase.getId()); throw new IllegalStateException("Unable to find parent test for " + testCase.getId()); } - - knownSuites.computeIfAbsent(parent, id -> new ArrayList<>()).add(testCase); + if (includeIncompleteTests || testCase.getDuration() != null) { + knownSuites.computeIfAbsent(parent, id -> new ArrayList<>()).add(testCase); + } } return knownSuites; } - private List findTestCases() { + // Requires the caller to have acquired resultsLock. + // Commented out to avoid adding a dependency to building the test runner. + // This is really just documentation until someone actually turns on a static analyser. + // If they do, we can decide whether we want to pick up the dependency. + // @GuardedBy("resultsLock") + private List findTestCases_locked() { return results.values().stream() // Ignore test plan roots. These are always the engine being used. .filter(result -> !testPlan.getRoots().contains(result.getId())) @@ -134,28 +158,33 @@ private void outputIfTestRootIsComplete(TestIdentifier testIdentifier) { return; } - List testCases = findTestCases(); - Map> testSuites = matchTestCasesToSuites(testCases); + output(false); + } - // Write the results - try { - for (Map.Entry> suiteAndTests : testSuites.entrySet()) { - new TestSuiteXmlRenderer(testPlan) - .toXml(xml, suiteAndTests.getKey(), suiteAndTests.getValue()); + private void output(boolean includeIncompleteTests) { + synchronized (this.resultsLock) { + List testCases = findTestCases_locked(); + Map> testSuites = matchTestCasesToSuites_locked(testCases, includeIncompleteTests); + + // Write the results + try { + for (Map.Entry> suiteAndTests : testSuites.entrySet()) { + new TestSuiteXmlRenderer(testPlan).toXml(xml, suiteAndTests.getKey(), suiteAndTests.getValue()); + } + } catch (XMLStreamException e) { + throw new RuntimeException(e); } - } catch (XMLStreamException e) { - throw new RuntimeException(e); - } - // Delete the results we've used to conserve memory. This is safe to do - // since we only do this when the test root is complete, so we know that - // we won't be adding to the list of suites and test cases for that root - // (because tests and containers are arranged in a hierarchy --- the - // containers only complete when all the things they contain are - // finished. We are leaving all the test data that we have _not_ written - // to the XML file. - Stream.concat(testCases.stream(), testSuites.keySet().stream()) - .forEach(data -> results.remove(data.getId().getUniqueIdObject())); + // Delete the results we've used to conserve memory. This is safe to do + // since we only do this when the test root is complete, so we know that + // we won't be adding to the list of suites and test cases for that root + // (because tests and containers are arranged in a hierarchy --- the + // containers only complete when all the things they contain are + // finished. We are leaving all the test data that we have _not_ written + // to the XML file. + Stream.concat(testCases.stream(), testSuites.keySet().stream()) + .forEach(data -> results.remove(data.getId().getUniqueIdObject())); + } } @Override @@ -164,10 +193,23 @@ public void reportingEntryPublished(TestIdentifier testIdentifier, ReportEntry e } private TestData getResult(TestIdentifier id) { - return results.computeIfAbsent(id.getUniqueIdObject(), ignored -> new TestData(id)); + synchronized (resultsLock) { + return results.computeIfAbsent(id.getUniqueIdObject(), ignored -> new TestData(id)); + } + } + + public void closeForInterrupt() { + wasInterrupted.set(true); + close(); } public void close() { + if (hasClosed.getAndSet(true)) { + return; + } + if (wasInterrupted.get()) { + output(true); + } try { xml.writeEndDocument(); xml.close(); diff --git a/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestCaseXmlRenderer.java b/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestCaseXmlRenderer.java index d829e579..fa0c5ab6 100644 --- a/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestCaseXmlRenderer.java +++ b/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestCaseXmlRenderer.java @@ -8,7 +8,10 @@ import java.math.RoundingMode; import java.text.DecimalFormat; import java.text.DecimalFormatSymbols; +import java.time.Duration; +import java.time.Instant; import java.util.Locale; +import java.util.Optional; import javax.xml.stream.XMLStreamException; import javax.xml.stream.XMLStreamWriter; import org.junit.platform.engine.TestExecutionResult; @@ -47,21 +50,31 @@ public void toXml(XMLStreamWriter xml, TestData test) throws XMLStreamException xml.writeStartElement("testcase"); xml.writeAttribute("name", name); xml.writeAttribute("classname", LegacyReportingUtils.getClassName(testPlan, id)); - xml.writeAttribute("time", decimalFormat.format(test.getDuration().toMillis() / 1000f)); - if (test.isDisabled() || test.isSkipped()) { - xml.writeStartElement("skipped"); - if (test.getSkipReason() != null) { - xml.writeCData(test.getSkipReason()); - } else { + /* @Nullable */ Duration maybeDuration = test.getDuration(); + boolean wasInterrupted = maybeDuration == null; + Duration duration = maybeDuration == null ? Duration.between(test.getStarted(), Instant.now()) : maybeDuration; + xml.writeAttribute("time", decimalFormat.format(duration.toMillis() / 1000f)); + + if (wasInterrupted) { + xml.writeStartElement("failure"); + xml.writeCData("Test timed out and was interrupted"); + xml.writeEndElement(); + } else { + if (test.isDisabled() || test.isSkipped()) { + xml.writeStartElement("skipped"); + if (test.getSkipReason() != null) { + xml.writeCData(test.getSkipReason()); + } else { + writeThrowableMessage(xml, test.getResult()); + } + xml.writeEndElement(); + } + if (test.isFailure() || test.isError()) { + xml.writeStartElement(test.isFailure() ? "failure" : "error"); writeThrowableMessage(xml, test.getResult()); + xml.writeEndElement(); } - xml.writeEndElement(); - } - if (test.isFailure() || test.isError()) { - xml.writeStartElement(test.isFailure() ? "failure" : "error"); - writeThrowableMessage(xml, test.getResult()); - xml.writeEndElement(); } writeTextElement(xml, "system-out", test.getStdOut()); diff --git a/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestData.java b/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestData.java index 60d725c5..abe81b03 100644 --- a/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestData.java +++ b/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestData.java @@ -16,9 +16,11 @@ class TestData { private final TestIdentifier id; private final List reportEntries = Collections.synchronizedList(new ArrayList<>()); private Instant started = Instant.now(); - private Instant finished = Instant.now(); + // Commented out to avoid pulling in the dependency, but present for documentation purposes. + // @Nullable + private Instant finished = null; private String reason; - private TestExecutionResult result; + TestExecutionResult result; private boolean dynamic; TestData(TestIdentifier id) { @@ -36,8 +38,6 @@ public TestData started() { public TestData mark(TestExecutionResult result) { if (result.getStatus() == TestExecutionResult.Status.ABORTED) { - skipReason(""); - Optional maybeThrowable = result.getThrowable(); if (maybeThrowable.isPresent() && maybeThrowable.get() instanceof TestAbortedException) { skipReason(maybeThrowable.get().getMessage()); @@ -62,7 +62,13 @@ public TestExecutionResult getResult() { return result; } + /** Returns how long the test took to run - will be absent if the test has not yet completed. */ + // Commented out to avoid pulling in the dependency, but present for documentation purposes. + // @Nullable public Duration getDuration() { + if (finished == null) { + return null; + } return Duration.between(started, finished); } @@ -84,6 +90,9 @@ public boolean isFailure() { || isSkipped()) { return false; } + if (result.getStatus() == TestExecutionResult.Status.ABORTED) { + return true; + } return result.getThrowable().map(thr -> (!(thr instanceof AssertionError))).orElse(false); } @@ -133,4 +142,8 @@ public TestData setDynamic(boolean isDynamic) { public boolean isDynamic() { return dynamic; } + + public Instant getStarted() { + return this.started; + } } diff --git a/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestSuiteXmlRenderer.java b/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestSuiteXmlRenderer.java index 1ee752b0..95c5b738 100644 --- a/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestSuiteXmlRenderer.java +++ b/java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestSuiteXmlRenderer.java @@ -27,17 +27,24 @@ public void toXml(XMLStreamWriter xml, TestData suite, Collection test int disabled = 0; int skipped = 0; for (TestData result : tests) { - if (result.isError()) { - errors++; - } - if (result.isFailure()) { + // Tests which didn't complete are considered to be failures. + // The caller is expected to filter out still-running tests, so if we got here, + // it's because the test has been cancelled (e.g. because of a timeout). + if (result.getDuration() == null) { failures++; - } - if (result.isDisabled()) { - disabled++; - } - if (result.isSkipped()) { - skipped++; + } else { + if (result.isError()) { + errors++; + } + if (result.isFailure()) { + failures++; + } + if (result.isDisabled()) { + disabled++; + } + if (result.isSkipped()) { + skipped++; + } } } xml.writeAttribute("failures", String.valueOf(failures)); diff --git a/java/test/com/github/bazel_contrib/contrib_rules_jvm/junit5/BazelJUnitOuputListenerTest.java b/java/test/com/github/bazel_contrib/contrib_rules_jvm/junit5/BazelJUnitOuputListenerTest.java index 84e53e48..8020ff7b 100644 --- a/java/test/com/github/bazel_contrib/contrib_rules_jvm/junit5/BazelJUnitOuputListenerTest.java +++ b/java/test/com/github/bazel_contrib/contrib_rules_jvm/junit5/BazelJUnitOuputListenerTest.java @@ -141,6 +141,51 @@ public void disabledTestsAreMarkedAsSkipped() { assertNotNull(skipped); } + @Test + public void interruptedTestsAreMarkedAsFailed() { + TestData suite = new TestData(identifier); + + TestPlan testPlan = Mockito.mock(TestPlan.class); + + TestIdentifier completedChild = + TestIdentifier.from(new StubbedTestDescriptor(createId("complete-child"))); + TestData completedChildResult = new TestData(completedChild).started(); + completedChildResult.mark(TestExecutionResult.successful()); + + TestIdentifier interruptedChild = + TestIdentifier.from(new StubbedTestDescriptor(createId("interrupted-child"))); + TestData interruptedChildResult = new TestData(interruptedChild).started(); + + Document xml = + generateTestXml(testPlan, suite, List.of(completedChildResult, interruptedChildResult)); + + // Because of the way we generated the XML, the root element is the `testsuite` one + Element root = xml.getDocumentElement(); + assertEquals("testsuite", root.getTagName()); + assertEquals("2", root.getAttribute("tests")); + assertEquals("0", root.getAttribute("disabled")); + assertEquals("0", root.getAttribute("errors")); + assertEquals("0", root.getAttribute("skipped")); + assertEquals("1", root.getAttribute("failures")); + + NodeList allTestCases = root.getElementsByTagName("testcase"); + assertEquals(2, allTestCases.getLength()); + Node testCaseZero = allTestCases.item(0); + Node testCaseOne = allTestCases.item(1); + + Node failureZero = getChild("failure", testCaseZero); + Node failureOne = getChild("failure", testCaseOne); + + if (!(failureZero == null ^ failureOne == null)) { + fail( + String.format("Expected exactly one failure but got %s and %s", failureZero, failureOne)); + } + + Node failure = failureZero == null ? failureOne : failureZero; + + assertEquals("Test timed out and was interrupted", failure.getTextContent()); + } + @Test void throwablesWithNullMessageAreSerialized() { var test = new TestData(identifier).mark(TestExecutionResult.failed(new Throwable()));