Skip to content

fix: log named pipe disconnects and timeouts in FrontendRunner requests - #285

Merged
baxeaz merged 1 commit into
OpenJobDescription:mainlinefrom
baxeaz:fix/log-named-pipe-request-failures
Nov 3, 2026
Merged

baxeaz merged 1 commit into
OpenJobDescription:mainlinefrom
baxeaz:fix/log-named-pipe-request-failures

Conversation

@baxeaz

@baxeaz baxeaz commented Nov 2, 2026

Copy link
Copy Markdown
Contributor

What was the problem/requirement? (What/Why)

On Windows, FrontendRunner._send_request logs Failed to send {path} request: ... only when the named pipe call raises pywintypes.error. NamedPipeHelper raises its own PipeDisconnectedException and NamedPipeTimeoutError for a broken pipe or a read/connect timeout, and neither derives from pywintypes.error. Those errors propagate without any log line saying which request failed or how long it took.

We hit this with an adaptor whose foreground command failed during a long startup with only:

  ERROR: Entrypoint failed: An error occurred: The pipe has been ended. (Error code: 109) in function ReadFile

That error means the backend closed the connection without replying. The backend does this when its 5s request read in ResourceRequestHandler.instance_thread times out, when a handle is closed without a response, or when the backend process exits. Telling these apart needs the request path and how long the frontend waited.

What was the solution? (How)

  • _send_request now also catches PipeDisconnectedException and NamedPipeTimeoutError, logs them the same way as pywintypes.error, and re-raises. Behavior is otherwise unchanged.
  • The log line now includes the elapsed time: Failed to send /heartbeat request after 5.02s: An error occurred: The pipe has been ended. (Error code: 109) in function ReadFile. A disconnect after about 5s points at the backend's request read timeout; a disconnect after a few milliseconds points at a closed handle or an exited backend.

What is the impact of this change?

One extra error log line on the frontend when a named pipe request fails on Windows. The same exceptions are raised as before. POSIX is unaffected.

How was this change tested?

See DEVELOPMENT.md for information on running tests.

  • Have you run the unit tests?
  • Yes. test_raises_when_request_fails in TestSendRequestInWindows is now parametrized over pywintypes.error, PipeDisconnectedException, and NamedPipeReadTimeoutError, and
    checks the logged path, elapsed time, and error text.
  • Windows Server 2022, Python 3.11.9: test_frontend_runner.py passes (26 passed, 5 skipped). With the source change reverted, all three parametrized cases fail, so the test covers the change. The rest of the unit suite passed except two tests that fail the same way without this change in that environment (the session ran as SYSTEM, where LookupAccountName returns 1332, plus an argparse difference in test_raises_jsonschema_validation_err).
  • Linux: hatch run test for test_frontend_runner.py passes (Windows cases skipped); hatch run lint passes.
  • Separately, against 0.9.6 on Windows, I confirmed which backend behaviors produce the error 109 message on the client: a backend request-read timeout (client pauses more than 5s between connect and write), a handle closed without a reply, and a backend process exit all do. A handler exception returns a 500, and a slow handler produces NamedPipeReadTimeoutError instead.

Was this change documented?

  • Are relevant docstrings in the code base updated?
    • No docstring changes needed; a short comment explains why the extra exception types are caught.

Is this a breaking change?

No.

Does this change impact security?

No. The log line contains the request path and the exception message, which were already logged for pywintypes.error. No request bodies or parameters are logged.


By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

On Windows, FrontendRunner._send_request logged "Failed to send {path}
request" only for pywintypes.error. NamedPipeHelper raises its own
PipeDisconnectedException and NamedPipeTimeoutError, which do not derive
from pywintypes.error, so a broken pipe or read timeout during a heartbeat
propagated without saying which request failed.

Catch those exceptions as well, and include the elapsed time so the log
shows whether the backend closed the connection at once or after its own
request read timeout.

Signed-off-by: Brian Axelson <86568017+baxeaz@users.noreply.github.com>
@github-actions

github-actions Bot commented Nov 2, 2026

Copy link
Copy Markdown

Claude review · advisory

Reviewed 0e1e4ee (full review): 0 findings.

Open: 0 blocking · 0 should-fix · 0 nit. ✅ Nothing blocking.

Fix or reply to each thread; the next revision's review re-checks open threads and resolves those it agrees are handled. Resolving a thread yourself also closes it. Later revisions review only what changed.

@baxeaz
baxeaz merged commit 9c8d54e into OpenJobDescription:mainline Nov 3, 2026
25 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants