docs: post-mortem for v1.15.0 — the spine named in August recurred five times in eight days (C-343)

reports/post_mortems/2026-10-20_release_v1150.md

@@ -0,0 +1,365 @@
+# Post-Deployment Post-Mortem: v1.15.0
+
+**Date:** 2026-10-20
+**Author:** Simon Polichinel von der Maase, Claude Code
+**Scope:** Export phase instrumentation (#501/#502); four rounds of C-343 deploy-procedure correction (#497–#500); release, publish and deploy of v1.15.0; a fifth C-343 round found while writing this window up (#507); a licensing contradiction found while onboarding an external consumer (#508)
+**Branch:** development → main
+**Release:** v1.15.0 (2026-10-20), deployed to `views-datafactory-00` the same night
+**Commits:** 8 in `v1.14.0..main` · **PRs:** #500, #502, #503, #504, #506, #507
+**Issues opened:** #501 (open), #505 (auto-opened, auto-closed), #508 (open)
+**Previous post-mortem:** [v1.9.0 → v1.11.0](2026-08-03_releases_v190_to_v1110.md)
+
+---
+
+## The thing to read if you read nothing else
+
+The previous post-mortem opened by observing that **nine releases had shipped without one being
+written**, and that the convention had recorded itself failing before failing nine more times. It
+then named the spine running through everything it reported:
+
+> "a written record that was true when written and stopped being true without anything failing."
+
+Both halves recurred.
+
+**Four more releases have shipped since — v1.12.0, v1.13.0, v1.14.0, v1.15.0 — and this is the
+first post-mortem for any of them.** Three of the four will now never be written up. The
+convention has recorded its own failure in the v1.6.0 post-mortem, again in the v1.11.0 one, and
+here for the third time.
+
+And the spine produced **five fresh instances in eight days**, all in one concern, C-343. The fifth
+was found inside the register entry created to track the first, including in its `Trigger:` field —
+the line an operator is supposed to act on. A sixth variant was committed by the same author three
+days after writing the fourth correction.
+
+The useful conclusion is not "try harder". It is that **this failure mode is not detected by
+anything we run.** Every instance in this window was found by a human asking an unprompted
+question, or by an author re-reading their own work. Five rounds of correction have produced a
+procedure that is now right; they have produced nothing that notices when a copy of it goes wrong.
+
+---
+
+## What we did
+
+One release, built from two unrelated threads that met at the deploy gate.
+
+The first thread was a measurement. A production run on 2026-10-16 took **5h50m**, and the operator
+pasted the log. Reading it closely showed the zarr export alone accounted for **5h07m — 88% of the
+pipeline** — against ADR-041's recorded figure of ~57 minutes. A **5× regression, four months old,
+that nothing had reported.**
+
+The second thread was C-343, "writing the deploy tag is not deploying", which had already been
+corrected four times and was corrected a fifth time in this window.
+
+They met because the instrument built for the first could only reach production through the
+procedure governed by the second: the server runs a **git tag** (ADR-022), so a script merged to
+`development` is nowhere the server can see. That collision is the most instructive thing in this
+document and is treated as its own incident below.
+
+---
+
+## What shipped
+
+### v1.15.0 — a release whose wheel contains no new code
+
+```
+$ git diff --name-only v1.14.0 origin/development -- src/
+(empty)
+```
+
+The wheel packages only the nine `src/datafactory_*` trees, so the published artifact is
+code-identical to v1.14.0 apart from version metadata. A consumer installing from PyPI gets nothing
+new.
+
+That was the point, not a defect. The release exists to carry `scripts/export_zarr.py` and a set of
+corrected guides to a server that deploys by tag. **There is no path by which a PyPI publish
+deploys a script the wheel does not contain.** House precedent exists twice over: v1.11.0 and
+v1.12.0 were both minor bumps with zero `src/` change, and v1.11.0's own commit subject says so —
+*"a release whose only shipped change is a dependency floor."*
+
+### The instrument (#502)
+
+Four phases timed in the zarr export — `scan` (the `source_sums` loop, one strided traversal of
+`grid.npy` per feature), `write` (`to_zarr` plus metadata consolidation), `verify` (the
+ADR-011/C-144 round-trip integrity read) and `swap` (the `.tmp` rename) — plus an explicit `other`,
+so the printed columns account for the whole of the existing `Time:` line rather than a selected
+part of it.
+
+The breakdown prints to `logs/refresh.log` **and** persists as `phase_seconds` in
+`data/assembled/export_ledger.jsonl`. The ledger half is the one that matters: logs rotate, and one
+measurement in a rotating log is not a trend. A 5× regression surviving four months is what the
+absence of that record looks like.
+
+`swap` is a fourth phase beyond the three the issue asked for, added because measuring it costs
+nothing and lets it be ruled out rather than assumed cheap.
+
+### The documentation rounds (#497–#500, #507)
+
+See the spine below. #500 is worth isolating: **seven places claimed a pipeline duration, spanning
+24×** (15–30 min to ~6 h), and two of the wrong figures had been written two days earlier, by us, as
+the new single authority — with no measurement anywhere in the repo to support them.
+
+---
+
+## The spine: one failure mode, five instances in eight days
+
+| Round | Found | What a live copy said |
+|---|---|---|
+| #497 (10-12) | four more copies of the one-step claim | writing the tag file is deploying |
+| #498 (10-16) | `~` after `sudo` expands as the **caller** | six verification commands read the operator's home, not `views-deploy`'s |
+| #499 (10-16) | the procedure had no single home; the tmux rule was missing | — |
+| #500 (10-18) | seven duration figures spanning 24× | the new authority's own figure had never been measured |
+| #507 (10-20) | four copies of the step **count** | "three steps" after the fourth block was added |
+
+### Each round fixed the previous round's blind spot
+
+- #497 consolidated copies. #499 then found that **a consolidation is only safe if the new
+  authority absorbs everything the demoted copies knew.**
+- #499 established a single authority. #500 then found that **a consolidation concentrates error as
+  effectively as it concentrates authority** — the new authority carried a figure nobody had
+  measured. *A consolidation must verify what it promotes, not only absorb what it demotes.*
+- #500 audited the guides for duration figures. #507 then found that it had audited **content** and
+  not **cardinality** — nothing suggested a count could rot.
+
+### Round five is the one to keep
+
+Four live copies still said "three steps". Two were **inside C-343 itself** — its `Open Items
+Summary` row and its `Trigger:` field. The summary row said "three steps" and then listed the three
+checks that constitute step **4**, describing four things while naming three.
+
+The sharpest was `scripts/refresh_pipeline.sh`. Its comment warns, in its own words:
+
+> "two copies of a procedure drifting apart is what C-343 IS, and a fix that adds a third copy would
+> be the same bug"
+
+It had carefully avoided duplicating the commands — and then duplicated the number, which was the
+one part that changed. **A count is a copy too.** The comment now records that it said THREE until
+2026-10-20, five weeks after the fourth block was added.
+
+Four rounds of hunting stale copies of this procedure, and the stalest surviving copies were inside
+the entry doing the hunting.
+
+---
+
+## Incident: "the next run will pick it up automatically"
+
+**What happened.** #502 merged to `development`. The author reported to the operator that the
+measurement would arrive on the next monthly cron **automatically**, requiring no further action.
+
+**Why it was wrong.** The server does not run `development`. Per ADR-022 `refresh_pipeline.sh` reads
+`~/.views-deploy-tag` and checks out that exact tag. The deployed tag was `v1.14.0`:
+
+```
+$ git show v1.14.0:scripts/export_zarr.py | grep -c phase_seconds
+0
+```
+
+The run on the 21st would have executed the uninstrumented export and printed nothing.
+
+**What it cost.** Nothing, because it was caught the same session. Uncaught, it would have cost five
+weeks: the instrument built, merged, idle, and the issue sitting open waiting for a number that
+could not arrive.
+
+**Why it belongs in a post-mortem rather than a correction.** It is C-343 displaced one layer up.
+*Writing the tag is not deploying* became *merging the instrumentation is not deploying the
+instrumentation* — the same confusion between "the change exists" and "the change is what runs",
+moved from the tag file to the branch. It was committed **three days after the same author wrote
+C-343's fourth round of correction.**
+
+The same slip recurred twice more in the same session as chat-only paraphrase ("three steps" for
+the four blocks), each time from recalling the procedure instead of opening it. Not registrable —
+chat is not a repo artifact — but the frequency is the evidence: **five instances across three
+months, every one from reasoning about the procedure rather than reading it.**
+
+**What would have caught it.** Nothing we run. #424's proposed pre-flight gate compares
+`$DEPLOY_TAG` against the HEAD the script started from; it would not have caught this, because the
+code never reached a tag at all. There is no check at any layer comparing what the server is
+running against what the repository expects.
+
+---
+
+## What we found: the good
+
+### 1. The corrected procedure completed, step 4 included, for the first time
+
+v1.15.0 deployed with all four blocks and all three verification commands agreeing:
+
+```
+cat ~/.views-deploy-tag                                → v1.15.0
+git describe --tags --exact-match                      → v1.15.0
+ls .venv/lib/python*/site-packages | grep views_data…  → views_datafactory-1.15.0.dist-info
+```
+
+`uv sync` printed `- views-datafactory==1.14.0` / `+ views-datafactory==1.15.0`, making block 3
+load-bearing on two measurements rather than one.
+
+**The new fact is not that it worked — it is that block 4 ran at all.** On 2026-10-16 its first
+command died on the `~`-expansion defect, so the verification block added on 2026-10-13 had never
+once executed successfully. #498's fix is now confirmed by execution rather than by reading.
+
+### 2. A falsification criterion committed before the measurement existed
+
+#501's strided-memmap hypothesis is the author's own. The criterion was posted to the issue
+**before any production figure existed**:
+
+> if `scan` comes in under ~25% of the export, the strided-memmap explanation is refuted and I stop
+> advancing it
+
+with the synthetic baseline (`scan` 10.1% — the *smallest* named phase when 0.1 GB fits in RAM) as
+the stated contrast. Without that, any breakdown could have been read as agreement after the fact.
+
+### 3. Guards drilled rather than assumed
+
+| Sabotage | Result |
+|---|---|
+| delete `phase_seconds["swap"] = ...` | `test_phase_timings_recorded` **FAILED** |
+| inflate the `scan` timer past the total | `test_phases_do_not_exceed_the_total` **FAILED** — *"phases sum to 9999.8s but total is 1.3s"* |
+| revert the plan title to `v1.14` with version at 1.15.0 | `TestF7ProductPlanCurrency` **FAILED** |
+
+The third was run specifically to establish that the product-plan edit in the bump was load-bearing
+rather than housekeeping tacked on.
+
+### 4. Verification by artifact, not by checkmark
+
+The PyPI publish was verified by installing into a clean venv, per the guide's requirement. The
+first attempt reported `No matching distribution found` — **which reads exactly like a failed
+publish.** It was not: the venv had been built on Python 3.10.14 against `requires-python >=3.11`.
+The broken thing was the check. A less careful reading would have raised a false alarm on a
+successful release.
+
+### 5. Squash merges verified by content
+
+`git branch --contains` and `git cherry` cannot verify a squash — it creates a new commit with a new
+patch-id. Every branch deleted this window was verified by comparing file content against
+`origin/development` first.
+
+### 6. A cross-session answer corrected rather than relayed
+
+A peer session asked about data access for a visiting researcher on the stated premise that the
+store sits behind the PRIO VPN. It does not — `viewser_transition_guide.md:75`: *"You no longer need
+the PRIO VPN or SSH tunnel for data access."* Checking the premise rather than answering the
+question dissolved most of it, and avoided routing a request to PRIO IT that PRIO IT has no part in.
+
+---
+
+## What we found: the gaps
+
+### 1. Nothing compares durations across runs
+
+`scripts/check_health.py` has **26** references to freshness, staleness or age and **zero** to
+duration or elapsed time. Durations are now *recorded* (#502) but nothing *compares* them. A second
+5× regression would still be invisible until a human read a log by hand — which is exactly how the
+first one was found, four months late.
+
+Deliberately not built: one datapoint does not justify a trend watcher, and the instrument that
+would have caught the first regression is what this release ships. **Flagged, not fixed.**
+
+### 2. Nothing compares what the server runs against what the repo expects
+
+#424's pre-flight gate remains unbuilt and would not have caught this window's variant. The gap is
+broader than the gate: at no layer does anything assert that deployed code matches intended code.
+
+### 3. Audit dimensions are chosen ad hoc
+
+#500 audited seven duration *figures* and did not check a step *count*. #507 checked the count. No
+list exists of what dimensions of a procedure can rot, so each round discovers one more by accident.
+This is why five rounds have been needed rather than one.
+
+### 4. `ADR-041` understates its own benefit by ~3.4×
+
+Its Consequences says a no-change deploy drops "from ~103 min to ~30 sec" (46 assembly + 57 export).
+Measured, it avoids **~350 min**. Amended, not rewritten — the Context is a record of what was true
+when written.
+
+### 5. A written commitment the system does not honour (#508)
+
+Found while onboarding an external consumer. `docs/sources/shdi.md:55` states, unqualified: *"we do
+not redistribute GDL data."* The served store contains **four SHDI features**, and
+`shdi_v1.py`'s docstring describes them as a **broadcast** — GDL's published values, re-indexed by
+centroid-in-polygon and repeated across each year's months. Not derived statistics: GDL's actual
+numbers, reorganised.
+
+ACLED is not in the same position and the distinction is documented rather than felt: its eight
+features are counts and a fatality sum per cell-month, so the event records its terms govern most
+tightly never leave. V-Dem is broadcast verbatim exactly like SHDI and is fine, because
+CC-BY-SA-4.0 permits it. The problem is specific to GDL's terms plus our own written denial.
+
+The permission request sent to GDL on **2026-05-29** remains unanswered, with no chase recorded.
+Filed as #508.
+
+**This is the same spine again, in a different domain:** a record that was true when written, that
+stopped being true without anything failing.
+
+### 6. Four releases with no post-mortem
+
+v1.12.0 through v1.14.0 shipped unexamined. This document covers v1.15.0 only; the earlier three are
+not reconstructed here and probably never will be.
+
+---
+
+## Verification performed in this window
+
+| Check | Result |
+|---|---|
+| Full suite, exit code captured (×3 across the window) | **EXIT=0, 0 FAILED, 0 ERROR** each time |
+| All 14 register-reading test files, run not sampled | 41 passed |
+| `ruff check .` / `mypy src/` / `validate_docs.sh` | clean / clean (89 files) / PASSED |
+| `bash -n scripts/refresh_pipeline.sh` | OK |
+| Release gates (`deploy_v160`, `_v160_r2`, `merge_readiness`) | 10 passed, 1 skipped pre-tag |
+| `test_version_equals_the_tag_head_is_on` | **ran and passed** once HEAD was tagged — first time this release |
+| PyPI, clean Python 3.13 venv | `1.15.0`; all nine `datafactory_*` packages import |
+| `notebooks/acled_cursor_parity.ipynb`, re-executed, no network | 3 slices, **106,329 events**, every oracle held, 0 errors |
+| Server, block 4 | three commands, all naming `v1.15.0` |
+
+Exit codes were captured rather than inferred from absent `FAILED` lines — **137 is SIGKILL/OOM and
+prints no failures at all** (C-345).
+
+---
+
+## Release topology
+
+`main` → `development` promotion was merged as a **merge commit** (#504, `b0c0b17`), leaving the
+expected one-commit divergence. `Release hygiene` detected it, auto-opened **#505**, and the
+back-merge (#506, merge commit `e2c5a94`) healed it; #505 closed on a `workflow_dispatch` rather
+than waiting for the 06:00 cron.
+
+Two tests were genuinely red between promotion and back-merge —
+`TestF2ReleaseTopology::test_main_is_ancestor_of_development` and
+`TestDF1MergeTopology::test_main_ancestor_of_development` — and both carry their own remedy in the
+assertion message, which is why the red was expected rather than investigated. **That is the
+mechanism working.**
+
+Worth noting against C-320's lesson: a permanently-red CI is indistinguishable from a broken build,
+and this red was transient, self-describing and self-closing.
+
+---
+
+## What to do differently
+
+1. **Write the post-mortem.** Three of the last four releases missed it, and the convention has now
+   documented its own failure three times — v1.6.0, v1.11.0, here. If it fails again, the honest
+   move is to delete the convention rather than record a fourth self-indictment.
+2. **Build the duration comparison** (gap 1). It is the only thing that would have caught the
+   regression this release exists to measure, and it is now the only part of #501 that remains
+   structural rather than diagnostic.
+3. **Enumerate what can rot in a procedure** before the next audit — commands, counts, paths, home
+   expansion, durations, step names. Five rounds of C-343 each found one dimension by accident.
+4. **Open the file.** Every instance in this window, including the two chat-only ones, came from
+   recalling a procedure instead of reading it. The procedure has one home and it is cheap to open.
+5. **Close #508** or record the decision. A public repository asserting a commitment the system does
+   not honour is a worse position than an unresolved question.
+6. **Do not optimise the export before the production number exists.** No change was made to
+   chunking, compression, the slicing pattern or the integrity check. Each is a plausible remedy for
+   a cause that is not yet established, and the integrity check is an ADR-011/C-144 guarantee that
+   must not be weakened to buy time.
+
+---
+
+## Open after this release
+
+| Item | State |
+|---|---|
+| **#501** | instrument deployed; the first production breakdown arrives on the 21 October cron. The pre-registered criterion decides whether the strided-memmap explanation survives or is retracted. |
+| **#508** | SHDI contradiction — amend, chase Smits, decide the position |
+| **#488** | a short ACLED harvest is still recorded as `success`; `n_events` is written and never read |
+| **#424** | the pre-flight gate; still unbuilt, and now known to be insufficient on its own |
+| C-343 | **open.** Five rounds of documentation correction have produced a procedure that executes correctly when followed, and nothing that notices when it is not. |