Skip to content

Tell a stalled source apart from a slow one, and honour a cancel during it - #10

Open
owenpkent wants to merge 4 commits into
network-drop-retryfrom
stall-watchdog
Open

owenpkent wants to merge 4 commits into
network-drop-retryfrom
stall-watchdog

Conversation

@owenpkent

Copy link
Copy Markdown
Owner

Summary

The previous PR retries a network source whose session errors. This one handles the case with no error at all: a hung handle simply stops returning bytes. Nothing could be retried, and nothing could tell it from a link that was merely crawling — the queue kept displaying the last rate it measured while the job sat frozen.

Time bytes, not chunks

The detail that makes this trustworthy. At the 350 KB/s I actually saw over a degraded VPN link, one 8 MiB chunk legitimately takes 23 seconds — so a timer watching chunk arrivals would report a perfectly healthy copy as stalled.

Reads are now assembled from 1 MiB sub-reads that stamp a heartbeat, decoupling the liveness signal from the chunk size the queue and hashers are tuned for. test_a_slow_link_is_not_a_stall is the guard: each sub-read lands inside the threshold while the chunk they build takes several times longer than it.

A gap past --stall-after (15 s, 0 disables) reports a stalled stage, the queue shows no data for 34s in place of a rate that has stopped being true, and the file is named in the job's warnings afterwards — same principle as a recovered read being reported.

No watchdog thread

The roadmap entry assumed this needed one. It did not: the consumer already runs on a different thread from the read it waits on, which is all a watchdog requires. Its chunks.get() just had no timeout.

A cancel bug, found by a test

Polling that wait let the checkpoint be checked mid-stall, so a cancel is honoured during a hang. Writing the test for that exposed a real bug: teardown did while thread.is_alive() with no deadline, so cancelling a job whose source had stopped responding waited for the operating system timeout anyway — the very thing the operator was escaping. The join is now bounded; a reader still blocked after a second is left behind, being a daemon holding one source handle that it closes itself.

What this does not do

It cannot abort the read. Recovery still waits for the OS to turn the hang into one of the codes from the previous PR — on Windows up to SessionTimeout, 60 s. Written up under "What is still not protected" in docs/data-safety.md, and the roadmap entry now names the mechanism that would fix it (CancelIoEx via ctypes, Windows-only).

Test plan

  • tests/test_stall.py — hung read reported; a stall still produces a verified copy; a slow link is not a stall; 0 disables; cancel honoured mid-hang (cancelled from another thread while the read sleeps, so it cannot pass trivially)
  • Full suite 486 passed, 3 skipped; ruff clean
  • CLI progress field widened to 7 so stalled does not shift every column after it

…ng it

A hung network handle raises nothing. It stops returning bytes, so there was
no error to retry and no way to distinguish it from a link crawling: the queue
went on showing whatever rate it last measured while the job sat frozen, and
the operator had only the progress bar to judge by.

Time the bytes rather than the chunks. Reads are assembled from 1 MiB
sub-reads that stamp a heartbeat, so the liveness signal is independent of the
8 MiB chunk the queue and the hashers work in. That matters: at 350 KB/s a
single chunk legitimately takes half a minute, and a chunk-granularity timer
would call a working copy stalled. A gap past the threshold reports a
"stalled" stage, the queue says "no data for 34s" instead of a rate that has
stopped being true, and the file is named in the job's warnings at the end.

No watchdog thread was needed: the consumer already runs on a different
thread from the read it waits on, which is all a watchdog requires. Polling
that wait also fixed a cancel that could not be honoured — the checkpoint is
now checked while waiting, and teardown no longer joins a blocked reader
without a deadline, which had made cancelling a hung job wait for the very
timeout the operator was trying to escape.

Reporting only: the read still cannot be aborted, so recovery waits for the
operating system to turn the hang into an error. Recorded under what is not
protected in data-safety.md, and left on the roadmap with the mechanism named.
The sub-reads are on the data path, which makes them the part of this change
worth attacking. A fencepost in that loop drops or duplicates bytes at a
boundary, and because the checksum is computed from whatever the loop
produced, a corrupted copy would faithfully match a corrupted source and
verify clean at every level. So the sizes either side of a sub-read and a
chunk boundary are compared against the bytes on disk and against a hash
taken independently, not against another run of the same code.

A short read gets its own test. read(n) returning fewer than n bytes does not
mean end of file, and a loop that assumed it did would truncate every chunk
to the first short read while still hashing consistently, since both sides
see the same truncation.

The display half was untested and is where the actual lie was: no progress
events arrive during a stall, so the throughput column kept showing the last
rate it measured. Covered now — no rate and no ETA while stalled, the rate
still shown when bytes are moving, the clock started once per stall rather
than restamped on every poll, and cleared when data resumes.

@owenpkent owenpkent left a comment

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

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

Reviewed source-wait detection, stall/resume reporting, retry-wait behavior, cancellation handling, and GUI propagation. The displayed elapsed stall duration loses the initial threshold interval; details inline.

Validation: 22 targeted stall and GUI tests passed on this head; git diff --check passed. These checks used synthetic blocked reads/headless Qt, not a physical reader or operating-system I/O stall.

Comment thread src/offloader/gui/worker.py Outdated
# stall's own rather than the age of the last one seen.
if stage == "stalled":
if item.stalled_since is None:
item.stalled_since = time.monotonic()

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

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

[P2] Include the silence already observed in the displayed stall duration.

The engine emits the first stalled event only after stall_after has elapsed, but stalled_since starts at the time that event reaches the GUI. With the default threshold, a source that has supplied no bytes for 15 seconds initially displays “no data for 0s” and continues to understate the outage by about 15 seconds.

The engine already computes the actual idle duration in note_stall. Carry that value, or the last-byte timestamp, through the progress signal and initialize the displayed clock from it. Add a controlled-clock regression asserting that the first displayed stalled duration includes the threshold, rather than only testing that the duration grows after the warning.

The first stalled event fires only once stall_after has elapsed, and the GUI
started its clock when that event arrived. So a source that had supplied no
bytes for fifteen seconds first displayed "no data for 0s", and went on
understating the outage by the whole threshold for as long as it lasted. That
figure is what someone reads to decide whether to go and look at the cable,
and understating it by the default threshold is understating it by the only
amount that matters at the point they first see it.

note_stall already had the real idle duration - it is the number the "stalled
for up to Ns" warning is built from - and was throwing it away at the event
boundary. ProgressEvent carries it now, the runner passes it through, and the
queue backdates its clock by it rather than stamping the arrival.

Four regressions across both halves. On the engine side: the first stalled
event reports at least the threshold, the reported silence never goes
backwards, and no other stage claims a duration, since a leftover value on a
copy event would restart a cleared clock. On the GUI side: a controlled
duration arriving through _on_progress is what the item displays, and a stall
the engine did not time still starts at zero rather than being invented.
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.

1 participant