SERVER-99725 Extend a resmoke test's log when its outcome is changed to a failure (#32022)

GitOrigin-RevId: 9570c53

Author: sleaux

buildscripts/resmokelib/testing/job.py

@@ -262,7 +262,9 @@ def _execute_test(self, test: TestCase, hook_failure_flag: Optional[threading.Ev
                     "%s marked as a failure because the fixture crashed during the test.",
                     test.short_description(),
                 )
-                self.report.setFailure(test, return_code=2)
+                self.report.setFailure(
+                    test, return_code=2, reason="the fixture crashed during the test"
+                )
                 # Always fail fast if the fixture fails.
                 raise errors.StopExecution(
                     "%s not running after %s" % (self.fixture, test.short_description())
@@ -397,10 +399,14 @@ def _run_hooks_after_tests(
                 self.fixture.stop_balancer()
             except:
                 self.logger.exception(
-                    "%s failed while stopping the balancer for end-test hooks",
+                    "%s failed while stopping the balancer for after-test hooks",
                     test.short_description(),
                 )
-                self.report.setFailure(test, return_code=2)
+                self.report.setFailure(
+                    test,
+                    return_code=2,
+                    reason="the balancer failed to stop before running after-test hooks",
+                )
                 if self.archival:
                     result = TestResult(test=test, hook=None, success=False)
                     self.archival.archive(self.logger, result, self.manager)
@@ -418,14 +424,18 @@ def _run_hooks_after_tests(
             self.logger.exception(
                 "%s marked as a failure by a hook's after_test.", test.short_description()
             )
-            self.report.setFailure(test, return_code=2)
+            self.report.setFailure(
+                test, return_code=2, reason=f"The hook {hook.REGISTERED_NAME} failed."
+            )
             raise errors.StopExecution("A hook's after_test failed")
 
         except errors.TestFailure:
             self.logger.exception(
                 "%s marked as a failure by a hook's after_test.", test.short_description()
             )
-            self.report.setFailure(test, return_code=1)
+            self.report.setFailure(
+                test, return_code=1, reason=f"The hook {hook.REGISTERED_NAME} failed."
+            )
             if self.suite_options.fail_fast:
                 raise errors.StopExecution("A hook's after_test failed")
 
@@ -442,7 +452,11 @@ def _run_hooks_after_tests(
                     "%s failed while re-starting the balancer after end-test hooks",
                     test.short_description(),
                 )
-                self.report.setFailure(test, return_code=2)
+                self.report.setFailure(
+                    test,
+                    return_code=2,
+                    reason="the balancer failed to restart after running after test hooks",
+                )
                 if self.archival:
                     result = TestResult(test=test, hook=None, success=False)
                     self.archival.archive(self.logger, result, self.manager)

buildscripts/resmokelib/testing/report.py

@@ -218,6 +218,7 @@ def setError(self, test, err):
             if test_info.end_time is None:
                 raise ValueError("stopTest was not called on %s" % (test.basename()))
 
+            changed = test_info.status != "error"
             # We don't distinguish between test failures and Python errors in Evergreen.
             test_info.status = "error"
             test_info.evergreen_status = "fail"
@@ -230,6 +231,9 @@ def setError(self, test, err):
         self.num_errored = len(self.get_errored())
         self.num_interrupted = len(self.get_interrupted())
 
+        if changed:
+            self._log_outcome_change(test, "error")
+
     def addFailure(self, test, err):
         """Call when a failureException was raised during the execution of 'test'."""
 
@@ -243,14 +247,15 @@ def addFailure(self, test, err):
             test_info.evergreen_status = "fail"
             test_info.return_code = test.return_code
 
-    def setFailure(self, test, return_code=1):
+    def setFailure(self, test, return_code=1, reason=""):
         """Change the outcome of an existing test to a failure."""
 
         with self._lock:
             test_info = self.find_test_info(test)
             if test_info.end_time is None:
                 raise ValueError("stopTest was not called on %s" % (test.basename()))
 
+            changed = test_info.status != "fail"
             test_info.status = "fail"
             test_info.evergreen_status = "fail"
             test_info.return_code = return_code
@@ -261,6 +266,9 @@ def setFailure(self, test, return_code=1):
         self.num_errored = len(self.get_errored())
         self.num_interrupted = len(self.get_interrupted())
 
+        if changed:
+            self._log_outcome_change(test, "fail", reason)
+
     def addSuccess(self, test):
         """Call when 'test' executed successfully."""
 
@@ -397,6 +405,24 @@ def find_test_info(self, test):
 
         raise ValueError("Details for %s not found in the report" % (test.basename()))
 
+    def _log_outcome_change(self, test, outcome, reason=""):
+        # Recreate the test logger for this test in order to append to the existing log.
+        logger = logging.loggers.new_test_logger(
+            test.short_name(),
+            test.basename(),
+            None,
+            test.logger,
+            self.job_num,
+            test.id(),
+            self.job_logger,
+        )
+        logger.info(
+            f'Sometime after completion of {test.short_description()}, the test outcome was changed to "{outcome}"'
+            + (f" because: {reason}" if reason else "."),
+        )
+        for handler in logger.handlers:
+            logging.flush.close_later(handler)
+
 
 class TestInfo(object):
     """Holder for the test status and timing information."""