Skip to content

Commit fbb6d55

Browse files
authored
fix: make the session tests robust to CI load (ROADMAP.md #72) (#91)
* fix: make the session tests robust to CI load (ROADMAP.md #72) start_session reads DOCX_SESSION_START_TIMEOUT for its budget (explicit argument wins, 30 s default unchanged) and a start that runs out of budget now reports which phase timed out, whether the kernel was still alive, the load average, the connection-file summary and the kernel's stderr. CI sets the variable to 120. The session tests replace their six timing sleeps with a handshake on the kernel's execute_input broadcast, replace the wall-clock stop assertion with a behavioural one (no signal sent, kernel gone), and add fake-kernel regression tests for the diagnosed failure shape: connection file present, control channel never answering. * fix: prefix the start-budget env var, reject inf, bound the CI job (ROADMAP.md #72) DOCX_SESSION_START_TIMEOUT becomes DOCX_EDITOR_SESSION_START_TIMEOUT, matching the repo's one existing env var before the name ships. The budget now rejects inf (an unbounded wait defeats the diagnostic), CI sets 60 instead of 120 and bounds the job at 45 minutes so a runner where every kernel start times out fails in bounded time. The three fake-kernel tests that only checked the error text now also prove the stand-in died, the stop-session kill spy filters on the kernel's pid, and the second-phase budget is computed at its use so the report cannot total more than the budget.
1 parent 4166c3c commit fbb6d55

5 files changed

Lines changed: 407 additions & 78 deletions

File tree

‎.github/workflows/main.yml‎

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,9 @@ jobs:
2727

2828
tests-and-type-check:
2929
runs-on: ubuntu-latest
30+
# A wedged runner must fail in bounded time: with every kernel start
31+
# timing out, the session tests alone would otherwise grind for hours.
32+
timeout-minutes: 45
3033
name: tests-and-type-check (${{ matrix.python-version }}, shard ${{ matrix.shard }})
3134
strategy:
3235
matrix:
@@ -53,6 +56,15 @@ jobs:
5356
# Coverage tracing only where the report is uploaded (3.11); the other
5457
# versions run the plain suite.
5558
- name: Run tests
59+
env:
60+
# A kernel start on this runner (2 vCPUs, two xdist workers each
61+
# spawning kernels, coverage tracing on 3.11) can take well over the
62+
# 30 s library default. Doubling covers that; going higher only
63+
# multiplies the wall time of a broken runner, where every start in
64+
# the module times out in sequence. A start that needs more than
65+
# this should fail loudly — the error explains which phase timed
66+
# out — rather than be retried.
67+
DOCX_EDITOR_SESSION_START_TIMEOUT: "60"
5668
run: >-
5769
uv run python -m pytest tests -n auto
5870
--splits 2 --group ${{ matrix.shard }}

‎docx_editor/session.py‎

Lines changed: 139 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@
1212
import argparse
1313
import ast
1414
import json
15+
import math
1516
import os
1617
import re
1718
import signal
@@ -31,6 +32,21 @@
3132

3233
DEFAULT_CONNECTION_FILE = Path.home() / ".cache" / "docx-editor" / "kernel.json"
3334

35+
# start_session's default budget, and the environment variable that overrides
36+
# it. A kernel start is a fresh interpreter importing ipykernel + IPython; on a
37+
# loaded machine (a 2-vCPU CI runner with parallel test workers, coverage
38+
# tracing on) that import alone can take longer than the unloaded 30 s default.
39+
DEFAULT_START_TIMEOUT = 30.0
40+
START_TIMEOUT_ENV = "DOCX_EDITOR_SESSION_START_TIMEOUT"
41+
42+
# How the kernel is launched. Tests substitute a stand-in kernel here to
43+
# exercise the start-failure paths deterministically; the "-f <file>" argument
44+
# is appended by start_session.
45+
_KERNEL_COMMAND = (sys.executable, "-m", "ipykernel_launcher")
46+
47+
# Bytes of kernel stderr kept in a start-failure diagnostic.
48+
_STDERR_TAIL_BYTES = 4096
49+
3450
_EXTRA_HINT = "Session mode requires extra dependencies: pip install 'docx-editor[session]'"
3551

3652

@@ -131,29 +147,116 @@ def _read_pid(connection_file: Path) -> int | None:
131147
return None
132148

133149

134-
def start_session(connection_file: Path = DEFAULT_CONNECTION_FILE, timeout: float = 30.0) -> int:
150+
def _start_timeout() -> float:
151+
"""start_session's budget: DOCX_EDITOR_SESSION_START_TIMEOUT, else the 30 s default.
152+
153+
Raises:
154+
SessionError: If the variable is set to anything but a positive number.
155+
"""
156+
raw = os.environ.get(START_TIMEOUT_ENV, "").strip()
157+
if not raw:
158+
return DEFAULT_START_TIMEOUT
159+
try:
160+
value = float(raw)
161+
if not (math.isfinite(value) and value > 0): # rejects nan and inf too
162+
raise ValueError
163+
except ValueError:
164+
raise SessionError(f"{START_TIMEOUT_ENV} must be a positive number of seconds, got {raw!r}") from None
165+
return value
166+
167+
168+
def _drain_stderr(proc: subprocess.Popen[bytes]) -> str:
169+
"""Tail of what a (killed and reaped) kernel wrote to stderr, without blocking.
170+
171+
Invariant: nothing may read ``proc.stderr`` before this runs — the raw-fd
172+
read below bypasses the ``BufferedReader``, so any bytes already buffered
173+
there would be silently dropped. (Today the only other reader, the
174+
exited-during-startup path, always raises without reaching ``_abort``.)
175+
176+
The pipe is switched to non-blocking first: every writer is dead, so the
177+
read hits EOF at once — but if a grandchild ever inherited the write end,
178+
EAGAIN ends the loop instead of hanging a diagnostic that exists to explain
179+
a hang.
180+
"""
181+
if proc.stderr is None:
182+
return ""
183+
fd = proc.stderr.fileno()
184+
if os.name == "posix":
185+
os.set_blocking(fd, False)
186+
chunks: list[bytes] = []
187+
while True:
188+
try:
189+
chunk = os.read(fd, 65536)
190+
except OSError: # EAGAIN: a writer still holds the pipe open
191+
break
192+
if not chunk:
193+
break
194+
chunks.append(chunk)
195+
return b"".join(chunks)[-_STDERR_TAIL_BYTES:].decode(errors="replace").strip()
196+
197+
198+
def _describe_connection_file(connection_file: Path) -> str:
199+
"""One line on what the kernel managed to write before the budget ran out."""
200+
try:
201+
size = connection_file.stat().st_size
202+
except OSError:
203+
return "Connection file: absent."
204+
try:
205+
info = json.loads(connection_file.read_text(encoding="utf-8"))
206+
return (
207+
f"Connection file: {size} bytes, {info['transport']} {info['ip']}, "
208+
f"shell={info['shell_port']} control={info['control_port']}."
209+
)
210+
except (OSError, ValueError, KeyError, TypeError) as e:
211+
return f"Connection file: {size} bytes, unreadable: {e}."
212+
213+
214+
def _load_average() -> str:
215+
"""Suffix "; load average N.NN" where the platform reports one, else ""."""
216+
if not hasattr(os, "getloadavg"): # Windows
217+
return ""
218+
try:
219+
return f"; load average {os.getloadavg()[0]:.2f}"
220+
except OSError:
221+
return ""
222+
223+
224+
def start_session(connection_file: Path = DEFAULT_CONNECTION_FILE, timeout: float | None = None) -> int:
135225
"""Start a detached IPython kernel and wait until it answers.
136226
137227
Args:
138228
connection_file: Where to write the kernel connection file
139-
timeout: Seconds to wait for the kernel to become ready
229+
timeout: Seconds to wait for the kernel to become ready. ``None`` (the
230+
default) reads ``DOCX_EDITOR_SESSION_START_TIMEOUT`` and falls back to
231+
30 s when it is unset or blank; an explicit argument always wins.
232+
The variable exists for loaded machines — CI runners, parallel
233+
test workers — where a fresh interpreter importing IPython takes
234+
far longer than it does interactively. ``docx-session start``
235+
has no flag for it and reaches the variable through this default.
140236
141237
Returns:
142238
PID of the kernel process.
143239
144240
Raises:
145241
SessionError: If a session is already running, the kernel fails to
146-
start, or the connection file it wrote is unreadable.
242+
start, the connection file it wrote is unreadable, or
243+
``DOCX_EDITOR_SESSION_START_TIMEOUT`` is not a positive number.
244+
A start that runs out of budget explains itself: which phase
245+
timed out (connection file vs. control-channel reply), whether
246+
the kernel was still alive, the load average, what it wrote to
247+
stderr, and the variable to raise.
147248
ImportError: If the [session] extra is not installed.
148249
"""
250+
if timeout is None:
251+
timeout = _start_timeout()
149252
if is_session_running(connection_file):
150253
raise SessionError(f"Session already running (connection file: {connection_file})")
151254

152255
connection_file.parent.mkdir(parents=True, exist_ok=True)
153256
connection_file.unlink(missing_ok=True)
154257

155258
proc = subprocess.Popen(
156-
[sys.executable, "-m", "ipykernel_launcher", "-f", str(connection_file)],
259+
[*_KERNEL_COMMAND, "-f", str(connection_file)],
157260
stdout=subprocess.DEVNULL,
158261
# Keep stderr so a failed start (e.g. missing ipykernel) can explain itself.
159262
stderr=subprocess.PIPE,
@@ -162,14 +265,32 @@ def start_session(connection_file: Path = DEFAULT_CONNECTION_FILE, timeout: floa
162265
)
163266
_pid_file(connection_file).write_text(str(proc.pid), encoding="utf-8")
164267

165-
def _abort(message: str) -> SessionError:
268+
def _abort(summary: str) -> SessionError:
269+
# Sampled before the kill so the report says what the kernel was doing
270+
# at the timeout, not what the kill did to it.
271+
exit_code = proc.poll()
166272
proc.kill()
167273
proc.wait()
274+
kernel = "was still alive at the timeout" if exit_code is None else f"had exited with code {exit_code}"
275+
stderr = _drain_stderr(proc)
276+
report = "\n".join([
277+
summary,
278+
f"Kernel pid {proc.pid} {kernel}{_load_average()}.",
279+
_describe_connection_file(connection_file),
280+
"Kernel stderr:",
281+
"\n".join(f" {line}" for line in stderr.splitlines()) if stderr else " (empty)",
282+
f"Set {START_TIMEOUT_ENV} to raise the budget on a loaded machine.",
283+
])
168284
connection_file.unlink(missing_ok=True)
169285
_pid_file(connection_file).unlink(missing_ok=True)
170-
return SessionError(message)
171-
172-
deadline = time.monotonic() + timeout
286+
return SessionError(report)
287+
288+
# Two phases share one budget. The connection file is written as soon as
289+
# the sockets are bound — *before* ipykernel imports IPython and wires the
290+
# control channel — so its appearance is an early signal, and the second
291+
# phase gets whatever is left (floored at 1 s).
292+
t0 = time.monotonic()
293+
deadline = t0 + timeout
173294
while not (connection_file.exists() and connection_file.stat().st_size > 0):
174295
if proc.poll() is not None:
175296
stderr = proc.stderr.read().decode(errors="replace").strip() if proc.stderr else ""
@@ -178,8 +299,11 @@ def _abort(message: str) -> SessionError:
178299
detail = f"\n{stderr}" if stderr else ""
179300
raise SessionError(f"Kernel process exited during startup (code {proc.returncode}). {hint}{detail}".strip())
180301
if time.monotonic() > deadline:
181-
raise _abort(f"Kernel did not start within {timeout}s")
302+
raise _abort(
303+
f"Kernel did not start within {timeout}s: no connection file after {time.monotonic() - t0:.1f}s."
304+
)
182305
time.sleep(0.1)
306+
t_file = time.monotonic() - t0
183307

184308
kc = None
185309
try:
@@ -190,8 +314,12 @@ def _abort(message: str) -> SessionError:
190314
kc = _client(connection_file)
191315
except (ValueError, OSError) as e:
192316
raise SessionError(f"Kernel wrote an unreadable connection file ({connection_file}): {e}") from e
193-
if not _kernel_alive(kc, timeout=max(1.0, deadline - time.monotonic())):
194-
raise SessionError(f"Kernel did not become ready within {timeout}s")
317+
remaining = max(1.0, deadline - time.monotonic())
318+
if not _kernel_alive(kc, timeout=remaining):
319+
raise _abort(
320+
f"Kernel did not become ready within {timeout}s: kernel.json appeared after {t_file:.1f}s, "
321+
f"then no kernel_info reply on the control channel in the remaining {remaining:.1f}s."
322+
)
195323
except BaseException:
196324
# Never leave a half-started kernel behind with no way to reach it.
197325
if proc.poll() is None:

‎skills/docx/SKILL.md‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1176,6 +1176,8 @@ scripts. The document (and all your variables) stays open between commands:
11761176
```bash
11771177
# Requires: pip install "docx-editor[session]"
11781178
docx-session start
1179+
# On a loaded machine (CI, parallel workers) set DOCX_EDITOR_SESSION_START_TIMEOUT=60
1180+
# to raise the 30 s budget `start` gives the kernel to answer.
11791181

11801182
# Use ABSOLUTE paths: the kernel keeps the cwd it was started in, which is not
11811183
# necessarily the cwd of a later exec. `start` prints the cwd it captured.

‎tests/conftest.py‎

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -180,10 +180,12 @@ def counting(root, tags, **kwargs):
180180
def _connection_file_from_argv(args) -> Path | None:
181181
"""Return the ``-f <path>`` of an ipykernel_launcher command line, else None.
182182
183-
``start_session`` always spawns the kernel as
183+
``start_session`` spawns the kernel as
184184
``[python, "-m", "ipykernel_launcher", "-f", <connection file>]``, so the
185185
connection file can be recovered from the argv alone — no cooperation from
186-
the code under test required.
186+
the code under test required. Tests that substitute a stand-in kernel (via
187+
``session_mod._KERNEL_COMMAND`` or a fake ``subprocess``) are invisible to
188+
this reaper and must reap their own processes.
187189
188190
The path is resolved eagerly: cwd is correct now, but two tests chdir
189191
(``test_workspace.py``, ``test_document.py``), so a relative path stored

0 commit comments

Comments
 (0)