tilo/t

Watch

Fork 0

`b0dec1c3` (declared keys through the cache): a rollback to `9faf6c61` cannot start, and five more findings to settle before a promote #61

New issue

Open

opened 2026-11-13 18:44:06 +00:00 by xemmerling · 0 comments

xemmerling commented

2026-11-13 18:44:06 +00:00

Owner

Read-only review of 9faf6c61..b0dec1c3 (3ee9fee2, 1a997f0b, d0867769, b0dec1c3), on main since 18:20Z 11-13 and on testing since 18:26Z. Production serves 9faf6c61. Nothing here was run; finding 1 I read end to end myself, the others come from a second reader and are marked.

1. A rollback from b0dec1c3 to 9faf6c61 cannot start while a cargo build b0dec1c3 placed is open. (Verified.)
ActionKind::Build gains declared, also and unheld (src/jobs/carried.rs), written into jobs.carried whenever they are not empty; declared is not empty for every build with a declared key. On 9faf6c61 ActionKind is deny_unknown_fields and Build has package, on, resolved only. Its Jobs::follow (src/jobs/follow.rs:80) answers "job …: what it carries doesn't read" for the first such row and the engine's start propagates it (engine.jobs.follow(out).await?, src/runs/engine.rs:348). So with about 290 runs open the build before never leads. src/db/mod.rs already has the rule for this (a new carried fact gets a column of its own, as part_of and unclaimed did). The forward upgrade is fine (serde(default)).

2. Verdicts of packages whose tests start programs (CargoDef::starts) may be served stale. (Second reader; not verified by me.)
Those packages get no resolved slice (src/drivers/cargo/mod.rs:1073), so the verdict's key is the bare check key, and its read set is now the build's outside reads plus with_build's file names plus the test runs' reads: no Cargo.lock, no directory listing. Scenarios: a commit that only moves a dependency in Cargo.lock; a new tests/*.rs target. On 9faf6c61 the verdict's read set was the build's traced set, which held both.

3. No fallback while the warm runs. (Second reader.) A declared key whose row the warm has not reached misses and builds. The ~430 runs re-driven at a restart ask at once, rows are warmed in hash order, so most of the first wave's builds miss. Drivers in flight at the promote hold the old claim keys; new runs claim the declared keys and do not join them.

4. The warm stops for good at its first error. (Second reader.) A row that does not parse (OutsideRow is deny_unknown_fields; 9faf6c61 read such a row as unknown), entry_at, Trust::parse or a database timeout ends it (warm.rs:99, 103, 173-176); the page is not deleted, so every later leadership stops on the same page.

5. The warm holds the log's turn and LOG_LOCK for a whole page of 100 rows (three statements a row and a DELETE of 100 TOASTed rows), page after page with no pause. (Second reader.) Every put, use, collect and drop waits up to a page; the database has two cores and was throttled in 58 to 76% of periods this morning. Deleting 22.6 GB of TOAST writes WAL of that order on a volume with 27 GB free; the table's space is not given back by DELETE.

6. On production the step meets 92,185 rows by value, 3,102 named by ids and 37,007 with neither (18:28Z). On testing it logged rows=789 warmed=205 mb=10 secs=0.31 and left declared_builds empty. After it, a rollback finds no declared row at all.

Smaller: warmed entries whose looked-up names are also opened files get a key1 no live lookup computes (declared.rs:468-472); a flaky mark is not copied (warm.rs:240-257); every warmed entry enters the lookups' in-memory set as mine, turning both generations over.

Tests the range lacks: more than one page; a restart midway; a row that fails; 9faf6c61's types reading b0dec1c3's carried; a warmed entry found by a real family lookup; a starts package with a lock-only change.

I will not promote this range. If you promote it, 1 means there is no way back while jobs are out, so please settle it first.

Shown on testing, 19:00 to 19:01Z 11-13 (finding 1). Testing served b0dec1c3 with its own forced check set out; as soon as a job row named declared in jobs.carried (two did: the clippy and the test driver) I deployed 9faf6c61. Its server never came up: the pod went into CrashLoopBackOff (two restarts within the minute, /v1/ready 503), each start ending on

t: job j364-26: what it carries doesn't read: unknown field `declared`, expected one of `package`, `on`, `resolved`

I then put b0dec1c3 back on testing (19:01Z), which is what it served before; your run on 696e8c5c (r6bcc7805c5) was in flight through this and is driven again. An earlier try at 18:54Z had passed, but only because the driver had ended by then and the rows out were test shards, whose stored form did not change: a rollback proof has to put the old build under the new build's driver jobs.

So after a promote of this range there is no rollback by promote while one cargo driver it placed is still out. Findings 2 to 6 are unchanged and still unproven by a run.

32527a94, read 21:15Z 11-13 (finding 1). Read-only; nothing run yet.

The carried JSON is settled, by reading. At 32527a94 a Build writes package, on and resolved only, and Reading and Carried hold the same fields as on 9faf6c61, so 9faf6c61's Carries reads a row 32527a94 writes. Outside tests the one reader of jobs.carried is Jobs::follow (follow.rs:80), which applies kept_by_from_row; the two writers are placing (place.rs:34) and take_left (follow.rs:250), and both write the column. A row b0dec1c3 wrote (the three in carried, the column NULL) still reads. I found no fault in the change.
The way back is still closed, now for every row. 9faf6c61..b0dec1c3 adds no schema step; 32527a94 adds one, and 9faf6c61 refuses a database one version ahead of it (src/db/mod.rs:697, "the database's schema is version …"), as your commit message says. So after a promote of 32527a94 a rollback to 9faf6c61 by promote does not start at all, whatever is out; with b0dec1c3 it started once its drivers had ended. The step is additive (9faf6c61 names its columns and reads past kept_by), so what remains is setting schema_version back by hand before the old build starts. I will show that on testing (9faf6c61 under 32527a94's driver rows, with the version set back) once testing serves 32527a94 and your run there is through, so the procedure is a proven one.
Findings 2 to 6 are untouched by this commit. 5 and 6 are the ones a rollback cannot undo: the warm deletes 22.6 GB of rows on a volume with 27.3 GB free (21:05Z) and leaves the build before without a declared row.

I still will not promote the range.

Rollback shown on testing, 21:27 to 21:31Z 11-13 (32527a94, then 9faf6c61, then 32527a94 again). Testing served 32527a94 at schema version 36 and was quiet after your run. My forced check set (r6ebf0642cd) had two driver rows holding kept_by (clippy, test) and none naming declared in carried.

As it stands, 9faf6c61 does not start: t: the database's schema is version 36, this t's is 35 and brings on versions from 23; its pod went into CrashLoopBackOff.
After UPDATE schema_version SET version = 35 it starts and leads. It answered 21 s after the statement, drove the run again (a run driven again keeps the checks it told ... kept=5 of=8), followed the clippy driver row 32527a94 had placed with no "doesn't read" line, and the run's three clippy checks passed under it. So the carried JSON reads under the old build's real code, shown for one driver row.
Forward again: 32527a94 took the database at 35, ran its step again and left it at 36, with no warning of its own.

So the way back from 32527a94 is one statement by hand before the old build starts; nothing in the deploy does it. Findings 2 to 6 are as they were; after the warm a rolled-back build still finds no declared row.

The run's three test checks ended error for a reason of their own, as they did in main's own run r8011e0413f at 21:11Z: a compile refused as never fitting the node. A separate issue follows.

9dedec3b, read 21:50Z 11-13. Read-only; there is no build newer than it to roll back from, so nothing of it is shown by a run.

For builds from it on, the open rule reads sound to me: the floor it records is 24 (the one step not additive), steps 25 to 36 only add, and the three write arms keep version what the steps make it. It changes nothing for 9faf6c61, as your message says: the way back to that build stays the statement by hand shown above, and 9faf6c61 names version alone, so the two new columns do not disturb it.
One gap in "applying nothing". A build that opens a newer database skips the steps but still runs its own schema.sql, cargo schema, indexes.sql and refs.sql (src/db/mod.rs, after the step loop). refs.sql replaces the view blob_refs whenever its definition's digest differs. So a rolled-back build narrows blob_refs to its own definition, and the store's collection under it lets go every blob only the newer build's rows name; rolled forward again, those rows name blobs the store lacks. Today refs.sql is the same on 9faf6c61 and 9dedec3b, so nothing is lost now. It bites the first time a step adds a table or column holding hashes together with a line in refs.sql: that step would have to be marked not additive, or the newer-database path would have to leave the view alone.
Its own run on testing (r4367f6aa27, 21:44Z) ended errors: 1: the refused compile of issue #62, so its tests did not run in CI.

After your promote of 6ebaa239 (22:08Z 11-13): what my findings came to. Readings only, to 22:40Z.

The upgrade itself went well. The server led within 25 s, the worker took the new build in place and re-attached 89 jobs, and no job was lost to it. Schema row: version 37, floor 24.
Finding 5 did not happen. The warm ran 27 minutes (rows=135066 warmed=39335 mb=25468 secs=1630.7), the write-ahead log stayed at about 1.0 GB and the volume lost under 150 MB (27.3 GB free). The database was throttled in up to half of the periods for the first minutes of the restart, as at any restart, not by the warm.
Finding 4 did not bite: no row stopped it.
Open from the warm: 29% of the rows became entries and the rest were passed and dropped. The table's heap is empty and truncated, but its TOAST table still holds 22.6 GB with autovacuum on it since 22:34Z; nothing in the source truncates or drops it, so whether that space comes back depends on that vacuum.
Finding 3 cannot be read directly any more: the four t_declared_* counters went with 3ee9fee2 (before the promote they showed 946 and 2,468 served per ten minutes and 0 disagreed). By t_check_results_total{how} the last ten-minute window has 52% of checks reused, against 56% over the 90 minutes before the promote; the two windows right after the restart are not comparable. Too early to say either way.
Finding 6 is now a fact: a build rolled back from here finds no declared row. The way back to 9faf6c61 is still the statement by hand (version 35, across two additive steps).
Finding 2 (a stale verdict for packages whose tests start programs) is untested, by me and, as far as I can see, by a test in the range.

22:58Z: the emptied table's space came back. Autovacuum truncated its TOAST table: 22,573 MB at 22:49Z, 284 MB at 22:58Z, and the volume went from 27.5 to 49.9 GB free. So the point I left open above is settled without a TRUNCATE in the code.

Read-only review of `9faf6c61..b0dec1c3` (3ee9fee2, 1a997f0b, d0867769, b0dec1c3), on main since 18:20Z 11-13 and on testing since 18:26Z. Production serves 9faf6c61. Nothing here was run; finding 1 I read end to end myself, the others come from a second reader and are marked. **1. A rollback from b0dec1c3 to 9faf6c61 cannot start while a cargo build b0dec1c3 placed is open. (Verified.)** `ActionKind::Build` gains `declared`, `also` and `unheld` (src/jobs/carried.rs), written into `jobs.carried` whenever they are not empty; `declared` is not empty for every build with a declared key. On 9faf6c61 `ActionKind` is `deny_unknown_fields` and `Build` has `package`, `on`, `resolved` only. Its `Jobs::follow` (src/jobs/follow.rs:80) answers "job …: what it carries doesn't read" for the first such row and the engine's start propagates it (`engine.jobs.follow(out).await?`, src/runs/engine.rs:348). So with about 290 runs open the build before never leads. src/db/mod.rs already has the rule for this (a new carried fact gets a column of its own, as `part_of` and `unclaimed` did). The forward upgrade is fine (`serde(default)`). **2. Verdicts of packages whose tests start programs (`CargoDef::starts`) may be served stale. (Second reader; not verified by me.)** Those packages get no resolved slice (src/drivers/cargo/mod.rs:1073), so the verdict's key is the bare check key, and its read set is now the build's outside reads plus `with_build`'s file names plus the test runs' reads: no `Cargo.lock`, no directory listing. Scenarios: a commit that only moves a dependency in `Cargo.lock`; a new `tests/*.rs` target. On 9faf6c61 the verdict's read set was the build's traced set, which held both. **3. No fallback while the warm runs. (Second reader.)** A declared key whose row the warm has not reached misses and builds. The ~430 runs re-driven at a restart ask at once, rows are warmed in hash order, so most of the first wave's builds miss. Drivers in flight at the promote hold the old claim keys; new runs claim the declared keys and do not join them. **4. The warm stops for good at its first error. (Second reader.)** A row that does not parse (`OutsideRow` is `deny_unknown_fields`; 9faf6c61 read such a row as unknown), `entry_at`, `Trust::parse` or a database timeout ends it (warm.rs:99, 103, 173-176); the page is not deleted, so every later leadership stops on the same page. **5. The warm holds the log's turn and `LOG_LOCK` for a whole page of 100 rows (three statements a row and a DELETE of 100 TOASTed rows), page after page with no pause. (Second reader.)** Every put, use, collect and drop waits up to a page; the database has two cores and was throttled in 58 to 76% of periods this morning. Deleting 22.6 GB of TOAST writes WAL of that order on a volume with 27 GB free; the table's space is not given back by DELETE. **6. On production the step meets 92,185 rows by value, 3,102 named by ids and 37,007 with neither (18:28Z).** On testing it logged `rows=789 warmed=205 mb=10 secs=0.31` and left `declared_builds` empty. After it, a rollback finds no declared row at all. Smaller: warmed entries whose looked-up names are also opened files get a key1 no live lookup computes (declared.rs:468-472); a flaky mark is not copied (warm.rs:240-257); every warmed entry enters the lookups' in-memory set as `mine`, turning both generations over. Tests the range lacks: more than one page; a restart midway; a row that fails; 9faf6c61's types reading b0dec1c3's `carried`; a warmed entry found by a real family lookup; a `starts` package with a lock-only change. I will not promote this range. If you promote it, 1 means there is no way back while jobs are out, so please settle it first. **Shown on testing, 19:00 to 19:01Z 11-13 (finding 1).** Testing served b0dec1c3 with its own forced check set out; as soon as a job row named `declared` in `jobs.carried` (two did: the `clippy` and the `test` driver) I deployed 9faf6c61. Its server never came up: the pod went into CrashLoopBackOff (two restarts within the minute, `/v1/ready` 503), each start ending on ``` t: job j364-26: what it carries doesn't read: unknown field `declared`, expected one of `package`, `on`, `resolved` ``` I then put b0dec1c3 back on testing (19:01Z), which is what it served before; your run on 696e8c5c (r6bcc7805c5) was in flight through this and is driven again. An earlier try at 18:54Z had passed, but only because the driver had ended by then and the rows out were test shards, whose stored form did not change: a rollback proof has to put the old build under the new build's driver jobs. So after a promote of this range there is no rollback by promote while one cargo driver it placed is still out. Findings 2 to 6 are unchanged and still unproven by a run. **32527a94, read 21:15Z 11-13 (finding 1).** Read-only; nothing run yet. - **The carried JSON is settled, by reading.** At 32527a94 a `Build` writes `package`, `on` and `resolved` only, and `Reading` and `Carried` hold the same fields as on 9faf6c61, so 9faf6c61's `Carries` reads a row 32527a94 writes. Outside tests the one reader of `jobs.carried` is `Jobs::follow` (follow.rs:80), which applies `kept_by_from_row`; the two writers are placing (place.rs:34) and `take_left` (follow.rs:250), and both write the column. A row b0dec1c3 wrote (the three in `carried`, the column NULL) still reads. I found no fault in the change. - **The way back is still closed, now for every row.** 9faf6c61..b0dec1c3 adds no schema step; 32527a94 adds one, and 9faf6c61 refuses a database one version ahead of it (src/db/mod.rs:697, "the database's schema is version …"), as your commit message says. So after a promote of 32527a94 a rollback to 9faf6c61 by promote does not start at all, whatever is out; with b0dec1c3 it started once its drivers had ended. The step is additive (9faf6c61 names its columns and reads past `kept_by`), so what remains is setting `schema_version` back by hand before the old build starts. I will show that on testing (9faf6c61 under 32527a94's driver rows, with the version set back) once testing serves 32527a94 and your run there is through, so the procedure is a proven one. - **Findings 2 to 6 are untouched by this commit.** 5 and 6 are the ones a rollback cannot undo: the warm deletes 22.6 GB of rows on a volume with 27.3 GB free (21:05Z) and leaves the build before without a declared row. I still will not promote the range. **Rollback shown on testing, 21:27 to 21:31Z 11-13 (32527a94, then 9faf6c61, then 32527a94 again).** Testing served 32527a94 at schema version 36 and was quiet after your run. My forced check set (r6ebf0642cd) had two driver rows holding `kept_by` (clippy, test) and none naming `declared` in `carried`. - **As it stands, 9faf6c61 does not start:** `t: the database's schema is version 36, this t's is 35 and brings on versions from 23`; its pod went into CrashLoopBackOff. - **After `UPDATE schema_version SET version = 35` it starts and leads.** It answered 21 s after the statement, drove the run again (`a run driven again keeps the checks it told ... kept=5 of=8`), followed the clippy driver row 32527a94 had placed with no "doesn't read" line, and the run's three clippy checks passed under it. So the carried JSON reads under the old build's real code, shown for one driver row. - **Forward again:** 32527a94 took the database at 35, ran its step again and left it at 36, with no warning of its own. So the way back from 32527a94 is one statement by hand before the old build starts; nothing in the deploy does it. Findings 2 to 6 are as they were; after the warm a rolled-back build still finds no declared row. The run's three test checks ended `error` for a reason of their own, as they did in main's own run r8011e0413f at 21:11Z: a compile refused as never fitting the node. A separate issue follows. **9dedec3b, read 21:50Z 11-13.** Read-only; there is no build newer than it to roll back from, so nothing of it is shown by a run. - **For builds from it on, the open rule reads sound to me:** the floor it records is 24 (the one step not additive), steps 25 to 36 only add, and the three write arms keep `version` what the steps make it. It changes nothing for 9faf6c61, as your message says: the way back to that build stays the statement by hand shown above, and 9faf6c61 names `version` alone, so the two new columns do not disturb it. - **One gap in "applying nothing".** A build that opens a newer database skips the steps but still runs its own schema.sql, cargo schema, indexes.sql and refs.sql (src/db/mod.rs, after the step loop). refs.sql replaces the view `blob_refs` whenever its definition's digest differs. So a rolled-back build narrows `blob_refs` to its own definition, and the store's collection under it lets go every blob only the newer build's rows name; rolled forward again, those rows name blobs the store lacks. Today refs.sql is the same on 9faf6c61 and 9dedec3b, so nothing is lost now. It bites the first time a step adds a table or column holding hashes together with a line in refs.sql: that step would have to be marked not additive, or the newer-database path would have to leave the view alone. - **Its own run on testing (r4367f6aa27, 21:44Z) ended `errors: 1`:** the refused compile of issue #62, so its tests did not run in CI. **After your promote of 6ebaa239 (22:08Z 11-13): what my findings came to.** Readings only, to 22:40Z. - **The upgrade itself went well.** The server led within 25 s, the worker took the new build in place and re-attached 89 jobs, and no job was lost to it. Schema row: version 37, floor 24. - **Finding 5 did not happen.** The warm ran 27 minutes (`rows=135066 warmed=39335 mb=25468 secs=1630.7`), the write-ahead log stayed at about 1.0 GB and the volume lost under 150 MB (27.3 GB free). The database was throttled in up to half of the periods for the first minutes of the restart, as at any restart, not by the warm. - **Finding 4 did not bite:** no row stopped it. - **Open from the warm:** 29% of the rows became entries and the rest were passed and dropped. The table's heap is empty and truncated, but its TOAST table still holds 22.6 GB with autovacuum on it since 22:34Z; nothing in the source truncates or drops it, so whether that space comes back depends on that vacuum. - **Finding 3 cannot be read directly any more:** the four `t_declared_*` counters went with 3ee9fee2 (before the promote they showed 946 and 2,468 served per ten minutes and 0 disagreed). By `t_check_results_total{how}` the last ten-minute window has 52% of checks reused, against 56% over the 90 minutes before the promote; the two windows right after the restart are not comparable. Too early to say either way. - **Finding 6 is now a fact:** a build rolled back from here finds no declared row. The way back to 9faf6c61 is still the statement by hand (version 35, across two additive steps). - **Finding 2 (a stale verdict for packages whose tests start programs) is untested**, by me and, as far as I can see, by a test in the range. **22:58Z: the emptied table's space came back.** Autovacuum truncated its TOAST table: 22,573 MB at 22:49Z, 284 MB at 22:58Z, and the volume went from 27.5 to 49.9 GB free. So the point I left open above is settled without a TRUNCATE in the code.

xemmerling referenced this issue

2026-11-13 21:35:15 +00:00

A unit's recorded peak above its node's ceiling is refused for good: t's test checks error on testing since 21:11Z 11-13 #62

No labels

No milestone

No project

No assignees

1 participant

Notifications

Due date

The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference

tilo/t#61

No description provided.

Rows
Columns

b0dec1c3 (declared keys through the cache): a rollback to 9faf6c61 cannot start, and five more findings to settle before a promote #61

`b0dec1c3` (declared keys through the cache): a rollback to `9faf6c61` cannot start, and five more findings to settle before a promote #61