Represent test timeouts in XML (#247)

This creates similar output as
bazelbuild/bazel@7b091c1

Note: This is a duplicate of #242, but with the comments addressed and
the merge conflicts resolved.

---------

Co-authored-by: Daniel Wagner-Hall <[email protected]>

Author: tjoneslo

MODULE.bazel

@@ -103,7 +103,7 @@ IO_GRPC_GRPC_JAVA_ARTIFACTS = [
     "com.google.auto.value:auto-value:1.9",
     "com.google.code.findbugs:jsr305:3.0.2",
     "com.google.code.gson:gson:2.9.0",
-    "com.google.errorprone:error_prone_annotations:2.9.0",
+    "com.google.errorprone:error_prone_annotations:2.11.0",
     "com.google.guava:failureaccess:1.0.1",
     "com.google.guava:guava:31.0.1-android",
     "com.google.j2objc:j2objc-annotations:1.3",

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();
 

java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/BazelJUnitOutputListener.java

@@ -13,6 +13,7 @@
 import java.util.Map;
 import java.util.NoSuchElementException;
 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;
@@ -31,9 +32,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());
@@ -73,12 +86,17 @@ 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.
     for (TestData testCase : testCases) {
-
       TestData parent;
 
       // The number of segments in the test case Unique ID depends upon the nature of the test:
@@ -120,13 +138,20 @@ private Map<TestData, List<TestData>> matchTestCasesToSuites(List<TestData> test
         throw new IllegalStateException(
             "Unexpected test organization for test Case: " + 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()))
@@ -169,28 +194,35 @@ private void outputIfTestRootIsComplete(TestIdentifier testIdentifier) {
       return;
     }
 
-    List<TestData> testCases = findTestCases();
-    Map<TestData, List<TestData>> testSuites = matchTestCasesToSuites(testCases);
+    output(false);
+  }
+
+  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());
+      // 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
@@ -199,10 +231,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();

java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestCaseXmlRenderer.java

@@ -8,6 +8,8 @@
 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 javax.xml.stream.XMLStreamException;
 import javax.xml.stream.XMLStreamWriter;
@@ -47,21 +49,32 @@ 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());

java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestData.java

@@ -16,7 +16,9 @@ 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;
   private boolean dynamic;
@@ -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());
@@ -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;
+  }
 }

java/src/com/github/bazel_contrib/contrib_rules_jvm/junit5/TestSuiteXmlRenderer.java

@@ -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));

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()));