Report ps forest on doctest timeout

Author: user202729

src/sage/doctest/forker.py

@@ -2039,7 +2039,8 @@ def sel_exit():
                             w.copied_exitcode,
                             w.result,
                             w.output,
-                            pid=w.copied_pid)
+                            pid=w.copied_pid,
+                            process_tree_before_kill=w.process_tree_before_kill)
 
                         pending_tests -= 1
 
@@ -2272,7 +2273,8 @@ def __init__(self, source, options, funclist=[], baseline=None):
         self.messages = ""
 
         # Has this worker been killed (because of a time out)?
-        self.killed = False
+        self.killed: bool = False
+        self.process_tree_before_kill: str | None = None
 
     def run(self):
         """
@@ -2502,6 +2504,17 @@ def kill(self):
             sage: W.is_alive()
             False
         """
+        try:
+            import subprocess
+            self.process_tree_before_kill = subprocess.run(["ps", "-ef", "--cols", "1000", "--forest"],
+                                                           stdout=subprocess.PIPE, stderr=subprocess.DEVNULL,
+                                                           text=True, errors="ignore").stdout
+        except FileNotFoundError:  # ps not available? Unlikely
+            pass
+        except subprocess.CalledProcessError:
+            self.process_tree_before_kill = subprocess.run(["ps", "-efwww"],
+                                                           stdout=subprocess.PIPE, stderr=subprocess.DEVNULL,
+                                                           text=True, errors="ignore").stdout
 
         if self.rmessages is not None:
             os.close(self.rmessages)

src/sage/doctest/reporting.py

@@ -222,7 +222,7 @@ def report_head(self, source, fail_msg=None):
                 cmd += f" [failed in baseline: {failed}]"
         return cmd
 
-    def _log_failure(self, source, fail_msg, event, output=None):
+    def _log_failure(self, source, fail_msg, event, output=None, *, process_tree_before_kill=None):
         r"""
         Report on the result of a failed doctest run.
 
@@ -236,6 +236,8 @@ def _log_failure(self, source, fail_msg, event, output=None):
 
         - ``output`` -- (optional) string
 
+        - ``process_tree_before_kill`` -- (optional) string
+
         EXAMPLES::
 
             sage: from sage.doctest.reporting import DocTestReporter
@@ -265,13 +267,9 @@ def _log_failure(self, source, fail_msg, event, output=None):
         """
         log = self.controller.log
         format = self.controller.options.format
+        stars = "*" * 70
         if format == 'sage':
-            stars = "*" * 70
             log(f"    {fail_msg}\n{stars}\n")
-            if output:
-                log(f"Tests run before {event}:")
-                log(output)
-                log(stars)
         elif format == 'github':
             # https://docs.github.com/en/actions/using-workflows/workflow-commands-for-github-actions#using-workflow-commands-to-access-toolkit-functions
             command = f'::error title={fail_msg}'
@@ -292,8 +290,18 @@ def _log_failure(self, source, fail_msg, event, output=None):
             log(command)
         else:
             raise ValueError(f'unknown format option: {format}')
-
-    def report(self, source, timeout, return_code, results, output, pid=None):
+        # we log the tests ran even in github mode. The last test information is redundant since it's included
+        # in the {lineno} above, but the printed outputs of previously ran tests are not
+        if output:
+            log(f"Tests run before {event}:")
+            log(output)
+            log(stars)
+        if process_tree_before_kill:
+            log("Process tree before kill:")
+            log(process_tree_before_kill)
+            log(stars)
+
+    def report(self, source, timeout, return_code, results, output, pid=None, *, process_tree_before_kill=None):
         """
         Report on the result of running doctests on a given source.
 
@@ -507,7 +515,7 @@ def report(self, source, timeout, return_code, results, output, pid=None):
                         fail_msg += " (and interrupt failed)"
                     else:
                         fail_msg += " (with %s after interrupt)" % signal_name(sig)
-                self._log_failure(source, fail_msg, f"{process_name} timed out", output)
+                self._log_failure(source, fail_msg, f"{process_name} timed out", output, process_tree_before_kill=process_tree_before_kill)
                 postscript['lines'].append(self.report_head(source, fail_msg))
                 stats[basename] = {"failed": True, "walltime": 1e6, "ntests": ntests}
                 if not baseline.get('failed', False):