Skip to content

Commit

Permalink
Represent test timeouts in XML
Browse files Browse the repository at this point in the history
This creates similar output as bazelbuild/bazel@7b091c1
  • Loading branch information
illicitonion committed Jan 18, 2024
1 parent 306e4da commit e09bda3
Show file tree
Hide file tree
Showing 6 changed files with 177 additions and 50 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -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();

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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<UniqueId, TestData> 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());
Expand Down Expand Up @@ -72,7 +85,12 @@ public void testPlanExecutionFinished(TestPlan testPlan) {
this.testPlan = null;
}

private Map<TestData, List<TestData>> matchTestCasesToSuites(List<TestData> 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<TestData, List<TestData>> matchTestCasesToSuites_locked(List<TestData> testCases, boolean includeIncompleteTests) {
Map<TestData, List<TestData>> knownSuites = new HashMap<>();

// Find the containing test suites for the test cases.
Expand All @@ -84,14 +102,20 @@ private Map<TestData, List<TestData>> matchTestCasesToSuites(List<TestData> 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<TestData> 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<TestData> findTestCases_locked() {
return results.values().stream()
// Ignore test plan roots. These are always the engine being used.
.filter(result -> !testPlan.getRoots().contains(result.getId()))
Expand Down Expand Up @@ -134,28 +158,33 @@ private void outputIfTestRootIsComplete(TestIdentifier testIdentifier) {
return;
}

List<TestData> testCases = findTestCases();
Map<TestData, List<TestData>> testSuites = matchTestCasesToSuites(testCases);
output(false);
}

// Write the results
try {
for (Map.Entry<TestData, List<TestData>> suiteAndTests : testSuites.entrySet()) {
new TestSuiteXmlRenderer(testPlan)
.toXml(xml, suiteAndTests.getKey(), suiteAndTests.getValue());
private void output(boolean includeIncompleteTests) {
synchronized (this.resultsLock) {
List<TestData> testCases = findTestCases_locked();
Map<TestData, List<TestData>> testSuites = matchTestCasesToSuites_locked(testCases, includeIncompleteTests);

// Write the results
try {
for (Map.Entry<TestData, List<TestData>> 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
Expand All @@ -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();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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());
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,9 +16,11 @@ class TestData {
private final TestIdentifier id;
private final List<ReportEntry> 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) {
Expand All @@ -36,8 +38,6 @@ public TestData started() {

public TestData mark(TestExecutionResult result) {
if (result.getStatus() == TestExecutionResult.Status.ABORTED) {
skipReason("");

Optional<Throwable> maybeThrowable = result.getThrowable();
if (maybeThrowable.isPresent() && maybeThrowable.get() instanceof TestAbortedException) {
skipReason(maybeThrowable.get().getMessage());
Expand All @@ -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);
}

Expand All @@ -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);
}
Expand Down Expand Up @@ -133,4 +142,8 @@ public TestData setDynamic(boolean isDynamic) {
public boolean isDynamic() {
return dynamic;
}

public Instant getStarted() {
return this.started;
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -27,17 +27,24 @@ public void toXml(XMLStreamWriter xml, TestData suite, Collection<TestData> 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));
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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()));
Expand Down

0 comments on commit e09bda3

Please sign in to comment.