fix(debugger): preserve output on command timeout (#114)

Fixes #112.

## What this changes

- Preserve the debugger lines already read when a marked CDB command
times out.
- Bound timeout diagnostics to 2,000 lines and 64 KiB, with a truncation
note.
- Document the preserved output in the timeout troubleshooting guide and
changelog.

## Why

The reader kept output in a private buffer until the completion marker
arrived. A runaway
SOS command such as `!clrstack` could therefore print useful frames and
then lose all of
them when the timeout path fired. The timeout error now includes that
partial output and
also exposes it on `DebuggerError.partial_output`; marker
synchronization and the existing
manual break-in warning are unchanged.

## How it was verified

- The new timeout regression fails on `35b6cdb` and passes with the fix;
the same test
  asserts the preserved line and the bounded diagnostic behavior.
- `test_debug_session.py`: 66 passed.
- Hermetic suite: 103 passed, 12 deselected; full suite: 103 passed, 12
skipped because
  this host has no CDB/KD or Git LFS debugger dumps.
- `uv lock --check`, MCP schema validation, docs formatter,
`compileall`, `uv build`,
  `twine check`, and `git diff --check` passed.

Co-authored-by: Oscar <319719771+Oscar-Williams@users.noreply.github.com>
Co-authored-by: Sven Scharmentke <sven.scharmentke@liasoft.de>
This commit is contained in:
Oscar
2026-09-29 06:39:47 +08:00
committed by GitHub
parent 44fbcccadd
commit c8e2355696
4 changed files with 88 additions and 1 deletions
+4
View File
@@ -15,6 +15,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
and preserve the closing caller's kernel resume policy. Break-in keeps the
validated session record so a concurrent close cannot cause a registry error
(#109, #110). Thanks to @adity982 for the fix.
- A command that times out before reaching its completion marker keeps the
output already read, so the timeout error still shows useful diagnostics from
runaway commands such as SOS `!clrstack`. The retained output is capped at
2,000 lines and 64 KiB (#112, #114). Thanks to @Oscar-Williams for the fix.
## [1.3.0] - 2026-09-10
+3
View File
@@ -50,6 +50,9 @@ A command that exceeds the per-command limit reports a timeout.
- Raise it with [`--timeout`](reference/cli.md#general), for example `--timeout 120`.
- On large dumps, prefer targeted commands over broad analysis.
- The timeout error includes the output read before CDB stopped responding. If the command
produces more than the diagnostic limit, the response ends with a truncation note; increase
the timeout or inspect the target directly for the complete output.
## Module not found (pip installs)
+54 -1
View File
@@ -45,6 +45,12 @@ PROMPT_REGEX = re.compile(r"^\d+:.*>\s*$")
# appended so each command waits for its own, distinct marker.
MARKER_BASE = "COMMAND_COMPLETED_MARKER"
# A runaway debugger command can produce output indefinitely. Keep timeout
# diagnostics useful without turning the error itself into another unbounded
# response.
MAX_PARTIAL_OUTPUT_LINES = 2000
MAX_PARTIAL_OUTPUT_CHARS = 64 * 1024
# How long ``wait_for_break`` blocks by default. Waiting on a resumed target is
# open-ended by nature - you are waiting for a bugcheck or a breakpoint - so this
# is deliberately unrelated to the per-command timeout.
@@ -69,6 +75,10 @@ RESUME_CONFIRM_TIMEOUT = 0.5
class DebuggerError(Exception):
"""Raised for any debugger session failure (launch, timeout, I/O)."""
def __init__(self, message: str, *, partial_output: Optional[List[str]] = None):
super().__init__(message)
self.partial_output = list(partial_output or [])
class _ReleaseOnExit:
"""Context manager that releases an already-acquired lock on exit."""
@@ -230,6 +240,10 @@ class DebuggerSession:
self.verbose = verbose
self.output_lines: List[str] = []
#: The reader's current command buffer. It is published under the same
#: lock as marker state so a timeout can retain output before the marker
#: arrives, even though the reader owns the list itself.
self._reader_buffer: Optional[List[str]] = None
self.lock = threading.Lock()
#: Serializes whole operations on the debugger's stdin. ``self.lock``
#: only guards individual field writes; it cannot make "install a
@@ -302,6 +316,8 @@ class DebuggerSession:
return
buffer: List[str] = []
with self.lock:
self._reader_buffer = buffer
try:
for line in self.process.stdout:
line = line.rstrip()
@@ -318,6 +334,7 @@ class DebuggerSession:
if self._expected_marker and self._expected_marker in line:
self.output_lines = buffer
buffer = []
self._reader_buffer = buffer
self._expected_marker = None
self.ready_event.set()
continue
@@ -340,6 +357,35 @@ class DebuggerSession:
self.output_lines = []
return result
def _snapshot_partial_output(self) -> List[str]:
"""Return bounded output read before the current marker arrived."""
with self.lock:
lines = list(self._reader_buffer or [])
bounded: List[str] = []
char_count = 0
truncated = False
for line in lines:
if len(bounded) >= MAX_PARTIAL_OUTPUT_LINES:
truncated = True
break
remaining = MAX_PARTIAL_OUTPUT_CHARS - char_count
if remaining <= 0:
truncated = True
break
if len(line) + 1 > remaining:
bounded.append(line[: max(0, remaining - 1)])
truncated = True
break
bounded.append(line)
char_count += len(line) + 1
if truncated:
bounded.append(
"[partial output truncated; increase the command timeout or inspect the target directly]"
)
return bounded
def _abandon_marker(self) -> bool:
"""Give up on the marker currently being waited for.
@@ -510,6 +556,7 @@ class DebuggerSession:
if self._closing:
raise DebuggerError("Session was closed while the command was running")
if not landed and not self._marker_landed():
partial_output = self._snapshot_partial_output()
resynced = self._abort_running_command()
detail = "" if resynced else " (session may need a manual break-in)"
# The break-in output is the only record of why the target stopped
@@ -519,8 +566,14 @@ class DebuggerSession:
if preamble
else ""
)
partial = (
"\nPartial output before timeout:\n" + "\n".join(partial_output)
if partial_output
else ""
)
raise DebuggerError(
f"Command timed out after {cmd_timeout} seconds: {command}{detail}{lost}"
f"Command timed out after {cmd_timeout} seconds: {command}{detail}{lost}{partial}",
partial_output=partial_output,
)
pipe_output = self._take_output()
@@ -231,6 +231,33 @@ def test_timeout_raises_when_marker_never_arrives(make_session):
assert "timed out" in str(exc.value).lower()
def test_timeout_error_preserves_output_seen_before_marker(make_session):
"""A command that never reaches its marker must retain useful output."""
session, proc = make_session(timeout=1)
proc._swallow = True
with pytest.raises(DebuggerError) as exc:
session.send_command("!clrstack", timeout=1)
message = str(exc.value)
assert "timed out" in message.lower()
assert "OUT:!clrstack" in message
assert exc.value.partial_output == ["OUT:!clrstack"]
def test_partial_timeout_output_has_line_and_size_limits(make_session):
session, _ = make_session(timeout=1)
with session.lock:
session._reader_buffer = ["frame"] * (debug_session.MAX_PARTIAL_OUTPUT_LINES + 1)
lines = session._snapshot_partial_output()
assert len(lines) == debug_session.MAX_PARTIAL_OUTPUT_LINES + 1
assert lines[-1].startswith("[partial output truncated;")
with session.lock:
session._reader_buffer = ["x" * debug_session.MAX_PARTIAL_OUTPUT_CHARS]
lines = session._snapshot_partial_output()
assert lines[-1].startswith("[partial output truncated;")
# -- go-class commands ----------------------------------------------------
#
# The bug these cover: 'g' hands the CPU to the target, after which the debugger