Skip to content

Commit 9dde5a0

Browse files
authored
[OPIK-7315] scope the sentinel repair to the flag window (#8055)
* [OPIK-7315] scope the sentinel repair to the flag window The repair matched every epoch end_time and NaN ttft in the table. That is unsafe: an epoch end_time is not evidence the flag produced it, since clients send them and rows predating the flag hold them. Those values cannot be recovered afterwards either, because the parked successor encodes an absent end_time as the same epoch, so no reference copy exists -- and the counts would still have reported success, because no sentinel would remain. Measured on an internal environment: the unbounded predicate matched 34 keys across 12 workspaces, of which 5 came from the flag window. The other 29 carried genuine client-sent values. --sentinel-window-from / --sentinel-window-to are now required, matched on created_at OR last_updated_at so a row created in the window and a pre-existing row updated in it are both caught. The counts carry the same window, so 0 means "the flag's damage is gone" rather than "no such value exists anywhere" -- unbounded, the gate could never clear on an estate holding any genuine epoch value. Both bounds are pinned to UTC. The timezone assertion added with the epoch literal caught this during development: unpinned, the window shifts with the server timezone and matches nothing. The test gains a cohort matching the predicate but written outside the window, asserting it keeps both values. * [OPIK-7315] describe the window consistently, and cover its two arms Baz review on #8055. Three of these are my own change not carried through. --confirm-flag-was-live still said it accepts "every epoch end_time and NaN ttft in traces" becoming NULL, written before the window existed. It authorises a window-scoped repair; rows outside are never touched whether or not it is passed. Corrected in the flag doc and the runtime NOTE. Both printed follow-up commands omitted the now-mandatory bounds, so each was guaranteed to exit 2 -- the same defect as the stage A command earlier in this work. They now carry placeholder bounds and say the script cannot know them. sentinelCounts interpolated the bounds while its sibling repairSentinels bound them. Now bound; only the database name stays formatted, an identifier having no bind form. And the test tied created_at, last_updated_at and start_time to one value, so it never exercised the last_updated_at arm and had no row on either boundary. Adds a row created before the window but updated inside it, and rows exactly at windowFrom and windowTo. Mutation-checked: dropping the last_updated_at arm leaves endTime=2 and fails; making windowTo inclusive fails. * [OPIK-7315] qualify every count the repair reports, and name the carry-forward gap Thiago's review on #8055. The window scoping silently changed what the output means, and I qualified one message out of four. The three that report counts still asserted table-wide facts, so bounds given in local time would produce 0 in-window, an unqualified clean bill of health, and exit 0 over unrepaired damage -- ticking the runbook box that gates finalize.sh. All three now name the window, and the driver prints the SAME aggregates over an all-time range beside them: a 0 in-window against a non-zero total is the signature of a wrong window, and is now visible rather than silent. Both readings come from the one shipped .sql file, so they cannot drift. The carry-forward gap is real and verified in TraceDAO.UPDATE, which copies created_at and (when the patch omits them) end_time/ttft verbatim while last_updated_at defaults to now64(6). A trace created pre-window, patched in-window under the flag, then patched again post-revert has a live version matching neither arm, and the repair clears the older in-window version so the gate still reports success. Documented, and the README claim that both arms catch every case is removed, since this case falsifies it. I have NOT redefined --sentinel-window-to as the repair time. That closes this hole by opening the opposite one: a row holding a genuine epoch end_time, merely patched inside the widened range, then matches and is nulled irrecoverably -- and end_time is carried forward verbatim, so nothing in the data separates the two. Measured here: 0 keys are pre-window-created and touched since, so this estate has no instances of either. The trade is now stated so the bound is chosen knowingly. Also: the sentinel_counts header said it takes no window while doing three substitutions, and the window/mode check had landed between a comment and the two flag checks it documents. * [OPIK-7315] cover the DateTime64 range, pin the carry-forward gap, own finalize.sh's limits Baz review on #8055. The unbounded comparison capped at 2100-01-01, an arbitrary number in a dataset where far-future timestamps are real (see the runbook's far-future id section) -- exactly the rows an operator would want the comparison to surface. Now 1900..2299, the DateTime64 range. The carry-forward gap Thiago found is now asserted rather than only described: a cohort with two versions of one key, the in-window one repaired and the live one outside the window keeping its epoch, with the window-scoped counts still reading 0. Asserting a known limitation is deliberate -- change the window semantics without addressing it and the test flips, which is the point. Needed an explicit-id overload and a FINAL-collapsed count helper, since the claim is about the live row rather than any version. Not taken: repairing "the latest row for each key across the full table". Across the full table is the unbounded predicate this PR removes, which destroyed 29 rows' genuine values on the environment measured here. And the checklist claimed to gate finalize.sh. It does not: finalize.sh has zero references to the repair and reads no marker proving one ran with the right window. Said plainly, so the box is understood as the only control rather than a mechanical one. ---------
1 parent c6fc00a commit 9dde5a0

5 files changed

Lines changed: 303 additions & 76 deletions

File tree

apps/opik-backend/data-migrations/traces-local-v2-cutover/README.md

Lines changed: 40 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -1036,14 +1036,15 @@ Pick the stage by how far the cutover got:
10361036
`RENAME`, then drops the ex-wrapper — landing in the post-`EXCHANGE`, pre-wrap state. (Guarded: aborts unless `traces`
10371037
is `Distributed` and `traces_local` holds the successor schema.) See "Un-wrap" below for when to prefer it over stage C.
10381038
- **Sentinel repair — after a stage B/C promote, or after abandoning the cutover pre-`EXCHANGE`:**
1039-
restores `NULL` on the rows the flag wrote into the still-Nullable original and recomputes their `duration`. Which
1040-
invocation depends on whether a promote parked the successor, because that is the only topological proof a cutover ran
1041-
on this estate:
1039+
restores `NULL` on the rows the flag wrote into the still-Nullable original and recomputes their `duration`. **The
1040+
window is mandatory** (see below). Which invocation depends on whether a promote parked the successor, because that is
1041+
the only topological proof a cutover ran on this estate:
10421042
```bash
1043+
W=(--sentinel-window-from '<flag rolled out, UTC>' --sentinel-window-to '<revert landed everywhere, UTC>')
10431044
# after a stage B/C promote — traces_post_rollback_backup is the proof
1044-
./scripts/rollback.sh --database opik --sentinel-repair-only --confirm-flag-reverted
1045+
./scripts/rollback.sh --database opik --sentinel-repair-only --confirm-flag-reverted "${W[@]}"
10451046
# no parked successor: abandoned pre-EXCHANGE (incl. after stage A), or finalize.sh has recycled it
1046-
./scripts/rollback.sh --database opik --sentinel-repair-only --confirm-flag-reverted --confirm-flag-was-live
1047+
./scripts/rollback.sh --database opik --sentinel-repair-only --confirm-flag-reverted --confirm-flag-was-live "${W[@]}"
10471048
```
10481049
The second asserts the flag was live here, because without the parked successor nothing in the topology or the data
10491050
distinguishes an epoch `end_time` this flag minted from a value a client sent — and the repair rewrites the whole
@@ -1198,8 +1199,30 @@ exists (`Code 60`). That is the second of the two flags the stage comparison tab
11981199
`duration`. The promote made them live again and `finalize.sh` discards the successor's healed copy, so repair them
11991200
here, **after** step 1 has landed on every instance or in-flight writes keep minting more:
12001201
```
1201-
./scripts/rollback.sh --database opik --sentinel-repair-only --confirm-flag-reverted
1202+
./scripts/rollback.sh --database opik --sentinel-repair-only --confirm-flag-reverted \
1203+
--sentinel-window-from '<flag rolled out, UTC>' --sentinel-window-to '<revert landed everywhere, UTC>'
12021204
```
1205+
**Both window bounds are required, and there is no safe default.** An epoch `end_time` is not evidence the flag
1206+
produced it: clients send them, and rows predating the flag hold them. Unbounded, the repair would set those to
1207+
`NULL` with no way back — the parked successor encodes an absent `end_time` as that same epoch, so nothing holds the
1208+
original — and the counts would still report success. Measured on an internal environment: the unbounded predicate
1209+
matched 34 keys across 12 workspaces where only 5 came from the flag window. Take the bounds from when the flag
1210+
rolled out and when its revert finished landing on every instance. Rows are matched on `created_at` **or**
1211+
`last_updated_at`. Both bounds are interpreted as UTC regardless of the server's timezone.
1212+
1213+
**One case the window cannot catch, and the gate cannot see.** `TraceDAO.UPDATE` re-inserts a version copying
1214+
`created_at` and — when the patch omits them — `end_time`/`ttft` verbatim, while `last_updated_at` takes
1215+
`DEFAULT now64(6)`. So a trace created *before* the window, patched *inside* it under the flag, then patched *again*
1216+
after the revert has a live version carrying a pre-window `created_at` and a post-window `last_updated_at`, matching
1217+
neither arm. It keeps its epoch `end_time`, and because the repair does clear the older in-window version the counts
1218+
still reach `0` and report success.
1219+
1220+
Extending `--sentinel-window-to` to the moment the repair runs closes that, at a cost worth stating rather than
1221+
burying: a row holding a **genuine** epoch `end_time` that was merely patched inside the widened range then matches
1222+
too, and is nulled irrecoverably. `end_time` is carried forward verbatim, so nothing in the data separates the two
1223+
cases. Neither bound is safe in both directions — choose knowingly, and use the unbounded counts the driver prints
1224+
alongside to see what a wider window would take in.
1225+
12031226
It reads the counts first and issues no mutation when they are `0`, restores `NULL` in a single mutation
12041227
(`000004_rollback_sentinel_repair.sql`) which recomputes `duration` as it rewrites each row, then asserts the counts
12051228
reached `0` (`000004_rollback_verify_sentinels.sql`). It is idempotent. A bare `MATERIALIZE COLUMN duration` does
@@ -1237,10 +1260,17 @@ Treat a stage B/C rollback as complete only when all of these hold:
12371260
`tracesDistributedWrapEnabled` if the wrap had been applied. Those are the only two — partition pruning is
12381261
unconditional and has no flag. Verify positively, not by absence of errors: absent `end_time`/`ttft` must read back
12391262
as `null`.
1240-
- [ ] **Sentinel repair applied**`--sentinel-repair-only` printed `Sentinel postcondition OK` (or reported nothing to
1241-
repair, which is equally valid) and **exited zero**. The gate is `sentinel_end_time`, `sentinel_ttft` and
1242-
`stale_duration` all at `0`; a residual `duration < 0` count elsewhere in the table is expected, from rows whose
1243-
`end_time` genuinely precedes `start_time`.
1263+
- [ ] **Sentinel repair applied**`--sentinel-repair-only` printed `Sentinel postcondition OK` and **exited zero**,
1264+
**and the window passed is the one the flag was live in, in UTC**. The gate is `sentinel_end_time`,
1265+
`sentinel_ttft` and `stale_duration` all at `0` *inside that window*; a residual `duration < 0` count elsewhere is
1266+
expected, from rows whose `end_time` genuinely precedes `start_time`.
1267+
**"Nothing to repair" is not interchangeable with a completed repair.** It is equally what a wrong window
1268+
produces — bounds in local time being the common case — so check it against the unbounded counts the driver prints
1269+
beside it before ticking this.
1270+
**`finalize.sh` does not check any of this** — it has no notion of the repair, and reads no marker proving one
1271+
ran with the right window. This checklist is the only control standing between a wrong-window no-op and
1272+
`TRUNCATE TABLE traces_post_rollback_backup`, which retires the last reference copy. Treat the box as a human
1273+
gate, because that is all it is.
12441274
- [ ] **The parked successor still parked**`traces_post_rollback_backup` retained, not finalized. It is the only copy
12451275
of the post-cutover writes the rollback discarded, and the only thing that makes a retry cheap.
12461276

apps/opik-backend/data-migrations/traces-local-v2-cutover/scripts/db-app-analytics/000004_rollback_sentinel_repair.sql

Lines changed: 38 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -1,42 +1,56 @@
11
-- runbook traces-local-v2-cutover — ROLLBACK sentinel repair (driven by ../rollback.sh --sentinel-repair-only)
22
-- The gate test TracesLocalV2CutoverTest reimplements this statement inline; keep the two in step (see its Javadoc).
33
--
4-
-- Restores NULL on the restored ORIGINAL `traces` for rows written while traceColumnsNonNullable was true. The successor
4+
-- Restores NULL on rows written into the still-Nullable original while traceColumnsNonNullable was true. The successor
55
-- schema stores an absent end_time/ttft as a sentinel (epoch / NaN) where the original stores NULL, so rows that landed
66
-- through the flag read back as "ended at 1970" / "ttft NaN" once the promote makes the original live again — and the
7-
-- original's MATERIALIZED duration expression computed a large NEGATIVE duration from them. That expression does guard
8-
-- against the epoch, but on `start_time` only: `end_time` it checks for NULL alone, which a sentinel is not.
7+
-- original's MATERIALIZED duration computed a large NEGATIVE duration from them. That expression does guard against the
8+
-- epoch, but on `start_time` only: `end_time` it checks for NULL alone, which a sentinel is not.
99
--
1010
-- MATERIALIZE COLUMN duration would NOT fix that: it re-evaluates the same expression against the same sentinel. Only
1111
-- restoring NULL does, and the mutation recomputes duration as a side effect of rewriting the row.
1212
--
13+
-- THE WINDOW IS MANDATORY, AND IS THE ONLY THING THAT MAKES THIS SAFE. An epoch end_time is not by itself evidence the
14+
-- flag produced it: a client can send one, and rows that predate the flag entirely do. Repairing every match would set
15+
-- those to NULL and they could not be recovered — the parked successor encodes an absent end_time as the same epoch, so
16+
-- there is no reference copy to restore from, and the counts would still report success because no sentinel would
17+
-- remain. Measured on an internal environment: the unbounded predicate matched 34 keys across 12 workspaces where only
18+
-- 5 came from the flag window; the other 29 carried genuine client-sent values.
19+
--
20+
-- So the operator supplies the window the flag was live in, and only rows written inside it are touched. Both arms are
21+
-- needed, for the same reason the delta insert needs both: a row CREATED in the window is caught by created_at, and a
22+
-- pre-existing row UPDATED in the window — which is where its sentinel came from — is caught by last_updated_at.
23+
--
1324
-- NOT part of stage B/C, deliberately. The flag revert has to land on every backend FIRST or in-flight writes keep
14-
-- minting sentinels behind the repair, and rolling out config is not something these DB-facing scripts do. So this is a
15-
-- separate, later invocation, gated on the operator asserting the revert is live (--confirm-flag-reverted).
25+
-- minting sentinels behind the repair, and rolling out config is not something these DB-facing scripts do.
1626
--
1727
-- ONE ALTER carrying TWO commands, on purpose: neither predicate is on the primary key, so ClickHouse cannot prune parts
18-
-- and a mutation rewrites every one of them. Combining the commands into a single mutation halves that to one pass, which
19-
-- on a large table is the difference that matters in a rollback tail. The cost is atomicity — it needs ALTER UPDATE on
20-
-- BOTH columns and applies neither if one grant is missing (../rollback.sh translates the ACCESS_DENIED).
21-
--
22-
-- LIMITATION, inherent rather than an omission: an end_time of exactly epoch cannot be told from the sentinel, nor a
23-
-- genuine NaN ttft from the sentinel NaN — the successor schema uses those very values to MEAN "absent", so the
24-
-- distinction does not exist in the data to recover. What bounds the blast radius is the topology guard in
25-
-- ../rollback.sh (this runs only against a restored original with the successor parked) and the counts in
26-
-- 000004_rollback_verify_sentinels.sql, not this statement.
27-
--
28-
-- KEEP IN STEP WITH 000004_rollback_verify_sentinels.sql: same two predicates, same DateTime64 precision 9 (the
29-
-- original's end_time is nanosecond). A check filtered differently from the repair would clear while sentinels remain,
30-
-- or never clear at all. Change one, change both.
28+
-- and a mutation rewrites every one of them. Combining the commands into a single mutation halves that to one pass. The
29+
-- cost is atomicity — it needs ALTER UPDATE on BOTH columns and applies neither if one grant is missing (../rollback.sh
30+
-- translates the ACCESS_DENIED).
31+
--
3132
-- Deliberately NOT `ON CLUSTER`, matching the reverse replay beside it. `traces` is a Replicated*MergeTree, so a
3233
-- mutation entered on one replica reaches the others through the replication log; routing it through the distributed-DDL
33-
-- queue instead would add a second, unrelated wait bounded by `distributed_ddl_task_timeout` (180s by default). This
34-
-- mutation rewrites every part, so on a large table that bound is exceeded routinely, and with the default
35-
-- `distributed_ddl_output_mode = 'throw'` the client raises TIMEOUT_EXCEEDED while the mutation is progressing normally.
36-
-- The driver would then report a healthy repair as failed. Single-shard assumption, same as the reverse replay's.
34+
-- queue instead would add a second wait bounded by `distributed_ddl_task_timeout` (180s by default), which this
35+
-- statement exceeds routinely — and with the default `distributed_ddl_output_mode = 'throw'` the client would raise
36+
-- TIMEOUT_EXCEEDED while the mutation progressed normally. Single-shard assumption, same as the reverse replay's.
37+
--
38+
-- KEEP IN STEP WITH 000004_rollback_verify_sentinels.sql: same two predicates, same window on the same two columns, same
39+
-- DateTime64 precisions. A check scoped differently from the repair either clears while sentinels remain, or never
40+
-- clears at all.
3741
ALTER TABLE ${ANALYTICS_DB_DATABASE_NAME}.traces
38-
UPDATE end_time = NULL WHERE end_time = toDateTime64('1970-01-01 00:00:00', 9, 'UTC'),
39-
UPDATE ttft = NULL WHERE isNaN(ttft)
42+
UPDATE end_time = NULL
43+
WHERE end_time = toDateTime64('1970-01-01 00:00:00', 9, 'UTC')
44+
AND ( (created_at >= toDateTime64('${SENTINEL_WINDOW_FROM}', 6, 'UTC')
45+
AND created_at < toDateTime64('${SENTINEL_WINDOW_TO}', 6, 'UTC'))
46+
OR (last_updated_at >= toDateTime64('${SENTINEL_WINDOW_FROM}', 6, 'UTC')
47+
AND last_updated_at < toDateTime64('${SENTINEL_WINDOW_TO}', 6, 'UTC'))),
48+
UPDATE ttft = NULL
49+
WHERE isNaN(ttft)
50+
AND ( (created_at >= toDateTime64('${SENTINEL_WINDOW_FROM}', 6, 'UTC')
51+
AND created_at < toDateTime64('${SENTINEL_WINDOW_TO}', 6, 'UTC'))
52+
OR (last_updated_at >= toDateTime64('${SENTINEL_WINDOW_FROM}', 6, 'UTC')
53+
AND last_updated_at < toDateTime64('${SENTINEL_WINDOW_TO}', 6, 'UTC')))
4054
-- mutations_sync = 2: wait for the mutation on every replica, so the repair has converged cluster-wide before the
4155
-- postcondition reads it back (same rationale as lightweight_deletes_sync = 2 in the reverse replay). The wait is
4256
-- unbounded server-side, so the CLIENT socket timeout is what limits it — see rollback.sh --receive-timeout.

apps/opik-backend/data-migrations/traces-local-v2-cutover/scripts/db-app-analytics/000004_rollback_verify_sentinels.sql

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -38,7 +38,13 @@
3838
-- silent false negative on the one gate that decides whether damaged rows get fixed, so it must not depend on host
3939
-- configuration.
4040
--
41-
-- KEEP IN STEP WITH 000004_rollback_sentinel_repair.sql: same two predicates, same DateTime64 precision 9, same 'UTC'.
41+
-- WINDOW-SCOPED, matching the repair exactly. Unbounded, these counts would include epoch/NaN values the flag never
42+
-- produced — client-sent ones, and rows predating it — so the gate could never reach 0 on an estate that holds any, and
43+
-- a repair that correctly left them alone would read as a failure. Scoping both to the same window is what makes 0 mean
44+
-- "the flag's damage is gone" rather than "no such value exists anywhere".
45+
--
46+
-- KEEP IN STEP WITH 000004_rollback_sentinel_repair.sql: same two predicates, same window on the same two columns, same
47+
-- DateTime64 precisions.
4248

4349
SELECT
4450
uniqExactIf((workspace_id, project_id, id), end_time = toDateTime64('1970-01-01 00:00:00', 9, 'UTC')) AS sentinel_end_time,
@@ -47,4 +53,8 @@ SELECT
4753
duration < 0 AND end_time = toDateTime64('1970-01-01 00:00:00', 9, 'UTC')) AS negative_from_sentinel,
4854
uniqExactIf((workspace_id, project_id, id), duration < 0 AND end_time IS NULL) AS stale_duration
4955
FROM clusterAllReplicas('{cluster}', ${ANALYTICS_DB_DATABASE_NAME}.traces)
56+
WHERE ( (created_at >= toDateTime64('${SENTINEL_WINDOW_FROM}', 6, 'UTC')
57+
AND created_at < toDateTime64('${SENTINEL_WINDOW_TO}', 6, 'UTC'))
58+
OR (last_updated_at >= toDateTime64('${SENTINEL_WINDOW_FROM}', 6, 'UTC')
59+
AND last_updated_at < toDateTime64('${SENTINEL_WINDOW_TO}', 6, 'UTC')))
5060
SETTINGS log_comment = 'traces_local_v2_rollback:verify_sentinels';

0 commit comments

Comments
 (0)