Conversation
A query whose WHERE is evaluated by a `set` skip index could not be stopped: `KILL QUERY` was acknowledged and `system.processes.is_cancelled` became 1, but the query kept running to completion, and `max_execution_time` was equally ineffective for the whole duration. `x IN (<constant array>)` is resolved to `has(<constant array>, x)`, and `has` over a constant array runs `FunctionArrayIndex::executeConst`, whose nested loop performs `rows * arr.size()` `Field` comparisons with no cancellation checkpoint. A constant array's size is not part of the block's data volume, so that loop can do unbounded work on a block, and a `set` index evaluates its condition as a single `ExpressionActions` over every value the index stored for a part, which hands the function one stored value per row of the part. The checks around it are all coarser than one such call: `MergeTreeSkipIndexReader::read` tests `is_cancelled` once per index before the work, and the planning route calls `checkTimeLimit()` once per part. Use the machinery that already exists for this shape, `src/Functions/CancellationBudget.h`, as its other users do, including the h3 functions: resolve the check once on entry so an already-passed deadline is observed even by a call that charges no work, then charge once per result row. Charge `i + 1`, the comparisons the row actually performed, not `arr.size()`. `HasAction`, `IndexOfAction` and `IndexOfAssumeSorted` stop at the first match, so a row matching at position 0 of a 1000000-element array performs one comparison; charging the array size there would exhaust the 65536-unit budget on every row and call `QueryStatus::checkTimeLimit()` per row, and that path takes `cancel_mutex`, which is shared by every query thread. The `+ 1` keeps a row that matched at position 0 from charging nothing at all. One budget in `executeConst` covers both index analysis routes, both arms of `filterMarksUsingIndex` and the ordinary data path, and every `FunctionArrayIndex` instantiation: `has`, `indexOf`, `indexOfAssumeSorted`, `countEqual`, `mapContainsKey` and `mapContainsValue`. The non-constant-array paths scan only the row's own data, so their work is bounded by the block they were handed; that is the general large-value case tracked by ClickHouse#112203 and is not changed here. A storage-layer alternative was considered and rejected: batching `MergeTreeIndexConditionSet::getPossibleGranules` and adding checkpoints to `filterMarksUsingIndex` needs a new virtual, a `QueryStatusPtr` parameter, an equivalence proof for splitting one `ExpressionActions::execute` into several and a guard for conditions sensitive to how many times they are evaluated, and it would still leave the same loop uninterruptible for every other caller. Measured on a debug build, one active part of 200000 rows: before, a `max_execution_time = 3` query ran 72.5 s and returned no error at all, and `KILL QUERY ... SYNC` returned after 72.2 s; after, the query stops at 3.0 s with `TIMEOUT_EXCEEDED` naming the function, and the kill returns in 0.18 s. The added per-row cost is not measurable above noise and is bounded at +0.4 ns/row on a 3-element constant array, the smallest per-row work this loop can do and a shape the default `optimize_rewrite_has_to_in` never routes here. The new test needs exactly one active part: with two or more, the pre-existing per-(part, index) checks interrupt the query on their own and it would pass without this change. Its `KILL QUERY` scenario bounds the wait at 15 seconds, and pins `secondary_indices_enable_bulk_filtering` and `use_query_condition_cache` on that query rather than leaving them to settings randomization. Both are randomized and both default to true, and both decide how long the unfixed scan is: without bulk filtering it is 14.5 s instead of 70 s (about 10 s on a release build), and with the query condition cache it is 40 ms, because the two deadline scenarios above it evaluate the same condition on the same part and leave a verdict behind. Either one would let the bound pass on unfixed code. It also waits until the query has been running for a second before killing it, since the process list entry is inserted before planning and a kill landing in that window raises the same error the oracle greps for, and it then asserts that the killed query really did spend time in index filtering. The deadline scenario evaluated while reading pins `secondary_indices_enable_bulk_filtering` as well: bulk filtering evaluates a whole part in one condition call, which is the only shape where the periodic charge, rather than the entry check, is what stops the query. The scenario evaluated during planning is left free there, which keeps the per-granule arm covered. Related: ClickHouse#120593 Related: ClickHouse#112203 Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Internal second-model review: adjudication log (click to expand)Pre-publication review by an independent model (engine: codex): three gate rounds plus my own pre-gate pass
Severity: ❌ blocker / Session id: cron:clickhouse-review-slot-8:20260918-145700 |
|
Workflow [PR], commit [113a176] Summary: ✅
AI ReviewSummaryThis PR adds Findings❌ Blocker: Final VerdictStatus: LLVM Coverage ReportMeasured on commit 113a176.
Changed lines: Changed C/C++ lines covered: 19/19 (100.00%) · Uncovered code |
`Stateless tests (amd_msan, flaky check)` reddened 1 run in 50 on this PR's own new test at head 4bea950. The failing line was the liveness guard, `KILL QUERY reached the index scan: 0`: the kill landed before the skip index scan was entered, so that run proved nothing about the checkpoint the test exists to cover. The other four flavours passed 50/50 each. The scenario waited for `system.processes.elapsed > 1` on the victim query. The process list entry is inserted before planning starts, so elapsed time only approximates "the scan is running", and on a contended runner the phases ahead of the scan outlast one second. The kill then ends the query in a window where none of the work has run, with the same `QUERY_WAS_CANCELLED` the oracle greps for, which is the case the guard was added to reject. So the attempt is verified instead of timed: the scenario is now a function, and an attempt the guard rejects is discarded and retried with a longer wait (1 s, 4 s, 16 s), each attempt under its own query id so the probe cannot read an earlier attempt's row. The oracle is unchanged, and the retry cannot hide a regression: a kill that does not stop the query reports "still waiting after 15s" from any attempt, and the guard reads 1 there because the whole scan runs. Measured on the fix binary, Build-ID 6fe1dedb1a9541a007e1e0ab56c5b81893dd6075: * The failure reproduces deterministically by adding a 3 s scalar subquery to the kill query, which lengthens exactly the phase the old predicate could not see past. The published test then fails with the CI diff byte for byte (`reached the index scan: 1` -> `0`, and `system.query_log` records 0 us of index filtering for a cancelled query); this version passes, with the same log showing attempt `_kill_1` rejected at 0 us and attempt `_kill_4` asserted at 1138106 us. * 100 of 100 runs pass at 8-way concurrency: 50 with both randomizers, 50 with `--no-random-settings`, plus the bulk filtering, query condition cache and planning route draws. 9.1 to 9.5 s per run, unchanged, because the first attempt suffices whenever nothing is slow. * The test still fails on the pristine base binary, Build-ID 01c086e6178f012e81291c93a15c33c16af5fe0a: FAIL in 151.70 s with `KILL QUERY: still waiting after 15s`. Related: ClickHouse#120593 Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
|
The Cause: the scenario waited for Reproduced deterministically by adding a 3 s scalar subquery to the kill query, which lengthens exactly the phase the old predicate could not see past: the published test then fails with the CI diff byte for byte, this one passes ( |
|
|
||
| /// Checked once on entry so that a deadline that has already passed is observed even by a call that | ||
| /// charges no work. | ||
| const std::function<void()> check_cancellation = makeCancellationCheck(name); |
There was a problem hiding this comment.
This closes the ColumnConst(Array) carrier, but has still has a second constant-container path through Map. executeMap() does convertToFullColumnIfConst() and then hands a plain ColumnArray to executeArrayImpl() (src/Functions/array/arrayIndex.h:943-968), so has(const_map, key_column) never reaches this CancellationBudget. That leaves the same rows * map_size() unchecked loop the PR is fixing for arrays, just on the documented has(map, key) surface; notHas inherits it because it delegates to has.
I think executeMap() needs to preserve const-ness here the same way MapToSubcolumnAdapter already does in src/Functions/array/FunctionsMapMiscellaneous.cpp:255-256, so a const map becomes a const keys array and reuses executeConst(). A focused regression test on has(const_map, column) would pin the remaining carrier.
There was a problem hiding this comment.
Confirmed, measured on the pushed head. With this PR's own fixture (200k rows, one part) and
max_execution_time = 1, timeout_overflow_mode = 'break', a 1000-key constant map runs 2009 ms with no
error, while the array carrier stops at 1004 ms with Code 159 ... elapsed time limit reached in function has. KILL QUERY sent after 1s returns 1.27s later against 0.166s for the array, and the map error carries no
while executing 'FUNCTION has(...)', so the cancellation is seen by the next pipeline check, not inside the
function. notHas inherits it. mapContains(map, key) and has(mapKeys(map), key) already preserve constness
and already stop, so the gap is specific to the has(map, key) spelling.
The materialized copy makes work track memory, about 1.66 GiB per second of unchecked scan (1000 keys: 1910 ms
at 3.17 GiB; 10000 keys dies on a single 13.04 GiB allocation, so the huge-map example errors rather than
stalls). max_memory_usage defaults to 0, so the window is bounded by server memory rather than by a constant.
I prototyped your remedy: it stops at the deadline, uses 6.05 MiB instead of 3.17 GiB, is 1.4x faster, and a new
scenario in the test reddens on this head for exactly that line. It is not free, though. 31 of 32 differential
cases are byte-identical; the 32nd is has(map(NULL::Dynamic, 1), NULL), which goes 0 to 1. That is what
mapContains, mapKeys and both array paths already return, but it is pinned at 0 by
04338_has_map_dynamic_key_lowcardinality_arg, and the non-const map path keeps returning 0, so const-
preservation trades an array-vs-map inconsistency for a const-vs-non-const one. A constant map above 1e6 keys
also starts raising Code 128 TOO_LARGE_ARRAY_SIZE, as mapContains already does there.
A Dynamic/NULL semantics change does not belong in a cancellation fix for the constant-array carrier this issue
reports, so I am not folding it in here. I will send it separately, in the shape with no semantic delta (chunk
the row range inside executeMap and check cancellation between chunks, which also bounds the peak memory
above), unless a maintainer prefers the const-preserving version with the NULL answer changed deliberately.
There was a problem hiding this comment.
Sent as #121034, and not in the shape I said I would use. The Dynamic-NULL delta that made me pick chunking does not exist in the const-preserving version as implemented: 04338_has_map_dynamic_key_lowcardinality_arg stays green with its reference untouched, and 92 differential cases across every needle wrapper and key type are byte identical to master. Chunking measured worse, since it bounds the copy instead of removing it, so #121034 removes the copy and puts the cancellation checkpoint in the loop that performs the work.
Build profile diff (arm_release)Commit See the job log for details. |
`Stateless tests (amd_msan, flaky check)` reddened 2 runs in 50 on this PR's own new test at head 846d178. Both diverge on the same single line, the anti-vacuity guard of the scenario evaluated during planning: -planning route spent over 1s filtering marks: 1 +planning route spent over 1s filtering marks: 0 Cancellation itself held in both runs, which reported `stopped in function has` for both routes, and the four other flavours passed 50/50 each. The victim query is stopped by its own deadline, so the index scan only gets whatever is left of that deadline once the phases ahead of it have taken their share. The guard, 1 s of `FilteringMarksWithSecondaryKeysMicroseconds` out of a 3 s deadline, is therefore really the predicate "those phases fitted in 2 s". They cost 32 to 76 ms locally, a 40x margin, which is why 48 of 50 runs and every run of the other flavours pass; MSan running nproc-1 parallel copies of a 1e10-comparison scan is where they do not. So the attempt is verified rather than assumed. The scenario is now a function, and an attempt its guard rejects is discarded and retried with a deadline large enough to dwarf that cost, 3 s and then 12 s, each attempt under its own query id so the probe cannot read an earlier attempt's row. The oracle and the reference file are unchanged, and the retry cannot hide a regression: a deadline that does not stop the query at all is reported from the first attempt, with no retry, which is also why an unfixed binary still fails in one pass. Measured on the published head, Build-ID 6fe1dedb1a9541a007e1e0ab56c5b81893dd6075: * The failure reproduces deterministically by charging the deadline for a slow pre-scan phase with a scalar `sleep(2.5)`, which is evaluated during analysis. The published logic then fails with the CI diff byte for byte; this logic passes. `system.query_log` records the published single shot at 461,548 us of index filtering, and the new pair as attempt `_0_3` at 462,569 us, rejected, followed by `_0_12` at 9,464,236 us, asserted. * Both deadline scenarios were exposed, not only the one that reddened: under the same injected cost the scenario evaluated while reading also reports 0, at 455,260 us. The retry lives in the helper they share, so both are covered. * 100 of 100 runs pass at 8-way concurrency, 50 with both randomizers and 50 with `--no-random-settings`, at 8.89 to 9.85 s per run against the published head's 8.8 to 9.4 s, because the first attempt suffices whenever nothing is slow. Four directed draws pass at 9.05 to 9.19 s: bulk filtering and the query condition cache each way, the planning route pinned, and `max_threads = 1`. * The test still fails on the pristine base binary, Build-ID 01c086e6178f012e81291c93a15c33c16af5fe0a, in 146.37 s, with five lines diverging including `KILL QUERY: still waiting after 15s`. Making the guard relative instead, `region * 2 > query_duration`, was measured to be weaker than the threshold it would replace: since the duration is the deadline, that is the predicate "those phases fitted in 1.5 s", and it reads 0 on the same reproduction. A timing-free attribution predicate has no uniform form either, because `SelectedRows` is 0 for the planning route but 174,400 for the read-time one, where the marks are all selected during planning and pruned while reading. Related: ClickHouse#120593 Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
|
…dex.h
`Build (amd_fuzzers)` could not link the standalone fuzzer executables on this
PR's head:
ld.lld-22: error: undefined symbol: DB::makeCancellationCheck(char const*)
>>> referenced by arrayIndex.h:1242
>>> has.cpp.o:(DB::FunctionArrayIndex<DB::HasAction, DB::NameHas>::executeConst(...))
>>> in archive src/libdbms.a
`makeCancellationCheck` is defined in `Functions/CancellationBudget.cpp`, which
belongs to `clickhouse_functions`. `has.cpp` is deliberately extracted into
`dbms_sources` by `src/Functions/array/CMakeLists.txt`, because
`ArrayExistsToHasPass.cpp` needs `createInternalFunctionHasOverloadResolver`, so
the new call in `arrayIndex.h` `executeConst` is instantiated inside
`libdbms.a` and leaves an unresolved reference to a `clickhouse_functions`
symbol there. That breaks the property the `DBMS_FUNCTIONS` list exists to
maintain, and the targets in `src/{Core,Storages,Compression}/fuzzers` link
`dbms` alone, so they have nothing that can resolve it. No other flavour links
such an executable, which is why only the fuzzers build sees it.
Move `CancellationBudget.cpp` into `DBMS_FUNCTIONS`, the treatment
`checkHyperscanRegexp.cpp` already gets for the same reason, being called from a
header. The translation unit only uses `Interpreters/Context`,
`Interpreters/ProcessList`, `CurrentThread` and `Exception`, all already in
`dbms`, so nothing is pulled in the other direction, and the callers left in
`clickhouse_functions` still resolve it because they link `dbms` publicly.
`has.cpp` is the only `arrayIndex.h` user on the `dbms` side; `indexOf.cpp`,
`countEqual.cpp`, `indexOfAssumeSorted.cpp` and `FunctionsMapMiscellaneous.cpp`
stay in `clickhouse_functions_array`. The other header-side callers of
`makeCancellationCheck`, `CountSubstringsImpl.h` and `FunctionStringReplace.h`,
are only instantiated by `clickhouse_functions` translation units, so master
never had an unresolved reference and no other call site leaked one.
Verified by linking `src/Core/fuzzers/names_and_types_fuzzer.cpp` against
`dbms` alone, with the fuzzer targets' library set: it fails with exactly this
one undefined symbol before the change, at the same `arrayIndex.h` line and
from the same `has.cpp.o` member, and links with none after. `libdbms.a` now
defines the symbol in `CancellationBudget.cpp.o`, the full `clickhouse` binary
still links with no duplicate definition, and `05227_has_const_array_cancellation`
passes 20 of 20 runs at 8-way concurrency, 9.45 to 9.70 s, against Build-ID
bc2476f8d557566f5f0f7f270ebbd102eb8a6cd2.
Related: ClickHouse#120593
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
|
CI finish ledger - c631758Every failure below has an owner: a fixing PR (mine or external), or a full-effort fix task
Session id: cron:our-pr-ci-monitor:20260919-133220 |
CI finish ledger - c687601Every failure below has an owner: a fixing PR (mine or external), or a full-effort fix task
Session id: cron:our-pr-ci-monitor:20260920-053046 |
Changelog category (leave one):
Changelog entry (a user-readable short description of the changes that goes into CHANGELOG.md):
Fixed
max_execution_timeandKILL QUERYbeing ignored whilehas,indexOf,indexOfAssumeSorted,countEqual,mapContainsKeyormapContainsValuesearches a constant array. Asetskip index evaluates its condition over every value it stored for a part in one such call, so a query using that index kept running to the end of the part after its time limit had expired or it had been killed.Description
Reported in #120593 by @ 4ertus2 and investigated at @ PedroTadim's request. The issue describes two defects; this PR fixes the unkillable query. The slowness is a separate analyzer defect.
Root cause.
x IN (<constant array>)resolves tohas(<constant array>, x), andhasover a constant array runsFunctionArrayIndex::executeConst, whose nested loop performsrows * arr.size()Fieldcomparisons with no cancellation checkpoint. Asetindex evaluates its condition as oneExpressionActionsover every value the index stored for a part, so that single call can receive as many values as the part has rows. The surrounding checks are too coarse: they run once per (part, index), before the work.The change.
executeConstuses the existingCancellationBudgetmachinery, as its other users do: checked once on entry, then charged per row with the comparisons that row performed. Chargingi + 1rather thanarr.size()keepscheckTimeLimit(), which takescancel_mutex, off the per-row path when a row matches early. One budget covers both index analysis routes and the ordinary data path. One row against an enormous constant array still runs one uninterrupted pass, bounded by the cost of materializing it. The non-constant-array paths scan only the row's own data and are left alone (#112203).hasAll/hasAny/hasSubstrreach the same shape throughGatherUtils::sliceHas, separate machinery, so a separate PR unless you want it here.Validation. Debug build, 200000 rows, one active part. Before:
max_execution_time = 3ran 72.5 s with no error, andKILL QUERY ... SYNCreturned after 72.2 s. After: 3.0 s withTIMEOUT_EXCEEDEDnaming the function, and the kill returns in 0.18 s. The new test covers both index analysis routes and the kill; its three oracle lines diverge on unfixed master. The added per-row cost is bounded at +0.4 ns/row on a 3 element array.Related: #120593
Related: #112203
Workflow [PR]
Sync PR [sync-upstream/pr/120870]