ci(python): exit and replace a GraalPy worker whose heap is spent (#1753)

.github/workflows/experimental.yml

@@ -262,7 +262,25 @@ jobs:
       # runner alive, and a breach fails this step instead:
       # - GraalPy alone: a 2 GiB heap per process, read by every GraalPy
       #   process, xdist workers included (GRAAL_PYTHON_VM_ARGS), and 3 workers,
-      #   which leaves a CPU of the 4 to the JIT and the runner.
+      #   which leaves a CPU of the 4 to the JIT and the runner. On the native
+      #   standalone `--vm.Xmx` caps the Java heap alone, not thread stacks or
+      #   JIT code (graalvm.org, Native Image, Memory Management), and a heap
+      #   the GC cannot free raises OutOfMemoryError, which GraalPy turns into
+      #   MemoryError (graalpython runtime/exception/ExceptionUtils.java:313-316,
+      #   at graal-25.4.4).
+      # - #1753: a worker's live heap grows with its tests. Job 116172356218's
+      #   three workers reached 2.2-2.6 GB RSS in 16 minutes; four tests raised
+      #   MemoryError, then gw1 raised one in pytest's own failure report,
+      #   which ends the session (exit 3) with 7.9 GB still free. Locally
+      #   (25.4.4, -n 0) the heap after a full GC rose from 199M to 1738M over
+      #   11% of tests/const and tests/corekit, so no heap the 12G holds for 3
+      #   workers lasts the tier. `-XX:+ExitOnOutOfMemoryError` ends that
+      #   worker instead, xdist reports the test it ran as crashed and starts a
+      #   fresh one. `--max-worker-restart=30` allows 30 restarts in all, where
+      #   three heaps that last 16 minutes need about 21 in 110; xdist's default
+      #   is 4 a worker, 12 at -n 3.
+      #   Five corekit files at `--vm.Xmx450m -n 1`: exit 3 after 28 passed
+      #   without the flag; with it, 3 workers replaced and the run finished.
       # - `timeout` sends SIGINT at 110 minutes, under the 120-minute cap, so
       #   pytest still writes the junit XML, and exits 124; SIGKILL 3 minutes on.
       # - `prlimit --fsize`: no file over 2 GiB.
@@ -280,21 +298,24 @@ jobs:
       #   way the tests run the one argv, in the scope or not.
       # `tests-status` holds the exit status, the scope and the probe's error,
       # the seconds the tests took, the kernel's OOM kills while they ran
-      # (/proc/vmstat `oom_kill`) and the MemoryError count, for `Containment
-      # summary`.
+      # (/proc/vmstat `oom_kill`), the MemoryError count (`-w`, so Java's
+      # `OutOfMemoryError` and the flag are not counted) and the workers that
+      # crashed, by xdist's `[gwN] node down:` lines (under `-q` it prints no
+      # `replacing crashed worker`, xdist/dsession.py:78-80 at v3.8.0), for
+      # `Containment summary`.
       - name: Run unit tests
         id: tests
         if: ${{ steps.install.outcome == 'success' }}
         continue-on-error: true
         timeout-minutes: 120
         env:
-          GRAAL_PYTHON_VM_ARGS: ${{ startsWith(matrix.python-version, 'graalpy') && '--vm.Xmx2g' || '' }}
+          GRAAL_PYTHON_VM_ARGS: ${{ startsWith(matrix.python-version, 'graalpy') && '--vm.Xmx2g --vm.XX:+ExitOnOutOfMemoryError' || '' }}
           WORKERS: ${{ startsWith(matrix.python-version, 'graalpy') && '3' || 'auto' }}
         run: |
           tail -n +1 -F "$RUNNER_TEMP/resource-monitor.log" 2>/dev/null &
           monitor=$!
           trap 'kill "$monitor" 2>/dev/null || true' EXIT
-          set -- -q -n "$WORKERS" --dist load \
+          set -- -q -n "$WORKERS" --dist load --max-worker-restart=30 \
             --durations=30 --durations-min=1.0 --junitxml="$RUNNER_TEMP/junit.xml" \
             --ignore=tests/integration \
             --ignore-glob='*_runtime.py' \
@@ -328,10 +349,11 @@ jobs:
           set -e
           elapsed=$((SECONDS - started))
           after=$(oom_kills)
-          memory_errors=$(grep -c MemoryError "$RUNNER_TEMP/pytest.log" || true)
-          printf 'exit=%s\nscope=%s\nprobe=%s\nelapsed=%s\noom_kills=%s\nmemory_errors=%s\n' \
+          memory_errors=$(grep -cw MemoryError "$RUNNER_TEMP/pytest.log" || true)
+          crashed_workers=$(grep -c '\] node down: ' "$RUNNER_TEMP/pytest.log" || true)
+          printf 'exit=%s\nscope=%s\nprobe=%s\nelapsed=%s\noom_kills=%s\nmemory_errors=%s\ncrashed_workers=%s\n' \
             "$status" "$scope" "$probe" "$elapsed" "$(( ${after:-0} - ${before:-0} ))" "$memory_errors" \
-            > "$RUNNER_TEMP/tests-status"
+            "$crashed_workers" > "$RUNNER_TEMP/tests-status"
           exit "$status"
 
       # #1740: after a failed, timed-out or cancelled tests step too. A lost
@@ -382,12 +404,12 @@ jobs:
       # tests, ahead of `Experimental summary`, whose script stays the KTLO
       # summary's (tests/project/test_ktlo_legs_stay_green_1672.py) and which
       # still reports a failed `tests` step as it reports any. Each cause gets a
-      # warning of its own: no 12G scope, an OOM kill, a MemoryError, and a
-      # timeout -- exit 124, or 137 with no OOM kill after 110 minutes, which is
-      # `--kill-after` ending a teardown that SIGINT did not. An OOM kill of
-      # pytest itself also exits 137, so the OOM count and the time tell them
-      # apart. Nothing here fails: a missing or partial status is reported as
-      # what it is.
+      # warning of its own: no 12G scope, an OOM kill, a MemoryError, a worker
+      # xdist replaced (#1753), and a timeout -- exit 124, or 137 with no OOM
+      # kill after 110 minutes, which is `--kill-after` ending a teardown that
+      # SIGINT did not. An OOM kill of pytest itself also exits 137, so the OOM
+      # count and the time tell them apart. Nothing here fails: a missing or
+      # partial status is reported as what it is.
       - name: Containment summary
         if: ${{ !cancelled() }}
         continue-on-error: true
@@ -411,7 +433,7 @@ jobs:
             echo "- ${LEG}: ${1}; non-blocking, so this job still succeeds." >> "$GITHUB_STEP_SUMMARY"
           }
           code=$(value exit) scope=$(value scope) elapsed=$(value elapsed)
-          oom=$(value oom_kills) errors=$(value memory_errors)
+          oom=$(value oom_kills) errors=$(value memory_errors) crashed=$(value crashed_workers)
           if [ "$scope" = none ]; then
             warn "No memory cap" "The probe, sudo -n systemd-run --scope with the tests' flags, failed ($(value probe)), so the tests ran without the 12G scope."
           fi
@@ -426,7 +448,10 @@ jobs:
           if [ "$errors" -gt 0 ] 2>/dev/null; then
             warn "tests raised MemoryError" "${errors} MemoryError line(s) in the pytest output, exit ${code}, scope ${scope}; ${last}."
           fi
-          echo "$LEG: tests exited ${code} after ${elapsed} s, scope ${scope}, ${oom} OOM kill(s), ${errors} MemoryError line(s); ${last}."
+          if [ "$crashed" -gt 0 ] 2>/dev/null; then
+            warn "tests lost an xdist worker" "${crashed} xdist worker(s) went down, each failing the test it ran, and xdist replaces up to 30; exit ${code}, scope ${scope}; ${last}."
+          fi
+          echo "$LEG: tests exited ${code} after ${elapsed} s, scope ${scope}, ${oom} OOM kill(s), ${errors} MemoryError line(s), ${crashed:-0} worker(s) down; ${last}."
 
       # #1660: an experimental leg's report, as unit-tests.yml `test`'s `KTLO
       # summary` is a KTLO leg's, and for the same reasons.

docs/source/contributing/workflows.rst

@@ -799,9 +799,16 @@ so ``Run unit tests`` holds the tests to what leaves the runner alive, and a bre
 fails the step, which ``Containment summary`` and ``Experimental summary`` report as
 warnings:
 
-* GraalPy alone gets ``GRAAL_PYTHON_VM_ARGS=--vm.Xmx2g``, a 2 GiB heap for every
-  GraalPy process, xdist workers included, and ``-n 3``, a CPU of the runner's 4 left
-  to the JIT and the runner; 3.14t keeps ``-n auto``.
+* GraalPy alone gets ``GRAAL_PYTHON_VM_ARGS=--vm.Xmx2g --vm.XX:+ExitOnOutOfMemoryError``,
+  a 2 GiB heap for every GraalPy process, xdist workers included, and ``-n 3``, a CPU
+  of the runner's 4 left to the JIT and the runner; 3.14t keeps ``-n auto``. A
+  worker's live heap grows with the tests it runs (`#1753
+  <https://github.com/JarryShaw/PyPCAPKit/issues/1753>`__): in job 116172356218 all
+  three reached 2.2-2.6 GB RSS in 16 minutes, and a ``MemoryError`` in pytest's own
+  failure report ended the session, exit 3, with 7.9 GB free. So a worker whose heap
+  is spent exits, xdist fails the test it ran as crashed and starts another, and
+  ``--max-worker-restart=30`` allows 30 restarts in all, where three 16-minute heaps need
+  about 21 in 110 minutes; xdist's default is 4 a worker, 12 at ``-n 3``.
 * ``timeout --signal=INT --kill-after=3m 110m`` ends pytest under the step's 120-minute
   cap, so it still writes the junit XML, and exits 124; ``prlimit --fsize=2147483648``
   caps any file at 2 GiB.
@@ -817,10 +824,11 @@ warnings:
 
 The step writes ``$RUNNER_TEMP/tests-status``: the exit status, the scope and the
 probe's error, the seconds the tests took, the OOM kills while they ran
-(``/proc/vmstat``) and the ``MemoryError`` lines in their output. From it and the
-monitor's last sample, ``Containment summary`` warns ``No memory cap``, ``tests lost a
-process to the OOM killer``, ``tests timed out at 110 minutes`` or ``tests raised
-MemoryError``, each a warning of its own. A timeout is exit 124, or 137 with no OOM kill
+(``/proc/vmstat``), the ``MemoryError`` lines in their output and xdist's ``node
+down`` lines. From it and the monitor's last sample, ``Containment summary`` warns
+``No memory cap``, ``tests lost a process to the OOM killer``, ``tests timed out at 110
+minutes``, ``tests raised MemoryError`` or ``tests lost an xdist worker``, each a
+warning of its own. A timeout is exit 124, or 137 with no OOM kill
 after 110 minutes: ``--kill-after``'s SIGKILL to a teardown SIGINT did not end, where an
 OOM kill of pytest exits 137 too. ``Experimental summary``, the job's last step and the
 KTLO summary's script, still warns of every failed step, ``tests`` included. The 2 GiB,

tests/project/test_graalpy_worker_heap_1753.py

@@ -0,0 +1,139 @@
+# -*- coding: utf-8 -*-
+"""#1753: a GraalPy xdist worker whose heap is spent exits, and xdist replaces it.
+
+Under #1740's 2 GiB heap a GraalPy worker's live heap grows with the tests it
+runs, until a ``MemoryError`` lands in pytest's own failure report and ends the
+session, exit 3 (job 116172356218, 16 minutes in, at ``34 failed, 569 passed``).
+So every GraalPy process gets ``-XX:+ExitOnOutOfMemoryError`` with its heap, and
+pytest ``--max-worker-restart=30``: the worker exits, xdist fails the test it ran
+as crashed and starts another, and the tier goes on to its end or its timeout.
+``Run unit tests`` counts xdist's ``[gwN] node down:`` lines, and ``Containment
+summary`` warns of them.
+
+"""
+
+from __future__ import annotations
+
+import os
+import pathlib
+import shutil
+import sys
+import tempfile
+import unittest
+
+from tests.project.test_python_matrix_tiers_1633 import legs, workflow_commands
+from tests.project.test_python_versions_1660 import ROOT, prose
+from tests.project.test_resource_monitor_1740 import (BASH, DEFAULT, EXPERIMENTAL, SUMMARY, TESTS, by_impl, sh,
+                                                      step)
+
+#: What every GraalPy process reads: #1740's 2 GiB heap, and an exit where it is spent.
+GRAAL_VM_ARGS = '--vm.Xmx2g --vm.XX:+ExitOnOutOfMemoryError'
+#: About 7 replacements a worker in 110 minutes, at a heap that lasts 16; xdist's default is 4 a worker.
+RESTARTS = '--max-worker-restart=30'
+#: xdist's line for a worker that went down with an error, which ``-q`` still prints.
+NODE_DOWN = '[gw0] node down: Not properly terminated'
+
+
+class TestTheWorkersAreReplaced(unittest.TestCase):
+
+    def test_graalpy_exits_on_a_spent_heap(self) -> None:
+        env = step(TESTS)['env']
+        versions = [leg['python-version'] for leg in legs(*EXPERIMENTAL)]
+        self.assertTrue(any(version.startswith('graalpy') for version in versions), versions)
+        for version in versions:
+            with self.subTest(version=version):
+                self.assertEqual(by_impl(env['GRAAL_PYTHON_VM_ARGS'], version),
+                                 GRAAL_VM_ARGS if version.startswith('graalpy') else '')
+
+    def test_xdist_may_replace_30_workers(self) -> None:
+        script = step(TESTS)['run']
+        self.assertIn(f'set -- -q -n "$WORKERS" --dist load {RESTARTS} \\\n', script)
+        self.assertEqual(script.count('--max-worker-restart'), 1)
+
+    def test_the_docs_say_it(self) -> None:
+        page = prose(ROOT / 'docs' / 'source' / 'contributing' / 'workflows.rst')
+        for phrase in (f'``GRAAL_PYTHON_VM_ARGS={GRAAL_VM_ARGS}``', f'``{RESTARTS}``', '#1753',
+                       '``tests lost an xdist worker``'):
+            with self.subTest(phrase=phrase):
+                self.assertIn(phrase, page)
+
+
+@unittest.skipUnless(sys.platform.startswith('linux') and all(map(shutil.which, ('bash', 'timeout', 'prlimit'))),
+                     'the tests step runs coreutils timeout and util-linux prlimit, as on the Ubuntu runners')
+class TestTheCrashesAreCounted(unittest.TestCase):
+    """The tests step and ``Containment summary``, with ``sudo`` and ``python`` stubbed on ``PATH``."""
+
+    def setUp(self) -> None:
+        tmp = tempfile.TemporaryDirectory(prefix='pcapkit-1753-')  # pylint: disable=consider-using-with
+        self.addCleanup(tmp.cleanup)
+        self.tmp = pathlib.Path(tmp.name)
+        self.temp = self.tmp / 'temp'
+        self.temp.mkdir()
+        self.bindir = self.tmp / 'bin'
+        self.bindir.mkdir()
+        (self.temp / 'resource-monitor.log').write_text('', encoding='utf-8')
+        self.vmstat = self.tmp / 'vmstat'
+        self.vmstat.write_text('oom_kill 0\n', encoding='utf-8')
+        self.env = dict(os.environ, RUNNER_TEMP=str(self.temp), GITHUB_WORKSPACE=str(ROOT), WORKERS='3',
+                        GRAAL_PYTHON_VM_ARGS=GRAAL_VM_ARGS,
+                        LEG='Python graalpy-25.4 (experimental, non-blocking)',
+                        GITHUB_STEP_SUMMARY=str(self.tmp / 'summary.md'),
+                        PATH=str(self.bindir) + os.pathsep + os.environ.get('PATH', ''))
+        # No scope: the probe fails, so the tests run the same argv uncapped.
+        self.stub('sudo', 'exit 1\n')
+
+    def stub(self, name: 'str', body: 'str') -> 'None':
+        path = self.bindir / name
+        path.write_text('#!/bin/sh\n' + body, encoding='utf-8')
+        path.chmod(0o755)
+
+    def status(self, pytest: 'str') -> 'dict[str, str]':
+        self.stub('python', pytest)
+        self.assertEqual(shutil.which('sudo', path=self.env['PATH']), str(self.bindir / 'sudo'))
+        result = sh(step(TESTS)['run'].replace('/proc/vmstat', str(self.vmstat)), self.env, DEFAULT)
+        self.assertEqual(result.returncode, 1, result.stderr)
+        text = (self.temp / 'tests-status').read_text(encoding='utf-8')
+        return dict(line.split('=', 1) for line in text.splitlines())
+
+    def test_the_heap_and_the_restarts_reach_pytest(self) -> None:
+        status = self.status(f'printf "%s\\n" "$@" > {self.tmp / "argv"}\necho "heap $GRAAL_PYTHON_VM_ARGS"\nexit 1\n')
+        argv = (self.tmp / 'argv').read_text(encoding='utf-8').splitlines()
+        self.assertEqual(argv[:8], ['-m', 'pytest', '-q', '-n', '3', '--dist', 'load', RESTARTS])
+        self.assertEqual(status['crashed_workers'], '0')
+
+    def test_every_worker_that_went_down_is_counted(self) -> None:
+        # As job 116172356218's progress line runs into it, and on a line of its own.
+        status = self.status(f'echo "..F.{NODE_DOWN}"\necho "[gw2] node down: Not properly terminated"\n'
+                             'echo "replacing crashed worker gw2"\nexit 1\n')
+        self.assertEqual(status['crashed_workers'], '2')
+        self.assertEqual(status['memory_errors'], '0')
+
+    def test_a_java_out_of_memory_line_is_no_memory_error(self) -> None:
+        """``-w``: the flag, and Java's ``OutOfMemoryError``, are not Python's ``MemoryError``."""
+        status = self.status('echo "heap $GRAAL_PYTHON_VM_ARGS"\necho "java.lang.OutOfMemoryError: Java heap space"\n'
+                             'echo "E   MemoryError"\necho "MemoryError: out of memory"\nexit 1\n')
+        self.assertEqual(status['memory_errors'], '2')
+
+    def test_the_summary_warns_of_the_lost_workers(self) -> None:
+        (self.temp / 'tests-status').write_text(
+            'exit=1\nscope=12G\nprobe=\nelapsed=6000\noom_kills=0\nmemory_errors=0\ncrashed_workers=7\n',
+            encoding='utf-8')
+        result = sh(step(SUMMARY)['run'], self.env, BASH)
+        self.assertEqual(result.returncode, 0, result.stderr)
+        self.assertEqual(workflow_commands(result.stdout), [
+            '::warning title=tests lost an xdist worker on Python graalpy-25.4 (experimental%2C non-blocking)::7 '
+            'xdist worker(s) went down, each failing the test it ran, and xdist replaces up to 30; exit 1, scope 12G; '
+            'no resource-monitor sample. Experimental legs never block (#1660), so this job still succeeds.'])
+        self.assertIn('7 worker(s) down', result.stdout)
+
+    def test_a_status_without_the_count_warns_of_nothing_new(self) -> None:
+        """A ``tests-status`` from before #1753, or a partial one, is no crash."""
+        (self.temp / 'tests-status').write_text('exit=1\nscope=12G\noom_kills=0\nmemory_errors=0\n', encoding='utf-8')
+        result = sh(step(SUMMARY)['run'], self.env, BASH)
+        self.assertEqual(result.returncode, 0, result.stderr)
+        self.assertEqual(workflow_commands(result.stdout), [])
+        self.assertIn('0 worker(s) down', result.stdout)
+
+
+if __name__ == '__main__':
+    unittest.main()

tests/project/test_resource_monitor_1740.py

@@ -194,8 +194,9 @@ def test_the_stop_step_passes_on_a_leg_the_monitor_never_started(self) -> None:
         self.assertEqual(stop.stdout, 'The resource monitor did not start on this leg.\n')
 
 
-#: Round 2's containment, as the issue's research sized it (estimates, until a run shows them).
-HEAP, GRAAL_WORKERS, SCOPE_MEMORY = '--vm.Xmx2g', '3', '12G'
+#: Round 2's containment, as the issue's research sized it (estimates, until a run shows them);
+#: #1753 adds the exit on a spent heap, which tests/project/test_graalpy_worker_heap_1753.py pins.
+HEAP, GRAAL_WORKERS, SCOPE_MEMORY = '--vm.Xmx2g --vm.XX:+ExitOnOutOfMemoryError', '3', '12G'
 FSIZE = 2 * 1024 ** 3
 #: Round 3: the probe is the scope itself, every flag included, under a throwaway unit.
 PROBE = 'if probe=$(scoped "pcapkit-probe-$$.scope" true 2>&1); then'
@@ -364,7 +365,8 @@ def test_the_scope_runs_the_tests_under_the_timeout_and_fsize_cap(self) -> None:
         self.assertEqual(workflow_commands(result.stdout), [])
         status = self.status()
         self.assertRegex(status.pop('elapsed'), r'^\d+$')
-        self.assertEqual(status, {'exit': '1', 'scope': '12G', 'probe': '', 'oom_kills': '0', 'memory_errors': '0'})
+        self.assertEqual(status, {'exit': '1', 'scope': '12G', 'probe': '', 'oom_kills': '0', 'memory_errors': '0',
+                                  'crashed_workers': '0'})
 
     def test_without_a_scope_the_tests_run_uncapped_with_a_warning(self) -> None:
         self.stub('sudo', 'echo "sudo: a password is required" >&2\nexit 1\n')

tests/project/test_sweeps_on_latest_only_1732.py

@@ -172,6 +172,8 @@ def test_every_other_leg_runs_the_rest(self) -> None:
             if is_experimental(leg):
                 # #1740: the experimental step's own worker count, 3 on GraalPy and `auto` on the rest.
                 want[want.index('-n') + 1] = step_env(leg, EXPERIMENTAL)['WORKERS']
+                # #1753: and its replacements for crashed workers, after `--dist load`.
+                want.insert(want.index('--dist') + 2, '--max-worker-restart=30')
             with self.subTest(python=version):
                 self.assertNotIn('coverage', argv)
                 self.assertEqual(argv[:2], ['-m', 'pytest'])