Report cancellation instead of a network error for a cancelled url failover read - #113453
Report cancellation instead of a network error for a cancelled url failover read#113453groeneai wants to merge 13 commits into
url failover read#113453Conversation
…failover read StorageURLSource::getFirstAvailableURIAndReadBuffer walks the |-separated URL options and returns the first one that opens. Its catch(...) treated every exception as an ordinary endpoint failure: it kept only the message text, moved on to the next option, and after the loop synthesized a new exception with a hardcoded NETWORK_ERROR. A cancellation was swallowed the same way, so KILL QUERY or max_execution_time on a multi-option read reported 210 NETWORK_ERROR with the real code surviving only inside the message text, and every remaining option was still attempted. Single-option reads kept their code only because of the existing "if (options == 1) throw". Ask the query's cancellation status on that failure path via CurrentThread::checkIfNotCancelled, which throws the real cancellation exception when the query was killed and returns immediately otherwise. One statement covers both halves: the cancellation keeps its own code, and control leaves the loop so no further option is started. This mirrors the primitive and the control-flow position that ClickHouse#108673 shipped for cancelled S3 requests. The three callers, including both schema-inference sites, share this callee and are all covered. Legitimate failover is untouched because the decision comes from the query status rather than from an error code: a slow but uncancelled option still fails over, a genuinely unreachable set of options still reports the aggregate NETWORK_ERROR, and timeout_overflow_mode = 'break' does not mark the query killed so that mode is unchanged. The attempt already in flight when the cancellation arrives still runs to its receive timeout, which is the separate concern tracked by ClickHouse#104929. The new test pins six cases: three cancellation rows, including one where the cancellation lands while the LAST option is in flight, plus three must-not-regress rows. The last-option row is what distinguishes reporting the cancellation from the handler itself from a check placed at the top of the failover loop, which cannot help once no further option remains.
The third group of 04674 was bounded on both sides by wall clocks: option 1 had to fail before the query deadline, and the deadline had to fire before option 2 failed. That left about one second of margin on either side, which is not safe under sanitizers plus the CI thread fuzzer, and it was the one group that distinguishes reporting the cancellation from the failover handler itself from checking at the top of the failover loop. The dead listener now publishes one byte per accepted connection, so the group can wait until option 2 is actually in flight and then issue KILL QUERY, instead of hoping a deadline lands inside a window. With max_execution_time = 0 the query is never registered with the cancellation checker, so no timeout can race the kill. KILL QUERY also reaches QueryStatus::throwQueryWasCancelled rather than the timeout branch, so the group additionally pins QUERY_WAS_CANCELLED, which no group asserted before. The two groups driven by max_execution_time are kept as they are, so both cancellation reasons are now asserted. Also trim the test comments to the usual per-block length and drop the parentheses from function names.
The KILL-QUERY group waited on a shared accept-marker file written by the dead listener. The readiness probes are accepted by that listener too, and TCP completes an inbound connect from the kernel backlog before the listener thread reaches accept(), so probe accepts could be recorded after the group sampled its baseline and satisfy the +2 threshold with zero requests from the target query. The kill could then land before the first option was even issued, reddening the one group that distinguishes reporting the cancellation from the failover handler itself from a check at the top of the failover loop. Poll the query's own ReadWriteBufferFromHTTPRequestsSent counter from system.processes instead. The counter belongs to the query's thread group, so no readiness probe, earlier group or concurrent copy of the test can contribute to it, and the accept marker plumbing is gone. A non-numeric reply is treated as "not observed yet" so it never reaches the arithmetic comparison, which would otherwise write to stderr and fail the test outright. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
…er loop The failover loop in StorageURLSource::getFirstAvailableURIAndReadBuffer has two exits that advance to the next URL option, and only the exception handler was guarded. When engine_url_skip_empty_files is enabled an option that answers with an empty body is stashed and skipped, and nothing between that continue and the next option's create() consults the query status. A query cancelled while such an empty response is being received therefore still issued an HTTP request for every remaining option, which is the second half of the behaviour this change claims: the error code was already correct on that path, because the next option is dead and its exception reaches the guarded handler. Applying the same check before the skip continue makes both paths that advance to the next option stop after a cancellation. The regression test gains a group covering the skip path. Its empty listener holds its response back until the shell has observed is_cancelled in system.processes, so the skip and the cancellation are ordered by observation rather than by a wall clock. wait_for_port now reports and exits on failure like the file's other poll helpers, instead of returning an ignored status. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Give both poll helpers a liveness guard: each now reads the value it waits for and the existence of the query's row in one query, so the two cannot be sampled at different instants. A query that was observed and then left system.processes can never reach the value, so it is reported at once instead of polled for until the harness timeout. The previous shape could not distinguish "not cancelled yet" from "query already gone", which made the empty-option group fail 9 of 50 runs by 600 s timeout. Remove the ordering cycle in that group. Its cancellation was ordered after the response was released and the release after the cancellation was observed, with nothing outside the cycle keeping the query alive: if the kill did not land within the receive timeout the read completed on its own, the query finished with the aggregate error, and the release was never created. The held read is now pinned above the harness window so the cancellation is the only way out of it, and the group's second option is the responsive listener rather than the dead one, so an unwanted attempt on it is counted immediately instead of blocking for that same timeout. Not paying those two receive timeouts is what brings the runtime down: over 50 randomized runs the median goes from 98 s to 51 s and the maximum from 170 s to 52 s, against a 180 s per-test ceiling. No check-silencing tag was added. The reference is unchanged, and deleting the check on the empty-option path still reddens exactly that group's request count. ifNull is needed around the request-count sum because sum() over an empty set is NULL, which the non-numeric guard would otherwise read as "not observed yet", making the new liveness guard vacuous in exactly the state it exists to catch. The source comment is trimmed to the invariant it states; the rest was motivation, which belongs here.
The check on the empty-option skip path sat inside a branch guarded by `option != std::prev(end)`, so a final empty option never reached it: the helper returned normally and both callers re-entered their outer `do ... while` on `eof()` and issued another HTTP request for the next URI after the query had been cancelled. `StorageURLSource::generate` cannot intercept that, because its `isCancelled` check runs before `initialize` rather than inside its loop. Moving the call to the first statement of the failover loop covers the same skip path (its `continue` returns there) plus that re-entry, in one line instead of two, through the single callee both callers share. The check in the `catch (...)` handler stays: the loop is not re-entered after the last option, so only a check there can report the cancellation for it. The `timeout_overflow_mode = 'break'` regression row now asserts the property it exists to pin, that a soft break timeout is not reported as a cancellation, instead of the aggregate `NETWORK_ERROR` message text. A soft break does not set `is_killed`, so `CurrentThread::checkIfNotCancelled` is a no-op for it either way; pinning the text additionally froze a contract that ClickHouse#112930 deliberately changes, which would have broken CI for whichever of the two merged second. Verified by mutation: making the guard treat a query past its soft deadline as cancelled reddens exactly that row.
The check in the `catch (...)` handler is deliberately placed before the `if (options == 1) throw;` rethrow, so a cancelled single-option read is reported as a cancellation too. Until now no test row exercised that, and the mutation arm that moves the check after the rethrow therefore passed. The covered single-option path is schema inference, not the read path. `delay_initialization` is the last parameter of `StorageURLSource::getFirstAvailableURIAndReadBuffer`, and the read-path caller passes `current_uri_options.size() == 1` for it while both schema-inference callers pass `false`. `ReadWriteBufferFromHTTP` calls `next` from its constructor only when initialization is not delayed, so with one option on the read path no request is issued inside the failover `try` and the handler is never entered. Omitting the structure argument routes the query through schema inference instead, where the request is issued inside the `try`. Without the fix that path reports `CANNOT_EXTRACT_TABLE_STRUCTURE`, not the `NETWORK_ERROR` of the multi-option shape: the swallowed cancellation makes the failover loop rethrow the raw `Poco` exception, which is not a `DB::Exception`, so `readSchemaFromFormatImpl` wraps it in its `catch (...)` instead of rethrowing it with its code intact. The `TSV` argument selects that code rather than `CANNOT_DETECT_FORMAT`, so it is load-bearing for the row. Measured on the fix, on pre-fix and with the handler check moved after the rethrow: the row reads `TIMEOUT_EXCEEDED` only on the fix, and the moved check reddens exactly it and no other row. ClickHouse#112930 places its equivalent guard after that rethrow and gates it on a `CancellationPtr` that only the read path passes, so this row also fails there. Adding the handler line to it makes all eight rows pass.
Internal second-model reviewBefore opening this PR I ran an independent review of the diff with a second model, plus my own ❌ Blockers: none.
The test group that cancels the read while the last URL option is in flight has to know that the
Final form observes the query's own counter,
A test row now pins that case, and it is what makes the placement mutation meaningful: moving the 💡 Noted, not blocking: over 50 randomized runs of the final test the per-run time was 55.50 s
Every round re-verified both directions on rebuilt binaries, asserting the served Session id: cron:clickhouse-review-slot-8:20260805-093500 |
Pre-PR validation gate (click to expand)
Session id: cron:clickhouse-review-slot-8:20260805-093500 |
|
cc @alexey-milovidov @Algunenano, could you review this? The failover loop in |
|
Workflow [PR], commit [ed4b110] Summary: ❌
|
`check_functional_test_cases` in `ci/jobs/check_style.py` rejects any file under `tests/queries` whose path contains the substring `fail`, which `failover` did. The stem now says `url_option_fallback`, matching the `uri_options` vocabulary of the code under test. Contents are unchanged: both files are byte-identical to their previous revisions and the executable bit is preserved.
getFirstAvailableURIAndReadBuffer returns the last option without revisiting the top of the failover loop and without throwing, so neither the loop-top nor the handler cancellation check is reached for it. With engine_url_skip_empty_files and a single empty option, option == std::prev(end) bypasses the skip branch and the empty buffer is returned; schema inference then runs out of options and reports CANNOT_EXTRACT_TABLE_STRUCTURE, which is one of the two shapes this change's changelog entry already promises to fix. Ask the cancellation status before the successful return as well. checkIfNotCancelled returns immediately unless the query is killed, so guarding the whole successful exit needs no new predicate and leaves an honestly empty file reported as empty. The read path was measured NOT to be affected: a cancelled read of a single empty option already reports QUERY_WAS_CANCELLED, because PipelineExecutor::finalizeExecution calls checkTimeLimit, which throws for a killed query. Only the schema-inference callers, which pass delay_initialization = false, reached the laundered outcome. Reverting only the added statement reddens exactly the new test row and nothing else; the pre-fix binary additionally reddens the five existing cancellation rows. Two non-cancellation rows pin that an empty single option is still reported as an empty file and still reads as zero rows, and read identically on every arm. Reported by clickhouse-gh[bot] on the previous head.
…etry retry) The Post Hooks failure on Build (arm_release) is the LogCluster telemetry INSERT dying with HTTP 500. ClickHouse#113409 merged that retry into ci/jobs/scripts/log_cluster.py at 2026-08-06T00:05:00Z; this branch predated it, so CI re-runs with the fix present.
CI finish ledger -- 1b5e603Every failure below has an owner: a fixing PR (ours or external), or a full-effort fix task
None of the three is PR-caused. This PR's diff is three files (
Session id: cron:our-pr-ci-monitor:20260806-003000 |
| @@ -0,0 +1,26 @@ | |||
| --- cancelled, two options --- | |||
There was a problem hiding this comment.
@groeneai just remove the test file, it's long and may become flaky
There was a problem hiding this comment.
You were right to flag it, and the retraction was too kind: this test now genuinely breaches the cap, so I am cutting its runtime rather than leaving it as is.
Measured on Stateless tests (amd_asan_ubsan, flaky check), per head:
| head | OK | FAIL | p50 | max |
|---|---|---|---|---|
c157ee94 |
50 | 0 | 135.3s | 142.1s |
1b5e603e |
50 | 0 | 155.9s | 167.0s |
08eef556 |
0 | 6 | 185.7s | 190.0s |
At the current head all six attempted runs report Test runs too long (> 180s) and the check then stops early on --max-failures. It is not one slow outlier against a healthy distribution: the minimum over those runs is 182.7s. The amd_debug, amd_msan and amd_tsan flaky checks are still 50/50 OK at 110-120s, which is why only the asan lane shows it. The ordinary amd_asan_ubsan, distributed plan, parallel run is 119.8s, so the cost is real and not an artifact of the 50x repetition.
Two things I am not going to do. Delete the test, because it is the only witness for the cancellation-instead-of-NETWORK_ERROR behaviour this PR fixes. And add a long tag, which exempts a test from that cap without making it any cheaper.
What the numbers say about where to cut: the growth tracks assertion groups, 8 groups at 135.3s against 10 at 155.9s, and the file is byte-identical between the last two heads, so the final 30s is not test content. I have not yet attributed the per-group wall clock, so I will measure that before choosing the cut, and size it for real headroom instead of to just clear 180s. I will post the numbers here.
There was a problem hiding this comment.
Numbers, as promised, and the cut is pushed in 9798fbd5815c0a3df1a5a3cf8c02836a1c035814.
Per-group wall clock at the previous head, one debug binary, one server, markers around each group:
| group | sec | % |
|---|---|---|
| KILL QUERY while the last option is in flight | 20.44 | 36.9 |
| timeout_overflow_mode = break | 10.30 | 18.6 |
| cancelled, two options | 5.37 | 9.7 |
| cancelled, one option, schema inference | 5.31 | 9.6 |
| cancelled, three options | 5.28 | 9.5 |
| not cancelled, all options down | 4.29 | 7.7 |
| not cancelled, failover to a working option | 2.09 | 3.8 |
| the three remaining groups | 1.64 | 3.0 |
| setup: port allocation, listeners, readiness | 0.69 | 1.2 |
So 53 of the 55 seconds is http_receive_timeout, and my earlier guess that the poll loops were the
expensive part was wrong. A micro-probe settled it: an option pointing at a listener that accepts and
never answers costs one full http_receive_timeout, one that accepts and closes costs 0.12s, and both
are counted by ReadWriteBufferFromHTTPRequestsSent. Wall clock tracked http_receive_timeout to
within 0.1s and did not move with max_execution_time.
That is where the waste was. Four groups only need their first option to have been attempted and
failed, and nothing asserts how long it took, so only the option each group is about has to stay open;
those four now point their first option at a listener that fails at once.
All uri (N) options are unreachable reports the option count rather than durations, so that message
is unchanged. The three cancellation groups keep max_execution_time = 2 and drop
http_receive_timeout 5 to 3, which a sweep showed is the last safe value: at 2 the asserted request
count becomes 2 instead of 1, and at 1 the group reports NETWORK_ERROR, because the transport
timeout rather than the soft one ends the read. And kill_and_wait polled every 0.1s while waiting for
a query that cannot leave system.processes until its own receive timeout elapses, so that is now
0.5s with the same overall cap; client invocations per run went 137 to 43.
Result on one binary and one server with randomization on: 50 of 50 pass, min 26.26 / p50 27.14 /
max 29.57s, against min 57.55 / p50 57.83 / max 58.62s over 12 runs of the previous file. 2.13x at the
p50, and 16.4% of the cap at the maximum rather than 106%. Largest group is now 4.45s, so nothing
dominates any more.
Coverage is unchanged and I checked that rather than assuming it. The .reference file is untouched,
so the same 26 lines are asserted. Reverting the fix entirely still reddens all six cancellation rows
and leaves all four must-not-regress rows green, and each single-line revert still reddens only its own
row, each on its own rebuilt binary with the served buildId() checked; the build ID returned
byte-exactly to the shipping one afterwards.
|
Fixing PR for the It replaces the oracle that counted every The failure on this PR was on a build that predates that merge. Probing the test file per build (marker No action needed here beyond a rerun or a rebase onto current master. |
The flaky check runs a changed test 50 times and fails any run over 180s. On `amd_asan_ubsan` this test reached a median of 185.7s and failed 6 of 6 attempted runs. Locally its cost was 55.0s per run, and per-arm instrumentation attributed 53.0s of that to `http_receive_timeout` waits and 0.7s to setup. The waits were paid for options nothing asserts about. A micro-probe measured that an option pointing at a listener which accepts but never answers costs one full `http_receive_timeout`, while an option pointing at a listener which accepts and closes costs 0.12s, and that in both cases the attempt is counted by `ReadWriteBufferFromHTTPRequestsSent`. Four arms only need their first option to have been attempted and failed; only the option each one asserts about has to stay open. Those four now use a new fail-at-once listener for the first option. `All uri (N) options are unreachable` reports the option count rather than how long each option took, so that message is unchanged. The three cancellation arms keep `max_execution_time = 2` and drop `http_receive_timeout` from 5 to 3. A sweep pinned 3 as the last safe value: at 2 the asserted request count becomes 2 instead of 1, and at 1 the arm reports `NETWORK_ERROR` instead of the cancellation, because the transport timeout rather than the soft one ends the read. `kill_and_wait` polled every 0.1s. Instrumenting it showed the wait is the awaited read finishing its own receive timeout, so the query cannot leave `system.processes` sooner and a finer cadence only spends client startups. It now polls every 0.5s with the same 60s cap, taking client invocations per run from 138 to 43. Measured on one binary and one server with randomization on: 50 of 50 runs pass at min 26.26 / median 27.14 / max 29.57s, against min 57.55 / median 57.83 / max 58.62s over 12 runs of the previous version. The reference file is untouched, and the mutants that pin the assertions still redden exactly as before: reverting the fix entirely reddens all six cancellation rows and no must-not-regress row, while each single-line revert reddens only its own row.
| } | ||
|
|
||
| /// The last option is returned without revisiting the loop top, empty or not. | ||
| CurrentThread::checkIfNotCancelled(); |
There was a problem hiding this comment.
This still leaves one unguarded return path: if engine_url_skip_empty_files = 1, an earlier option was saved into last_skipped_empty_res, and the final option throws normally, a KILL QUERY that lands after the catch-side CurrentThread::checkIfNotCancelled() but before the post-loop return last_skipped_empty_res; will still hand EOF back to the caller instead of the cancellation.
That matters for schema inference, because StorageURLSchemaReader::next consumes that EOF in its outer do ... while and on a single URL entry then falls out as CANNOT_EXTRACT_TABLE_STRUCTURE / “all files are empty”. I think this needs the same cancellation probe before returning last_skipped_empty_res, plus a regression row for an empty option followed by a failing option under engine_url_skip_empty_files = 1.
There was a problem hiding this comment.
Agreed, and the window is wider in scope than reported: it also reaches the NETWORK_ERROR throw two lines below the return, so it hits the read path too, not only schema inference. Fixed in ed4b110.
I measured it by widening the span between the handler's check and the post-loop exits to 12 seconds and logging whether the cancellation was observed inside it, so the kill lands there by construction:
| cell (kill lands inside the window) | before | after |
|---|---|---|
| EOF return, schema inference | 636 CANNOT_EXTRACT_TABLE_STRUCTURE |
394 QUERY_WAS_CANCELLED |
NETWORK_ERROR throw, schema inference |
210 NETWORK_ERROR |
394 |
NETWORK_ERROR throw, read path |
210 NETWORK_ERROR |
394 |
| each of the three, not cancelled | 636 / 210 / 210 |
unchanged |
One statement covers both exits, because the handler's continue is the only edge that can leave the loop: the empty-option skip is guarded by option != std::prev(end) so it cannot run on the final iteration, and the successful return leaves the function. So nothing else reaches the post-loop code.
On the regression row: a row that races a KILL QUERY against this window would be a control rather than a witness. The span is straight-line code only, and instrumenting it measured 35 to 64 microseconds (median 37, n=25). Firing the kill the instant the query's own request counter shows the final option in flight, 70 attempts landed in it zero times, all reporting 394 on a binary without the fix. I pinned it with a PAUSEABLE_ONCE failpoint parked in the window instead, in 04812_url_failover_post_loop_honors_cancellation: three cancellation rows and two not-cancelled controls. Reverting only the added check reddens exactly the three and leaves both controls green.
It is a separate file because a pauseable failpoint is a global channel and needs no-parallel, which the existing ten rows do not. That also keeps it cheap: 2.9 seconds, and 50 randomized runs give 50 passes at a median of 5.5 seconds against the 180 second cap, so it does not spend the runtime headroom recovered in 9798fbd.
Build profile diff (arm_release)No arm_release build profile data for commit ed4b110 - the build was skipped, reused from cache, or predates profile upload. |
… option Once the loop has tried every URL option, control reaches the post-loop code only through the exception handler's `continue`. That handler checks the query status, but the post-loop code then has two exits of its own, and a cancellation observed between the handler's check and those exits was reported as an ordinary failure: the kept empty option was handed back as end-of-input, which schema inference turns into CANNOT_EXTRACT_TABLE_STRUCTURE, and with no empty option the aggregate NETWORK_ERROR was thrown instead. Both replace the cancellation this change set exists to preserve. The handler's own check is what makes one statement enough here: the loop's other two exits (the empty-option skip and the successful return) cannot leave the loop, so nothing else reaches the post-loop code and no second check is needed. The window between the handler's check and the post-loop exits is only straight-line code -- an exception message, a log call, the loop increment and one branch. Measured on a debug build it is 35 to 64 microseconds wide (median 37), and 70 attempts that fire KILL QUERY while the final option is in flight never landed inside it, so a test that races a kill against it would be a control rather than a witness. It is instead pinned with a PAUSEABLE_ONCE failpoint parked in exactly that window, which needs no receive timeout and adds under three seconds. Reverting only the added check reports CANNOT_EXTRACT_TABLE_STRUCTURE, NETWORK_ERROR and NETWORK_ERROR for the three cancelled rows while both not-cancelled rows stay unchanged. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
`ci/jobs/check_style.py` rejects any functional test file whose name contains the substring `fail`, which `failover` matches. The rule walks the whole `tests/queries` tree rather than the change, so the check reports `test case ./tests/queries/0_stateless/04812_url_failover_post_loop_honors_cancellation.sh includes 'fail' in its name`. The sibling test in this change set was renamed for the same reason, so this adopts the same stem. The file contents and mode are unchanged. Removing only the post-loop check still reports `CANNOT_EXTRACT_TABLE_STRUCTURE`, `NETWORK_ERROR` and `NETWORK_ERROR` for the three cancelled rows under the new name while both not-cancelled rows stay unchanged, so the rename does not weaken what the test observes. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
|
#112930 supersedes this PR |
|
Agreed, and thanks for triaging it. #112930 covers the failover read path, its loop-top check is byte-identical to the one here ( One shape in Closing it is one statement before |
|
Done: #112930 (comment) I re-measured everything at |
Report cancellation instead of a network error for a cancelled
urlfailover readChangelog category (leave one):
Changelog entry (a user-readable short description of the changes that goes into CHANGELOG.md):
Fixes a cancelled read from a
urlorENGINE = URLtable being reported as a transport failure instead of as a cancellation: with several|-separated options it reportedNETWORK_ERRORwith the messageAll uri (N) options are unreachable, and with a single option during schema inference the cancellation was wrapped asCANNOT_EXTRACT_TABLE_STRUCTURE. Also stops the failover loop from starting another URL option after the query was cancelled.Description
StorageURLSource::getFirstAvailableURIAndReadBufferwalks the|-separated URL options and returns the first that opens. Itscatch (...)treated every exception as an ordinary endpoint failure: try the next option, then throw a hardcodedNETWORK_ERROR. A cancellation was swallowed the same way, soKILL QUERYandmax_execution_timereported210 NETWORK_ERRORand still attempted every remaining option.The fix asks the query's cancellation status via
CurrentThread::checkIfNotCancelled, which throws only when the query was killed, so the cancellation keeps its own code and no further option is started. It runs on the failure paths and before the successful return, because the last option is returned without revisiting the loop top: with a single empty option underengine_url_skip_empty_filesnothing throws at all. #108673 shipped the same primitive for cancelled S3 requests. The decision comes from the query status, not an error code, so legitimate failover is untouched and an empty file is still reported as empty. The in-flight attempt still runs to its receive timeout (#104929).Overlap, measured against #112930 at
6395a10676e8. Its loop-top check is the same statement as the one here, byte for byte; only the comment differs, and that is the branches' sole merge conflict. Unique here are the checks in thecatchand before the return: itscatchguard is a barethrow;, rethrowing the in-flight transport error, and is gated on aCancellationPtronly the read path passes, so it is inert on both schema-inference call sites. Its head fails 3 of the 10 rows added here; adding those two lines to it makes all 10 pass, so folding them in is likely tidier than merging this. #111845 restructures the samecatchand also conflicts.The
timeout_overflow_mode = 'break'test row asserts only that a soft break timeout is not reported as a cancellation, which holds under #112930's partial-result contract too.