Collect system.query_views_log: materialized-view execution - #33
CamiloSierraH wants to merge 3 commits into
Conversation
A materialized view that throws, or that "succeeds" while writing nothing, is invisible in query_log — the parent INSERT reports success either way. system.query_views_log is the only place an MV's own execution is recorded, and the bundle explicitly did not collect it. Adds system.query_views_log_3_days to all three modes, aggregated into 1-hour buckets by view, target, type, status and exception_code. Per bucket: executions, a zero_write_executions counter (read_rows > 0 AND written_rows = 0), row/byte sums, view duration sum and max, peak memory as avg/median/max, and a 500-char sampled exception. Design notes: - Aggregate, not raw rows. query_views_log is one row per (insert x view) and rivals part_log in size. GROUP BY state stays bounded because the keys are all low-cardinality; initial_query_id and the exception text are deliberately not keys (the part_name regression part_log documents). - merge(system, '^query_views_log') so a post-upgrade query_views_log_0 still counts — the pre-upgrade baseline is exactly what a per-view memory regression needs. With no such table it fails with 636 CANNOT_EXTRACT_TABLE_STRUCTURE, a recognisable "not collected". - No uniqExact on the exception string: exception_code is a group key, so any(exception) is already representative and a hash set of full messages would buy nothing. - peak memory as median/max, not just sum: a sum tracks insert volume and hides a single view that got more expensive per block. - view_uuid is NOT collected. Verified on 26.7.5.10 that the server writes the zero UUID into it for every view while system.tables carries the real one. For an MV declared without TO, view_target is db.`.inner_id.<uuid>` and that does change on a recreate. - Every aggregate argument is qualified through the table alias. Without it `sum(view_duration_ms) AS view_duration_ms` shadows the column and a later max() over it is rejected with ILLEGAL_AGGREGATION 184. - gov splits view_name/view_target on '.' and hashes each half, so the PrintGovNameMapping CSV can reverse them, and ships no exception text. Hashing sits in the outer select over the aggregated result, so SHA256 runs once per output row rather than once per source row. Skill updates: new file-guide entry, HC-5.9 and HC-7.6/7.7/7.8, patterns P-35 (MV runs clean but writes nothing) and P-36 (MV push throws after the base part committed), a bundle-layout row, and query_views_log removed from running-the-tool's "deliberately not collected" list. Both new patterns record the trap found while testing: a failed INSERT marks EVERY view in the pipeline with ExceptionWhileProcessing and the same message, not just the one that broke. Verified against ClickHouse 22.8.21.38 and 26.7.5.10: all six files run, and onprem/cloud/gov collect end-to-end with the silent-drop and MV-failure signatures reproduced. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The query_views_log collector landed without a reader, so MV failures — the highest-severity thing that file records — only reached an analyst who went looking. Adds six checks to the deterministic pre-pass. Coverage gate (HC-0): cross-checks system.tables for MaterializedView engines against the file. If the server has MVs and query_views_log is absent or empty, log_query_views = 0 or <query_views_log> is unconfigured, and "no MV findings" means no telemetry rather than a healthy pipeline. This is the check that stops a false all-clear, so SKILL.md step 0 now asks for it in the coverage lines. Failures (HC-7.6/P-36), attributed correctly: a failed INSERT writes an ExceptionWhileProcessing row for EVERY view in the pipeline carrying the same message. Naively counting rows per view reports four broken MVs when one is broken, so the check names the view with the highest count as the culprit and reports the rest as blast radius. Zero-write as a CHANGE, not an absolute (HC-7.7/P-35): a filtering MV legitimately writes nothing forever, which is why the flat ratio in HC-7.7 is not what gets implemented. Only a view with a mixed bucket history — it wrote, then stopped — raises a warning. Views that never wrote get one info line. Per-view memory step change (HC-5.9/P-54): median peak memory of the window's second half against its first, flagged at >= 3x only while written rows stay within +/-25%. Needs >= 6 buckets, so it stays quiet on thin windows. Timeline flag: MV push failures per hour feed the existing incident table as an "mv failures N" flag, which is what correlates them with Keeper loss or stalled merges. No new column, so bundles without MVs are unchanged. Usage table: top 10 views by executions with written rows, zero-write %, failed pushes, median peak memory and max duration — the one output that describes the MV topology on a healthy bundle, where no finding fires. Works unchanged in gov mode: view_label() falls back to the hashed view_database/view_table pair, and every count and ratio is identical. Verified on a real onprem bundle (correct culprit attribution across four views where one was faulty), a gov bundle, a bundle with the file removed, and a synthetic fixture for the stopped-writing and memory-step branches — where a steady view correctly raised nothing. make test passes; --json mode checked on all four. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
There was a problem hiding this comment.
Copilot review overview
🟡 Changes recommended
Unresolved moderate issues affect collector correctness, diagnostics, and documentation alignment.
Get a fresh assessment by requesting another Copilot review.
Review effort: Lite
Findings: 5
Open (6)
Incorrect parsing of dotted inner MV targets · New Incorrect parsing of dotted inner MV targets · New QueryStart rows are incorrectly counted as executions · New Failed view attribution ignores exception details · New Write-stop detection loses bucket ordering · New Documented warning condition differs from implemented check · New
What changed in this PR
Adds system.query_views_log collection and materialized-view diagnostics across ClickHouse deployment modes, including failure, zero-write, memory, and coverage analysis.
Changes:
- Adds versioned collectors for on-prem, cloud, and government environments.
- Extends bundle inspection and reporting with MV health checks.
- Updates documentation, patterns, bundle layout, and default-window tests.
Unresolved issues remain in collector target parsing, execution accounting, exception attribution, temporal zero-write detection, coverage interpretation, and health-check documentation alignment.
| File | Summary |
|---|---|
skills/clickhouse-diagnostic/SKILL.md |
Documents MV telemetry coverage. |
skills/clickhouse-diagnostic/scripts/inspect_bundle.py |
Adds MV analysis and reporting. |
skills/clickhouse-diagnostic/references/running-the-tool.md |
Documents the MV collection window. |
skills/clickhouse-diagnostic/references/known-patterns.md |
Adds MV failure and zero-write patterns. |
skills/clickhouse-diagnostic/references/health-checks.md |
Adds MV health-check guidance. |
skills/clickhouse-diagnostic/references/file-guide.md |
Documents the new bundle file. |
skills/clickhouse-diagnostic/references/bundle-layout.md |
Defines MV archive schema and redaction. |
README.md |
Lists the collector and window. |
queries.onprem/system.query_views_log_3_days.sql |
Adds the baseline on-prem collector. |
queries.onprem/23.11.1.0/system.query_views_log_3_days.sql |
Adds the versioned on-prem collector. |
queries.gov/system.query_views_log_3_days.sql |
Adds the redacted government collector. |
queries.gov/23.11.1.0/system.query_views_log_3_days.sql |
Adds the versioned redacted government collector. |
queries.cloud/system.query_views_log_3_days.sql |
Adds the cloud collector. |
queries.cloud/23.11.1.0/system.query_views_log_3_days.sql |
Adds the versioned cloud collector. |
internal/query/window_test.go |
Verifies the new default window. |
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
| hex(SHA256(concat(splitByChar('.', view_target)[1], '%salt%'))) AS target_database, | ||
| hex(SHA256(concat(splitByChar('.', view_target)[2], '%salt%'))) AS target_table, |
There was a problem hiding this comment.
Fixed in 7b210e7 — correct. Verified live: for an MV declared with an ENGINE, view_target is db.\.inner_id.`andsplitByChar('.', …)[2]was a bare backtick, so every inner target hashed to one value that matched nothing. Both gov files now split at the first dot and strip backticks; checked that the hashed halves equalhex(SHA256(database))/hex(SHA256(name))of the matchingsystem.tables` row for a TO target and an inner target alike.
| hex(SHA256(concat(splitByChar('.', view_target)[1], '%salt%'))) AS target_database, | ||
| hex(SHA256(concat(splitByChar('.', view_target)[2], '%salt%'))) AS target_table, |
There was a problem hiding this comment.
Fixed in 7b210e7 — correct. Verified live: for an MV declared with an ENGINE, view_target is db.\.inner_id.`andsplitByChar('.', …)[2]was a bare backtick, so every inner target hashed to one value that matched nothing. Both gov files now split at the first dot and strip backticks; checked that the hashed halves equalhex(SHA256(database))/hex(SHA256(name))of the matchingsystem.tables` row for a TO target and an inner target alike. (same fix, root file.)
| "no MV telemetry in this bundle: 'no MV findings' here does NOT mean the MVs are healthy", "HC-0") | ||
| elif qv: | ||
| views = {} | ||
| for r in qv: |
There was a problem hiding this comment.
Guarded in 7b210e7. For the record it was theoretical: the server writes only QueryFinish / ExceptionWhileProcessing for views — checked SELECT status, count() FROM system.query_views_log GROUP BY status on 26.7, no QueryStart rows exist. Skipped anyway, as the query_log pass does, so a future change in what the server logs cannot double-count.
| # ---- HC-7.6 failures, attributed to the view that actually broke | ||
| failing = sorted(((k, v) for k, v in views.items() if v["failures"]), | ||
| key=lambda kv: -kv[1]["failures"]) | ||
| if failing: | ||
| culprit, cv = failing[0] | ||
| codes = ", ".join(f"{ERROR_NAMES.get(c, c)}({c})={n}" for c, n in cv["codes"].most_common(3)) | ||
| blast = (f"; {len(failing) - 1} other view(s) carry the same message — a failed INSERT marks " | ||
| "every view in the pipeline") if len(failing) > 1 else "" |
There was a problem hiding this comment.
Fixed in 7b210e7 — right, and the data makes it exact rather than heuristic. Every sibling's row carries the same message, and that message ends with … while pushing to view db.mv naming the view that threw — at position ~200 of 287 chars in the real bundle, inside the 500-char cap. The pre-pass now parses it. Without text (gov) it names a view only on a strict count lead; with neither it lists the failing views and says attribution is unavailable. Fixture: three siblings at 7 failures each → the named one is picked, not the first in input order.
| # ---- HC-7.7 a view that STOPPED writing (mixed history), vs one that never wrote | ||
| stopped = [(k, v) for k, v in views.items() | ||
| if v["buckets_wrote"] >= 2 and v["buckets_zero"] >= 2 | ||
| and v["buckets_zero"] >= v["buckets_wrote"]] |
There was a problem hiding this comment.
Fixed in 7b210e7 — correct, the counters lost order. The pre-pass now keeps the per-hour history and looks for the last hour with writes followed by ≥ 2 later hours that read rows and wrote none; the message quotes both hours. A view that started writing (zeros first, writes later) has an empty trailing run and is not flagged — fixture-tested. I kept the ≥ 2 trailing-hour threshold rather than 1: a single zero-write hour after a write is what any bursty MV looks like at the end of the window.
| | 7.4 | `system.tables` | ≥ 5 `MaterializedView`s on one source table; MV chains ≥ 2 hops *(guideline)* | info | Every insert block is processed by each MV synchronously; TOO_MANY_PARTS on an MV target means the *source* gets too many small inserts. P-34. | | ||
| | 7.5 | `text_log` / `system.errors` | `INSERT_WAS_DEDUPLICATED` (389) or "Deduplication path already exists" | info→warning | Client retries are being deduplicated (normal) — or every insert is (token misuse) → P-33. | | ||
| | 7.6 | `query_views_log_3_days` | any `status = 'ExceptionWhileProcessing'` | warning→critical | The MV threw after the base part was committed: the source has the rows, the target does not. `exception_code` names the class (60 after a swap/rename/detach, 241 memory, 252 parts, 341 during drain). **A failed INSERT marks every view in the pipeline with the same message** — attribute it to the view named in the text. P-36. | | ||
| | 7.7 | `query_views_log_3_days` | `zero_write_executions / executions > 0.9` on a view with `read_rows > 0` *(guideline)* | warning | The MV ran clean and produced nothing. Legitimate for a filtering MV — compare against that view's earlier buckets and its siblings before concluding. P-35. | |
There was a problem hiding this comment.
Fixed in 7b210e7 — the row now describes what the code implements (the ordered stop rule, info for a view that never wrote) and says explicitly why the flat ratio is not the rule: it fires on every correctly filtering MV. HC-7.6 also gained the attribution method.
…rdered stop detection Six findings on #33, each checked against a live 26.7 server first. Gov hashing split view_name / view_target on EVERY dot. An MV declared with an ENGINE writes to db.`.inner_id.<uuid>` — a name with dots inside — so splitByChar('.', view_target)[2] was a bare backtick for every inner target, hashing to one value that matched nothing in the mapping CSV. Both gov files now split at the first dot only and strip backticks; verified that the hashed halves equal hex(SHA256(database)) / hex(SHA256(name)) of the matching system.tables row for a TO target and an inner target alike. The pre-pass counted every row as an execution. The server writes only QueryFinish / ExceptionWhileProcessing for views (checked: no QueryStart rows exist), so this was theoretical — skipped anyway, as the query_log pass does. Attribution picked the view with the most failed pushes, but a failed INSERT gives every sibling an identical row, so counts tie and the sort order chose. The sampled exception says which view threw — "… while pushing to view db.mv" — on every sibling's row and well inside the 500-char cap (position ~200 of 287 in the real bundle). The pre-pass now parses that; without text (gov) it names a view only on a strict count lead; with neither it lists the failing views and says attribution is unavailable. On a fixture with three siblings at 7 failures each it names the one the text names. Stopped-writing kept counts of writing and zero-write buckets, so a view that STARTED writing (zeros first) fired the same warning. It now keeps the ordered per-hour history: the last hour with writes, then the run of later hours that read rows and wrote none; two or more of those is the finding, and the message quotes the hours. A view that started writing has an empty trailing run and is not flagged (fixture-tested). HC-7.7 still described the flat ratio the code deliberately does not implement; it now describes the ordered rule and says why the ratio is not it. HC-7.6 says how the culprit is attributed. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>


Why
A materialized view that throws, or that "succeeds" while writing nothing, is invisible in
query_log— the parent INSERT reports success either way.system.query_views_logis the only place an MV's own execution is recorded, and the bundle explicitly listed it under "deliberately does not contain".Reviewing the closed escalations that touch
query_views_logturned up five recurring questions, each already answered by support engineers running ad-hoc hourly aggregates against this table:QueryFinish,exception_code = 0,read_rows > 0,written_rows = 0status = 'ExceptionWhileProcessing'(60 / 241 / 252 / 341)peak_memory_usagemedian/max vs flatwritten_rowsview_duration_mswritten_rowsper view per bucketWhat
1. The collector.
system.query_views_log_3_daysin all three modes, 1-hour buckets keyed by view, target, type, status andexception_code. Per bucket:executions,zero_write_executions, row/byte sums, view duration sum + max, peak memory as avg/median/max, and a 500-char sampledexception.2. The pre-pass reads it. Six checks in
inspect_bundle.py, so MV failures reach triage instead of waiting for someone to go looking.3. Skill docs. A
file-guide.mdentry,HC-5.9andHC-7.6/7.7/7.8, patterns P-35 (MV runs clean but writes nothing) and P-36 (MV push throws after the base part committed), abundle-layout.mdrow,P-33/P-34upgraded from hedged references to the real file, andquery_views_logstruck from the never-collected list.Keeping the query light
query_views_logis one row per (insert × view) and rivalspart_login size, so the shape matters more than the window:initial_query_idand the exception text are deliberately not keys — that is thepart_nameregressionpart_logdocuments.uniqExacton the exception string.exception_codeis a group key, soany(exception)is already representative; a hash set of full messages would buy nothing and cost real CPU.stack_trace,view_queryandProfileEventsare never read — the bulk of the table's bytes.SHA256runs once per output row instead of once per source row.The pre-pass checks
The two that required care:
ExceptionWhileProcessingrow for every view in the pipeline with the same message. Counting rows per view reports four broken MVs when one is broken. The check names the highest-count view as the culprit and reports the rest as blast radius.> 0.9ratio in HC-7.7 is not what got implemented. Only a view with a mixed bucket history — it wrote, then stopped — warns. Views that never wrote get oneinfoline.The rest: an HC-0 coverage gate (MVs exist in
system.tablesbut noquery_views_log→log_query_views = 0; without this, "no MV findings" is indistinguishable from "no telemetry"), a per-view memory step change (≥ 3× median peak across the window halves with writes flat, ≥ 6 buckets required), anmv failures Nflag on the existing incident timeline, and a top-10 views table — the only output that describes the MV topology on a bundle where nothing is wrong.Three things found by testing rather than reading
view_uuidis always the zero UUID. It was in the design as a recreate-detector; on 26.7.5.10 the server writes zeros into it for every view, TO-target and inner-table alike, whilesystem.tablescarries the real one. Dropped. For an MV declared withoutTO,view_targetisdb.`.inner_id.<uuid>`and that changes on a recreate.merge()with no matching table fails with 636CANNOT_EXTRACT_TABLE_STRUCTURE, not 60. That is the recognisable "not collected" when<query_views_log>is unconfigured.merge(system, '^query_views_log')rather than the bare table so a post-upgradequery_views_log_0still counts — the pre-upgrade baseline is exactly what a memory regression needs.Verification
SQL against 22.8.21.38 (the floor) and 26.7.5.10:
GROUP BY ALL,clusterAllReplicasand the gov hashingzero_write_executions = 5/5, a broken JOIN atexception_code = 60Pre-pass against four bundles: a real onprem one (correct culprit attribution across four views where one was faulty), a gov one (hashed labels, identical ratios), one with the file removed (coverage gate fires), and a synthetic fixture for the stopped-writing and memory-step branches — where a steady view correctly raised nothing.
--jsonmode checked on all four.make testpasses, includingTestShippedQueryDefaultWindowsandTestGovQueries_NoRawIdentifiersOrDDL.Review follow-up
Six findings, all addressed in the third commit and each checked against a live server first:
view_targeton every dot;.inner_id.<uuid>targets hashed to a bare backticksystem.tables's for TO and inner targetsQueryStartrows counted as executionsQueryStartrows for views (checked)while pushing to view <culprit>Re-run on the real bundle (
mv_joinnamed from the text, three siblings correctly reported as blast radius) and on two fixtures (--jsonclean);make testpasses.🤖 Generated with Claude Code