Observe query cancellation in the compact-part mark read loop - #113423
Observe query cancellation in the compact-part mark read loop#113423groeneai wants to merge 10 commits into
Conversation
MergeTreeReaderCompactSingleBuffer::readRows walks one mark per iteration and had no cancellation check, while query limits are otherwise only enforced between blocks (MergeTreeSelectProcessor::read's `while (!is_cancelled)` and PipelineExecutor::checkTimeLimit). With index_granularity = 1 a single block spans as many marks as max_block_size allows, so one call runs unbounded and neither max_execution_time nor KILL QUERY takes effect until it returns. Measured on a 400k-mark compact part: a 1 s max_execution_time reported 17.9 s elapsed and a KILL QUERY ... SYNC took 17-18 s, both dropping to the limit with this change. Overshoot scales linearly with max_block_size (6.77x at 1e8 rows, 1.43x at 300k, 1.07x at 65536), which is the per-block interrupt granularity. The CI symptom is a Stress hung check: a cancelled INSERT ... SELECT on 03710_pr_join_with_mv ran 1592 s with is_cancelled = 1 after writing 10 rows, surviving the 90 s hung-check drain window (25 rows / 24 PRs / 1 master over 14 d on Stress test (arm_asan_ubsan) alone). readRows is a function-try-block whose catch calls reportBroken() for anything isRetryableException does not recognise, and that predicate lists neither QUERY_WAS_CANCELLED nor TIMEOUT_EXCEEDED. Without the second half of this change a cancelled query marks a healthy active part broken: on ReplicatedMergeTree it enqueues a part check (observed, then "looks good"). The guard is local to this one catch; isRetryableException itself is left alone because its 25 call sites drive fetch retries and part-check scheduling, where a query cancellation is not retryable in any sense. Wide parts do not carry this defect: MergeTreeReaderWide::readRows loops per column, not per mark, and the same fixture shows no overshoot (1000.1 ms against a 1000 ms limit). Merges and mutations are unaffected, having no query context, so tryGetQueryContext() returns null and no check is performed - verified by running OPTIMIZE FINAL and an ALTER UPDATE under a 1 s limit and observing both complete. Hot-path cost on an uncancelled 400k-mark read is within noise (median 18.18 s vs 18.34 s, n=5 each). Cancellation is observed for String, Nullable, LowCardinality, LowCardinality(Nullable), Array, Map, Tuple and Decimal columns.
The comment named max_execution_time, max_rows_to_read and max_block_size as the settings the tags protect against. Measured against tests/clickhouse-test: max_execution_time and timeout_overflow_mode do not appear at all, and max_rows_to_read appears once as a fixed override for infrastructure queries, not as a randomized setting. What actually makes the assertions stop discriminating is the read-speed family, whose fast combinations let the unpatched read finish inside the asserted bounds. Also record that no-random-merge-tree-settings is redundant today, since no-random-settings already disables the merge-tree randomizer, so a reader does not conclude the tag is load-bearing on its own. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
MergeTreeReaderTextIndex::readRows has the same unchecked per-mark loop the previous commit fixed in the compact reader, and it is a separate carrier: when a query's only predicate is served by the text index it requests no physical column, so MergeTreeReadTask::initializeReadersChain leaves the main reader out of the chain entirely and the compact reader's check never runs. Measured on a 400k-mark Compact part with a text index and 30 hasAnyTokens conjuncts: a 1 s max_execution_time reported 2.5-3.8 s elapsed before this change and stops at the limit after it. Reverting only this check while keeping the compact one leaves the new test arm red, and reverting only the compact check leaves it green, so each site is independently load-bearing. No isQueryCancellation guard is added here: unlike the compact reader this function is not a function-try-block and never calls reportBroken, so a cancellation exception cannot be mistaken for a part-health signal. The new test arm pins use_skip_indexes_on_data_read = 0 and query_plan_direct_read_from_text_index = 1. Both are randomized, and each one on its own disarms the assertion: with skip-index-on-data-read enabled a MergeTreeReaderIndex takes the chain-front slot, so the text reader is driven by continueReadingChain and the interrupt-site diagnostic is never appended; with direct read disabled the text reader is not used at all and the diagnostic comes from the compact reader's own check, so the arm would pass with this change reverted. Also corrects two comment claims from the previous commit. The interrupt-site token is appended by MergeTreeReadersChain::read, not by readRows, whose own catch appends a differently worded message; and checkTimeLimit is not "cheap (a flag plus an elapsed-timer read)" because throwProperExceptionIfNeeded takes cancel_mutex unconditionally. The call itself is unchanged: the lock-free variant, checkTimeLimitSoft, returns bool and never throws, so it cannot interrupt the walk, and gating on is_killed first would drop the max_execution_time half of the fix. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The arm added for MergeTreeReaderTextIndex checks that the query stopped inside a block read, and its neighbour checks that the text index pruned granules, but neither shows that the reader under test executed. EXPLAIN indexes = 1 renders index_stats, which filterPartsByPrimaryKeyAndSkipIndexes populates whether or not the direct-read rewrite ran; that rewrite is decided separately, in processAndOptimizeTextIndexFunctions. So the assertion written to prove the reader served the query could not detect a silent decline into a plan that never enters it, which is exactly what happens at query_plan_direct_read_from_text_index = 0, where the arm passes with the fix reverted. The setting is pinned per query, so the gap was covered, but only by prevention and not by detection. Give the timeout query its own query_id and read ProfileEvents['TextIndexReaderTotalMicroseconds'] back from system.query_log. That event has one increment site in the tree, the first statement of MergeTreeReaderTextIndex::readRows, and ProfileEventTimeIncrement's destructor reports during stack unwinding, so it records even though the query leaves that function by throwing. The row is matched on type = 'ExceptionWhileProcessing': the fixed server ends this query with a thrown TIMEOUT_EXCEEDED and writes no QueryFinish row. log_profile_events defaults to true and the runner does not randomize it, so no further pin is owed. On one binary the new line reads 1 with direct read enabled and 0 with it disabled, while the pruning line reads 1 in both, which is what distinguishes an execution oracle from a second pruning assertion. The other text index profile events cannot serve here: TextIndexReadPostings, TextIndexReadGranulesMicroseconds and TextIndexUseHint all sit on the granule-load pruning path and would report work in precisely the declined configuration. Reverting only the text index check still reddens one line, the interrupt-site assertion, and leaves the new line at 1, since that reader does run and simply does not stop. The pruning assertion, both pins and every earlier reference line are unchanged. 50 randomized runs pass. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Internal second-model review (5 rounds)An independent reviewer read the resulting code cold, without the author's evidence, and a ❌ The text-index reader carries the same defect ( ❌ The text arm's assertion could not detect the decline it was written to catch. ❌ A kill assertion bounded by ❌ The part-check oracle was unscoped, counting rows left by earlier runs of the same ❌ The test's oracle comment named the wrong emitter. ❌ The per-mark check was described as "a flag plus an elapsed-timer read". It is not: ❌ A carrier claim in the description was broader than the diff supports. It read as if
💡 Findings raised and refuted before being filed, recorded rather than acted on: a 💡 One nit is recorded and deliberately not changed: the execution oracle uses Also verified independently of the author's evidence: exactly two readers loop per mark and |
Pre-PR validation gate (click to expand)
Session id: cron:clickhouse-impl-slot-6:20260804-202100 |
|
cc @Ergus @serxa, could you review this? A single |
PedroTadim
added
the
can be tested
|
Workflow [PR], commit [3125620] Summary: ❌
AI ReviewSummaryThis PR adds per-mark Findings
Final VerdictThe per-mark cancellation fix and its new stateless coverage look good, but I would not treat the review as fully clean while the existing S3-backed reader path above still misreports healthy parts as broken. |
clickhouse-gh
Bot
added
the
pr-bugfix
The Style check's catch_all rule flags a terminal catch (...) that neither logs, rethrows nor saves the exception. Here the swallow is the correct answer rather than an oversight: isQueryCancellation is a pure classifier that rethrows the stored exception_ptr only to read its error code, and all 81 throw sites of the three codes it tests (QUERY_WAS_CANCELLED, QUERY_WAS_CANCELLED_BY_CLIENT, TIMEOUT_EXCEEDED) raise a plain DB::Exception, so anything reaching the catch-all is by construction not a cancellation and false is the complete answer. Nothing is lost: the caller still rethrows for diagnostics and the exception continues to propagate. Annotated with an Ok comment, which is the form the rule documents (ci/jobs/check_style.py:512-516 accepts a comment matching \bok\b in the block or the two preceding lines) and the form the sibling predicate called on the same line already uses -- isRetryableException in checkDataPart.cpp has the identical rethrow-and-classify shape and passes the check only because its terminal catch carries "But it is OK". 84 catch (...) sites in src/ use this annotation. Restructuring was considered and rejected: routing through getExceptionErrorCode would replace a code test with an equivalent one while adding an indirection, and that helper carries the very same Ok annotation on its own catch-all. Comment-only: the preprocessed code is byte-identical to the reviewed tree, so no rebuild and no re-verification of the fix is owed.
The test cancelled reads with max_execution_time and asserted the reported elapsed stayed under a fixed bound. That limit runs from the start of the query, so loading 400001 marks and analysing the text index are charged against it, and several limit checks fire before the read begins. On a loaded runner that work alone outlasts the limit: the deadline fires while the query is still being prepared, the read is never entered, and the interrupt-site diagnostic cannot appear. All 36 failing runs across 8 checks show it. In the text arm the query_log row was ExceptionBeforeStart, so the execution oracle matched no row and its line went missing entirely. Reproduced by shortening the limit below the preparation cost: at 0.5 s and lower the text arm fails exactly as CI did, with TextIndexReaderTotalMicroseconds = 0. No constant fixes this, because one number must exceed preparation (2 ms to 15 s, load dependent) and stay under the total read. The compact arm now raises the limit until the deadline lands inside the read, keyed on the interrupt-site diagnostic itself rather than on a wall clock, since that diagnostic is the only signal reporting where the query stopped. A limit that stops timing out is already too generous, so the ladder ends there. The text arm cancels with KILL QUERY after a handshake that waits for every mark to be selected while no row has been delivered, which is the pattern the neighbouring compact arm already used: that arm's line matched in all 36 failing runs. Its oracle also gains read_rows, which an uninterrupted walk sets to 400000. The walk costs about 150 ms per predicate, and at 30 predicates it lasted 4.5 s, short enough that the cancel could arrive after it finished; 120 predicates put it at 18 s, matching the compact arm. Verified on the reviewed binary, whose build id is unchanged because no source is touched: 25 of 25 randomized runs, and 12 of 12 at six-way self-contention on a host at load 81, which inflates preparation as CI does. Both mutation arms still redden, on disjoint lines: reverting the compact check fails only the two compact lines, reverting the text-index check only the two text lines. Both settings the text arm pins were re-measured under the new mechanism and both remain load-bearing.
![clickhouse-gh[bot]](https://avatars.githubusercontent.com/in/928874?s=60&v=4){kind=small}
…catch MergeTreeSequentialSource::generate reports a suspected broken part for every non-retryable exception, and isRetryableException does not recognise the three cancellation codes. Once the compact reader's mark loop can throw them, a cancelled foreground query enqueues a part check for a healthy Compact part. MergeTreeDataPartCompact::getReader returns MergeTreeReaderCompactSingleBuffer, so a Compact read through this source enters the loop this PR changed. The foreground caller is WhatIfEmpiricalEstimator, which drives the source from EXPLAIN WHATIF on the calling thread with the query's process-list element attached and no experimental setting gating it; the other three callers are merges and mutations. reportBroken reaches broken_part_callback, which for ReplicatedMergeTree queues the part for a full data check. Measured on a Replicated Compact table with index_granularity = 1 and 400k marks. With both sites instrumented, a deadline landing inside the read reached the catch twice and ran reportBroken both times, and the server then logged a full re-check of the active part ending "Part all_0_0_0 looks good." Reverting only the new conjunct restores that: on a paired ladder where each arm reached the read once, the pre-fix arm enqueued one check and the fixed arm enqueued none, with the part active and not detached in both. The classifier moves from the compact reader's anonymous namespace into checkDataPart, beside isRetryableException, and both catch sites call it, so it is defined once rather than twice. Both files already included that header for isRetryableException, so this adds no dependency. Adding the codes to isRetryableException itself would have been wrong: its three call sites inside checkDataPart treat retryable as "return empty checksums and retry later". A loop-top deadline check in this source was measured dead in an earlier round and stays out: readRows is called with one mark's rows, so its loop body runs at most once. That is also why the defect is narrow, since a deadline usually fires between marks. Reachability of a regression arm for the wiring measured 1 in 20, so no arm is added rather than a flaky one; the classifier itself is covered by the existing arms of 04746. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The test crossed the runner's 600 s per-test wall on two sanitizer arms (`amd_tsan, flaky check` 5/5 at 600.06-600.19 s, `amd_msan, WasmEdge, parallel, 2/2` 1 of 5 at 600.18 s, the other 4 passing at 249.8-448.2 s). The runner prints the processes left in the test's process group on a timeout, which names the phase each failure was in: five were in the text arm's `EXPLAIN indexes = 1` assertion and one was in that arm's `INSERT`. None was in either cancellation read, so the reads under test are not what has to shrink. Analysing the predicate costs about as much per term as reading does, so the 120-term conjunction made that assertion the most expensive statement in the file: 3.0 s on a debug build and 12.3 s under ASAN. The assertion only asks whether the text index is usable for this predicate shape, which does not depend on how many terms are conjoined, so it now asks it of a single term. Measured on a debug build, it answers 1 at one term and at 120, and answers 0 at both counts with `use_skip_indexes = 0`, with `ignore_data_skipping_indices = 'idx_s'`, and for a predicate the index cannot serve. Under ASAN it drops to 0.57 s. Both tables shrink from 400k to 100k rows, and the text predicate count rises from 120 to 240 to hold the read that the cancel has to land inside at about 8.9 s, against a floor of roughly 70 ms for the earliest kill the handshake can deliver. The insert that the sixth failure was in falls from 5.1 s to 1.7 s under ASAN. Every assertion and oracle is retained. Reverting both `checkTimeLimit` guards at the new size still reddens all three interrupt-site lines, so the smaller workload continues to detect the defect. The test now takes 7.5 s where it took 13.0 s, and 50 randomized runs pass with per-run times of 5.49 to 6.14 s.
Build profile diff (arm_release)No arm_release build profile data for commit af9b00b - the build was skipped, reused from cache, or predates profile upload. |
The text arm sent one KILL QUERY as soon as ProfileEvents['SelectedMarks'] was non-zero and read_rows was still 0, then asserted the interrupt happened inside MergeTreeReaderTextIndex::readRows. That handshake cannot establish what it was read as establishing. SelectedMarks is incremented in ReadFromMergeTree::initializePipeline, once index analysis has finished but before the pipeline runs, and no ProfileEvent advances while the reader walks marks: measured over 95 samples spanning a whole 8.9 s walk, the only counters that moved were produced by the polling client itself, and TextIndexReaderTotalMicroseconds appears only as its scope guard reports during unwinding. So the two signals available sit on either side of the read, never inside it, and a cancel sent on the earlier one lands before the reader is entered whenever the interval between them stretches. The compact arm above does not have this problem for a reason that is easy to miss: its handshake reads CompressedReadBufferBlocks > 1000, which is incremented from readHeaderAndGetCodec, so it can only accrue while data is actually being decompressed. Observed on Stateless tests (amd_debug, flaky check), where one of five runs printed 'text kill observed not interrupted inside the part read' together with 'text index reader ran 0 0', that second line being the reader reporting it was never entered. The four other runs passed, so nothing about the fix under test changed; only where the cancel happened to land did. Retry instead, keyed on the same interrupt-site diagnostic the compact arms already key on, growing the pause before the cancel. Each pause stays below how long the read lasts: a pause that outlasted it would let the query finish and leave the diagnostic absent for the opposite reason, which this retry cannot distinguish and would answer by pausing longer still. Verified by forcing the failure, since a runner cannot produce it on demand. Killing at the first instant the query is visible guarantees the cancel precedes the reader; the retry then converges in 4 of 4 trials, while the single cancel it replaces fails in 4 of 4. Reverting the reader's check still reddens exactly the two text lines, so the arm keeps discriminating. On the shipped tree the test passes 50 of 50 randomized runs and 12 of 12 six-way concurrent runs on a host at load 63, worst case 7.8 s against the runner's 600 s limit.
|
|
||
| /// A cancelled or timed-out query says nothing about the part's health, so such an exception must | ||
| /// not reach reportBroken. | ||
| bool isQueryCancellation(std::exception_ptr exception_ptr); |
There was a problem hiding this comment.
isQueryCancellation is being introduced as the shared way to keep query cancellation from reaching reportBroken(), but the sibling reader catches that already see cancellation from lower I/O are still unchanged. Object-storage reads rewrite failed requests to the query's cancellation via CurrentThread::checkIfNotCancelled() in src/IO/S3/Client.cpp:422 and :711; that exception will still be treated as non-retryable in MergeTreeReaderWide.cpp:75-76, 106-107, 256-257, and MergeTreeReaderCompactSingleBuffer.cpp:162-163.
So killing or timing out a query while reading an S3-backed part can still enqueue a bogus part check for a healthy part (ReplicatedMergeTree will verify it again). Please extend those catches to exempt isQueryCancellation(std::current_exception()) as well, or the new helper/comment is only true for the two call sites touched here.
There was a problem hiding this comment.
Both halves check out, and they point in opposite directions, so I have taken the second one and declined the first.
The sibling catches are a different carrier, and this branch does not arm them. Every site you cite is verbatim correct at origin/master, and the mechanism is real: checkIfNotCancelled reaches throwProperExceptionIfNeeded, which throws TIMEOUT_EXCEEDED or QUERY_WAS_CANCELLED; isRetryableException lists neither, so such an exception is classified non-retryable and reaches reportBroken(). What decides ownership is whether this diff makes that reachable, and it does not:
src/IO/S3/Client.cpp(md53ee869320a496f4d93fb8f093c87f61e) andMergeTreeReaderWide.cpp(md568bb5fd7a6e4586fe55f58509745161d) are byte-identical across the merge-base91687a7d610e, this head, andorigin/master.- The S3 route predates the branch:
538f478f2929678introduced it, andgit merge-base --is-ancestor 538f478f2929678 91687a7d610ereturns 0. - Neither new throw site can unwind into a frame you name. They are at
MergeTreeReaderCompactSingleBuffer.cpp:43andMergeTreeReaderTextIndex.cpp:496(zero inMergeTreeReaderWide.cpp).MergeTreeReadersChaindrivesrange_readersin a sequential loop, not nested, so reader types cannot mix within one part. And theCompactSingleBuffercatch you cite isinit()'s, which returns at:20before the mark loop holding the new check at:38-43, i.e. strictly upstream of it.
So widening the exemption into those four catches would be a second carrier in this PR, and it collides with my open #112918, which already edits MergeTreeReaderWide.cpp:256 and this header (git merge-tree against it: 4 conflicted paths). I would rather not ship four more exemptions with no test pinning them.
The comment did overclaim, and that is fixed in 3125620. /// ... such an exception must not reach reportBroken reads as a property of the codebase, while the helper is applied at 2 of the 6 reportBroken() catch sites in src/; the PR description already scoped it correctly ("the guard is local to this catch") and the header contradicted it. It now describes only what the predicate detects:
/// True for a cancelled or timed-out query, which says nothing about the part's health.
One correction to your citation for whoever reads this later: MergeTreeReaderCompactSingleBuffer.cpp:162-163 resolves only on this branch. On origin/master that file is 152 lines and the init() catch is at :147-148; the other four line references are exact on master.
The pre-existing S3-cancellation path is worth someone fixing, and I have not filed it: a spurious enqueuePartForCheck on a healthy Active part is re-verified as healthy, so it costs background work and log noise rather than correctness, and I have no S3 fixture to demonstrate it with.
CI finish ledger — af9b00bEvery failure below has an owner: a fixing PR (mine or external), or a full-effort fix task 175 check-runs, all completed: 158 success / 17 skipped / 0 failure.
CI is green, but the change request above on Session id: cron:our-pr-ci-monitor:20260806-133000 |
The declaration comment asserted that a cancellation "must not reach
reportBroken", which reads as a codebase-wide invariant. The helper is
applied at 2 of the 6 reportBroken() catch sites in src/, so the wider
claim is not delivered by this change; the PR description already scopes
it correctly ("the guard is local to this catch").
Reported by clickhouse-gh[bot] on checkDataPart.h:22. The sibling catches
it names (MergeTreeReaderWide.cpp:76,107,257 and
MergeTreeReaderCompactSingleBuffer.cpp init()'s catch) are a different
carrier: object-storage I/O rewriting a failed request to the query's
cancellation via CurrentThread::checkIfNotCancelled (S3/Client.cpp:422,
:711). That route predates this branch -- both files are byte-identical
across the merge-base, this head and origin/master, and 538f478
which introduced it is an ancestor of the merge-base -- and none of the
new throw sites can unwind into those frames, so widening it here would
be a second, unpinned concern.
Comment-only: the header is code-identical after stripping comments.
CI finish ledger - 3125620Every failure below has an owner: a fixing PR (mine or external), or a full-effort fix task
None of these is attributable to this PR: no compile ever started on the failing jobs, and the only Session id: cron:our-pr-ci-monitor:20260806-213000 |
2 participants
Changelog category (leave one):
Changelog entry (a user-readable short description of the changes that goes into CHANGELOG.md):
Fix
KILL QUERY, andmax_execution_timeunder the defaulttimeout_overflow_mode = 'throw', being ignored while a query reads a CompactMergeTreepart with a smallindex_granularity. A single block read walked every mark without checking cancellation, so one call could run for minutes past the limit.Description
MergeTreeReaderCompactSingleBuffer::readRowswalks one mark per iteration and had nocancellation check. Limits are otherwise enforced only between blocks
(
MergeTreeSelectProcessor::read,PipelineExecutor::checkTimeLimit), so withindex_granularity = 1one block spans as many marks asmax_block_sizeallows and no limitapplies until it returns.
Measured on a 400k-mark Compact part: a 1 s
max_execution_timereported 17.9 s elapsed, andKILL QUERY ... SYNCtook 17-18 s; both drop to the limit with this change. The overshootscales linearly with
max_block_size(6.77x at 1e8, 1.43x at 300k, 1.07x at 65536), which is theper-block interrupt granularity. The CI symptom is a Stress hung check: a cancelled
INSERT ... SELECTran 1592 s withis_cancelled = 1after writing 10 rows (25 rows / 24 PRs /1 master over 14 d on
Stress test (arm_asan_ubsan)alone).The catch guard is required, not incidental.
readRowsis a function-try-block whose catch callsreportBroken()for anythingisRetryableExceptiondoes not recognise, and it lists neitherQUERY_WAS_CANCELLEDnorTIMEOUT_EXCEEDED- so the check alone reports ahealthy active part broken (on
ReplicatedMergeTree, an observed part check). The guardis local to this catch;
isRetryableExceptionis untouched, because its 25 call sites drive fetchretries where a cancellation is not retryable in any sense.
MergeTreeReaderTextIndex::readRowshas the same loop and is fixed too, on either part type; itneeds no guard, reporting no broken part. The Wide main reader needs no check
(
MergeTreeReaderWide::readRowsloops per column, not per mark). Hot-path cost is within noise.Scope:
KILL QUERYis honoured in every overflow mode, but a plainmax_execution_timeexpiryunder
timeout_overflow_mode = 'break'still overshoots, becausecheckTimeLimitreturnsfalsethere instead of throwing. Making it stop would turn a documented silent stop
(
02896_max_execution_time_with_break_overflow_mode) into a client-visible error, so it is leftout.
Part of the class tracked by #107474.