Skip to content

Long line deadlock fix - #241

Merged
hcallahan-lowrisc merged 2 commits into
lowRISC:masterfrom
hcallahan-lowrisc:long_line_deadlock_fix
Aug 7, 2026
Merged

Long line deadlock fix#241
hcallahan-lowrisc merged 2 commits into
lowRISC:masterfrom
hcallahan-lowrisc:long_line_deadlock_fix

Conversation

@hcallahan-lowrisc

@hcallahan-lowrisc hcallahan-lowrisc commented Aug 6, 2026

Copy link
Copy Markdown
Contributor

Description

Fixes #240
Commit messages describe the fixes, and 5 new unit tests are added in support of this.

Checklist

  • All commits are signed off (git commit -s), indicating acceptance of the CLA
  • Commit messages follow the conventional commit format (<type>[(<scope>)][!]: <description>)
    • The commit type correctly reflects the semver impact of the change
    • Breaking changes are marked with ! or a BREAKING CHANGE: footer
  • New behaviour is covered by tests

@AlexJones0 AlexJones0 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks - mostly looks good to me, I just have a couple of small suggestions.

Comment thread src/dvsim/runtime/local.py Outdated
Comment thread src/dvsim/runtime/local.py Outdated
Comment thread src/dvsim/runtime/local.py Outdated
log.exception(
"Error while streaming subprocess output to log file for job '%s'.",
handle.spec.full_name,
)

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would recommend logging the exception here as well (except Exception as e, etc.)

But actually, I think a better fix (untested), would be to change the asyncio.gather(...) to use return_exceptions=False, to stop the exceptions being aggregated.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

log.exception prints the trace as well as the message. This is now checked as part of a new test as well:

$ python -m pytest "tests/test_runtime.py::TestLocalBackendStreaming::test_reader_error_is_logged_not_raised" -s -o log_cli=true --log-cli-level=ERROR

<...>

tests/test_runtime.py::TestLocalBackendStreaming::test_reader_error_is_logged_not_raised [E 260807 12:06:43 plugin:178] Error while streaming subprocess output to log file for job 'job'.
Traceback (most recent call last):
  File "/home/harry/projects/dvsim/src/dvsim/runtime/local.py", line 109, in _log_from_pipe
    handle.log_file.write(decoder.decode(chunk))
    ~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/harry/projects/dvsim/tests/test_runtime.py", line 230, in write
    raise OSError("simulated disk-full")
OSError: simulated disk-full
PASSED

…ines

LocalRuntimeBackend._log_from_pipe drained subprocess stdout/stderr with
`async for line in stream`, which calls StreamReader.readline(). readline()
raises LimitOverrunError (surfaced as ValueError) once a single line exceeds
the StreamReader limit — 64 KiB by default, as create_subprocess_exec was
invoked with no `limit=`. A tool emitting a very long line without a newline
(e.g. Jasper's cov-unr UNR report, observed at 116 398 chars) crashed the
reader task. With no consumer, asyncio paused the transport, the OS pipe
filled, the tool blocked writing to it, and `await process.wait()` hung
forever. The legacy launcher wrote tool output straight to the log fd
and could not deadlock this way, so the async rewrite was the regression.

Read fixed-size chunks via StreamReader.read() instead, which imposes no
line-length limit. An incremental UTF-8 decoder (surrogateescape) handles
multibyte characters that straddle a chunk boundary.

Harden the reader against a recurrence:
- Broaden the `except` so an unexpected error is logged via log.exception
  rather than silently killing the reader task (which would re-deadlock the
  pipe), while still passing asyncio.CancelledError through untouched.
- Pass an explicit `limit=` to create_subprocess_exec.

Keep the two concerns as separate constants: SUBPROCESS_STREAM_LIMIT is the
StreamReader/readline buffer cap (64 KiB, matching the asyncio default) and
SUBPROCESS_READ_CHUNK_SIZE is the read() chunk size used in _log_from_pipe.

Signed-off-by: Harry Callahan <hcallahan@lowrisc.org>
The existing runtime tests only exercised the backend registry and never
launched a subprocess, so regressions in _log_from_pipe (empty logs, a
NameError, or a re-introduced deadlock) passed CI unnoticed.

Add TestLocalBackendStreaming:

- streams stdout to the log and passes. The sentinel is emitted via chr()
  codes so it cannot appear in the "[Executing]" command preamble the
  monitor writes, i.e. the assertion only holds if real subprocess output
  was captured.
- a single line far larger than the 64 KiB StreamReader limit is logged
  without deadlocking. Regression test for the original readline()
  LimitOverrunError bug; @timeout turns a re-regression into a failure
  rather than a hang.
- a multibyte UTF-8 character split across a read-chunk boundary decodes
  correctly (incremental decoder).
- an unexpected log-write error is caught and reported via log.exception
  rather than propagating (a dead reader would re-deadlock the pipe).
- normal cancellation is silent (no error logged).

Confirmed these fail on both the original readline deadlock and a
bare-name NameError in the read loop.

Signed-off-by: Harry Callahan <hcallahan@lowrisc.org>
@hcallahan-lowrisc

Copy link
Copy Markdown
Contributor Author

Addressed review comments and added 5 unit tests covering the failure mode / new implementation.

@hcallahan-lowrisc
hcallahan-lowrisc added this pull request to the merge queue Aug 7, 2026
Merged via the queue into lowRISC:master with commit 56f61b1 Aug 7, 2026
6 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

LocalRuntimeBackend deadlocks when a job emits a line ≥ 64 KiB on stdout/stderr

2 participants