Skip to content

iris-ci: the socket read timeout must follow the caller's deadline - #67

Merged
techomancer merged 1 commit into
techomancer:mainfrom
sgidevnet:fix/iris-ci-read-timeout
Aug 1, 2026
Merged

iris-ci: the socket read timeout must follow the caller's deadline#67
techomancer merged 1 commit into
techomancer:mainfrom
sgidevnet:fix/iris-ci-read-timeout

Conversation

@mach-kernel

@mach-kernel mach-kernel commented Jul 31, 2026

Copy link
Copy Markdown
Contributor

send_tcp and send_unix pinned the client read timeout at 300s, while --timeout reached only the server as wait-serial's timeout_ms. Any guest command over five minutes failed with connect: Resource temporarily unavailable (os error 11) while the guest carried on and finished the work, so the console showed no error and --timeout looked like it did nothing.

Changes
  • send_until takes the read timeout the caller needs; send keeps 300s for commands that answer promptly.
  • The three wait-serial sites that carry a caller deadline derive from it: cmd_serial_wait (:527), run_capture (:591), and the deadline-based waiter (:688). Nothing else changes behaviour.
  • READ_TIMEOUT_GRACE is 30s on top of the guest deadline, so the server's own timeout fires first and names the pattern it missed rather than the client bailing with a connection error.
  • send_tcp takes the same parameter for symmetry. TCP mode is unexercised here.
  • Every io error funnelled into Error::Connection and printed as connect <socket>, so an expired read deadline reported as a failure to connect. WouldBlock and TimedOut now say so. That message is what hid this bug: the socket was always fine.
  • The two fixed-deadline wait-serial sites (Password: at 5000 ms, the shell sentinel at 8000 ms) route through read_timeout_for as well. They were already correct against the old default; this makes the invariant hold by construction.
Coverage / needs eyes
  • Reproducer, on a restored guest with nothing else touching the socket: iris-ci run --shell sh --timeout 900 'sleep 400; echo LONG_OK'. Before: 5m14 and 5m29 across two runs, both EAGAIN. After: LONG_OK.
  • sleep 120 succeeded throughout at 2m04, which is what kept this hidden. Anything short works.
  • cargo build --release --bin iris-ci --features chd,lightning,rex-jit clean.
  • Unix socket only. send_tcp takes the same change and I have not run it.
  • Downstream: sgidevnet/irix-actions-runner runs each CI job as one iris-ci run with --timeout 14000. Every job step over five minutes died, the container exited 1, and the runner reported no step conclusion because the guest was never asked. A 20m34s job passes with this in.
  • Review raised two ceilings this does not address, both worth their own change: validate and pull/push have no --timeout at all and can exceed 300s on a large snapshot or a slow registry; and z85c30.rs:1170 rescans the whole accumulated buffer on every byte under wait_for, which is superlinear for a long command producing real output. My reproducer emits almost nothing, so it would not have caught the latter.
  • read_timeout_for adds 30s to a Duration::from_millis(timeout_ms); a caller passing a timeout_ms near u64::MAX would overflow in debug. Every current caller derives it from a --timeout in seconds.

mach-kernel added a commit to sgidevnet/irix-actions-runner that referenced this pull request Jul 31, 2026
This reverts commit db304ab. The panic I blamed was a misread: make test was
not killing the guest, iris-ci was giving up on the socket at 300s while the
guest kept working. Fixed in techomancer/iris#67 and the worker image carries
it now.
@mach-kernel
mach-kernel marked this pull request as ready for review July 31, 2026 13:52
@techomancer

Copy link
Copy Markdown
Owner

hey it looks good but few issues.
it changes release name to sgidevnet which probably needs to stay downstream
it needs to be rebased on latest
and again lets do a single commit

send_tcp and send_unix pinned the client read timeout at 300s while
--timeout was passed only to the server as wait-serial's timeout_ms. Any
guest command over five minutes therefore failed with

    iris-ci: connect /tmp/iris.sock: Resource temporarily unavailable (os error 11)

while the guest carried on and finished the work, so the console showed no
error and --timeout looked like it did nothing.

Reproducer, on a restored guest with nothing else on the socket:

    iris-ci run --shell sh --timeout 900 'sleep 400; echo LONG_OK'

Before: 5m14 and 5m29 across two runs, both EAGAIN. After: LONG_OK.
sleep 120 succeeded either way, which is what kept this hidden.

300s stays the default for commands that answer promptly. The three
wait-serial sites that carry a caller deadline derive the read timeout from
it, plus 30s so the server's own timeout fires first and names the pattern
it missed. The two fixed-deadline sites, at 5000 and 8000 ms, go through
read_timeout_for as well; they were already correct against the old default,
this makes the invariant hold by construction.

Every io error funnelled into Error::Connection and printed as "connect
<socket>", so a read deadline that expired mid-command reported as a failure
to connect and sent the reader to the wrong end. WouldBlock and TimedOut now
say so. That message is what hid this bug: the socket was always fine.
@mach-kernel
mach-kernel force-pushed the fix/iris-ci-read-timeout branch from 34155a2 to d53bb99 Compare August 1, 2026 18:19
@mach-kernel

Copy link
Copy Markdown
Contributor Author

Sorted

@techomancer
techomancer merged commit fc3a7a1 into techomancer:main Aug 1, 2026
1 check 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.

2 participants