From 7661c94105be03c6e96c9e0fd39b1a2bad0ace6b Mon Sep 17 00:00:00 2001 From: retoor Date: Mon, 14 Sep 2026 21:02:58 +0000 Subject: [PATCH] Add POSTMORTEM.md: every real issue found, how, fix, and regression prevention A detailed, permanent record covering the whole arc of this project's development so far -- requested explicitly, as detailed as possible, to prevent regression for ever. Seven sections: 1. Performance findings: the file-index O(n^2) treap rewrite, pack_write's O(n^2) dedup + latent hash-collision correctness bug, and the mount table's O(n^2) (confirmed, deliberately not fixed, with the reasoning). 2. Environment/tooling limitations: TSan's categorical block (every workaround actually tried and ruled out, not just the ones that worked), and both variants of the ASan/UBSan sandbox-startup flake. 3. Project professionalization: version API, SPDX, pkg-config, SECURITY.md, CHANGELOG.md, the Gitea-not-GitHub migration, and the CODE_OF_CONDUCT decision. 4. Git identity correction: the filter-branch rewrite, the tag-object tagger field it missed (found only by a full object-database sweep, not by re-reading git log), and the exhaustive re-verification. 5. Data-integrity fault injection: test_crash_consistency.c, the real bug in its own oracle (128 false failures before a progress side-channel fixed it), and the two real overlay.c bugs found while building the write-failure test (silent journal failure, torn-record poisoning of later records). 6. CI as a second, independent reviewer: the memory leak detect_leaks=0 had been masking locally, and the set -e scripting bug -- including the mistake made while fixing it (reintroducing the same bug in a new shape), the follow-on bash-variable-blowup bug, the newly-discovered TSan segfault variant, and the retry-budget gap, each confirmed by direct reproduction under bash -eo pipefail, not reasoned about. 7. Distilled lessons: ten patterns extracted from the above, written to be applied to a new problem, not just recognized in this one. Every figure cited was checked against BENCH.md/CLAUDE.md's own numbers before writing this, not reproduced from memory. Cross-referenced from CLAUDE.md's "Repository status", README.md's "Contributing" section, and CHANGELOG.md -- including two entries CHANGELOG itself was missing (the set -e CI fix from the previous commit, and this document), the exact class of gap POSTMORTEM.md section 3 already describes happening once before with the v0.1.0 tag. Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01UqJpkdJ6Njnt1pw3CbghzB --- CHANGELOG.md | 31 +++ CLAUDE.md | 2 +- POSTMORTEM.md | 709 ++++++++++++++++++++++++++++++++++++++++++++++++++ README.md | 6 +- 4 files changed, 746 insertions(+), 2 deletions(-) create mode 100644 POSTMORTEM.md diff --git a/CHANGELOG.md b/CHANGELOG.md index f24fb79..0df0b2a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -67,6 +67,37 @@ pushed to any remote — there is no public release yet, only a local one. fluke), not just this project's own — same root cause (`personality(ADDR_NO_RANDOMIZE)` blocked by seccomp) confirmed both generically and against this project's actual test suite. +- **`POSTMORTEM.md`**: a detailed, permanent record of every real bug and + environment issue found across this project's development, how each was + actually diagnosed (including false starts), the final fix, and the + regression-prevention artifact for each — written so a future session + doesn't have to re-diagnose something already answered there. + +### Fixed (CI) +- **`.gitea/workflows/ci.yml`'s ThreadSanitizer step was failing CI for an + environment reason, but the actual bug was in the CI script, not the + code under test.** Gitea Actions' `run:` steps execute under `set -e`; + an unwrapped `OUT=$("./binary" 2>&1)` aborts the whole script on the + first nonzero exit *before* the step's own classification logic (which + exists specifically to not fail the build over the already-documented + TSan-can't-start-here limitation) ever runs. Fixed by wrapping every + such invocation in `if cmd; then RC=0; else RC=$?; fi`. Fixing this + surfaced two more real issues, both also fixed: capturing unbounded + flake output into a bash variable (rather than a file with a bounded + read-back) caused a genuine misclassification at scale, and a second, + previously undocumented segfault variant of the same TSan-can't-start + flake (confirmed via hitting multiple unrelated binaries at random, not + a per-binary bug). The ASan/UBSan step's retry budget was also raised + from 3 to 5 after a real 3-in-a-row flake exhaustion was observed during + this same verification work. See `POSTMORTEM.md` §6.2 for the full + diagnosis, including the exact reproduction technique used to confirm + each fix (not just reasoned about). +- A `-Wunused-result` warning on `tests/test_crash_consistency.c`'s + intentionally-ignored `write()` return value built clean locally (a + `(void)` cast) but still warned on the Gitea runner's own gcc — a real + toolchain configuration difference, confirmed by reproducing clean + locally with identical flags first. Fixed with an actual conditional + branch on the return value instead, which is portably honored. ## [0.1.0] - 2026-09-14 diff --git a/CLAUDE.md b/CLAUDE.md index 329c539..47935b3 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -4,7 +4,7 @@ This file provides guidance to Claude Code (claude.ai/code) when working with co ## Repository status -This repository contains a working v0 implementation of the `concept.md` specification: `include/packfs.h` (public API), `src/*.c` (implementation), `tests/test_*.c` (test suite), and open-source project scaffolding (`README.md`, `LICENSE`, `CONTRIBUTING.md`, `CHANGELOG.md`, `SECURITY.md`, `packfs.pc.in`, `.gitea/workflows/ci.yml` — this project is hosted on Gitea, not GitHub), alongside the frozen `concept.md` and this file. Every file under `src/` and `include/` carries an `SPDX-License-Identifier: MIT` tag; `include/packfs.h`'s `PACKFS_VERSION_*` macros are the single source of truth for the project's version — `pfs_version()` (runtime) and `packfs.pc` (generated by `make install`) are both derived from them, never maintained separately. +This repository contains a working v0 implementation of the `concept.md` specification: `include/packfs.h` (public API), `src/*.c` (implementation), `tests/test_*.c` (test suite), and open-source project scaffolding (`README.md`, `LICENSE`, `CONTRIBUTING.md`, `CHANGELOG.md`, `SECURITY.md`, `packfs.pc.in`, `.gitea/workflows/ci.yml` — this project is hosted on Gitea, not GitHub), alongside the frozen `concept.md`, this file, and `POSTMORTEM.md` (every real bug and environment issue found during development, how each was actually diagnosed, the final fix, and the regression-prevention artifact for each — read it before re-investigating something that might already be answered there, and add to it rather than letting a future finding go unrecorded). Every file under `src/` and `include/` carries an `SPDX-License-Identifier: MIT` tag; `include/packfs.h`'s `PACKFS_VERSION_*` macros are the single source of truth for the project's version — `pfs_version()` (runtime) and `packfs.pc` (generated by `make install`) are both derived from them, never maintained separately. ## Build, test, and lint commands diff --git a/POSTMORTEM.md b/POSTMORTEM.md new file mode 100644 index 0000000..dc47b61 --- /dev/null +++ b/POSTMORTEM.md @@ -0,0 +1,709 @@ +# PackFS development postmortem + +This document is a permanent record of every real issue found during this +project's development from the initial O(n²) file-index finding through the +`c414a27` CI fix — what happened, how it was actually diagnosed (including +false starts and things that looked like fixes but weren't), the final fix, +how it was verified, and what permanent artifact (a test, a CI change, a +documentation update) now prevents it from recurring silently. It exists +because several of the issues below were found only by *re-checking* a claim +that had already been asserted as true — the purpose of writing this down is +to make that re-checking unnecessary next time: read this first, not the git +log, to find out whether something below already covers the question at +hand. + +Every finding here follows the same shape this project's other documents +already use (`CLAUDE.md`'s "Documentation standard"): a claim is not treated +as verified until it has been reproduced directly, not merely reasoned +about, and a revision extends the record rather than silently overwriting an +earlier, wrong belief. Several entries below are explicitly about a *test* +or a *fix* being wrong on its first attempt — those are kept, not deleted, +because the wrong first attempt and why it was wrong is exactly the +information that prevents the same mistake twice. + +Commit hashes below refer to `master` in this repository +(`retoor.molodetz.nl/retoor/packfs`). + +## Contents + +1. [Performance findings](#1-performance-findings) +2. [Environment and tooling limitations](#2-environment-and-tooling-limitations) +3. [Project professionalization](#3-project-professionalization) +4. [Git identity correction](#4-git-identity-correction) +5. [Data-integrity fault injection](#5-data-integrity-fault-injection) +6. [CI as a second, independent reviewer](#6-ci-as-a-second-independent-reviewer) +7. [Distilled lessons](#7-distilled-lessons) + +--- + +## 1. Performance findings + +### 1.1 File index O(n²) in bulk sequential structural writes (`64283d5`) + +**Symptom.** An early `make bench` run showed `mem`/`dir` bulk sequential +`create`/`unlink`/`mkdir` running 9–22x *slower* than the raw host +filesystem — the opposite of what an in-memory, in-process VFS should show. + +**Diagnosis.** `UpperSnapshot` (`src/upper.c`) was a flat, sorted array; +every structural write copied the entire array before publishing the next +immutable snapshot (Section 5.3's single-writer model). At N=20,000 entries, +each `create` was doing an O(N) copy, making N sequential creates O(N²) +total. `concept.md` Section 5.3 had already named the exact trigger for +reconsidering this design ("a persistent (structurally shared) tree +structure is not required until this assumption is empirically violated") +— this was that violation, measured rather than hypothesized. + +**Fix.** Rewrote the index as a persistent treap (Seidel & Aragon 1996; +Liljenzin arXiv:1301.3388 for the persistent-treap-as-MVCC-snapshot +technique specifically) — a structural write now touches only the O(log n) +nodes on the path to the change, sharing every other node (refcounted) with +the snapshot it was built from. + +**Verification.** `mkdir`-at-N=4,000-vs-`create`-at-N=20,000 (same +mechanism, 5x the N) showed a 7.15x ratio post-fix versus 25–28.4x pre-fix — +O(n) predicts 5.0x, O(n log n) predicts 5.97x, the old O(n²) regime +predicted and measured 25–28.4x. This is the complexity-*class* +confirmation, not just "it got faster" (a constant-factor optimization could +also produce a speedup without changing the class). `mem` create/unlink went +from 9.5–22x slower than raw fs to 15–27x *faster*. + +**Regression prevention.** `tests/test_index_stress.c` (thousands of +randomized, non-sequential creates/deletes/renames, cross-checked against an +independent reference model — not just "the benchmark ran fast without +crashing"). `BENCH.md`'s "Resolution" section carries the full before/after +table and this exact complexity-class methodology, reusable for any future +index change. + +### 1.2 `pack_write` compaction dedup: O(n²) plus a latent correctness bug (`684c6d9`) + +**Symptom.** None initially — this was found by deliberately auditing the +codebase for *other* instances of the O(n²) shape §1.1 had just fixed, not +by a benchmark regression. + +**Diagnosis, first pass (nearly missed).** `bench/bench.c`'s own compaction +benchmark (category 8) never showed a problem, because its test files are +all byte-identical — every entry's linear duplicate-scan matched on the very +first comparison, which is the scan's *best* case, not its worst case. This +was the actual trap: a benchmark whose own test data accidentally happens to +avoid an algorithm's worst case will report a clean result for a genuinely +quadratic function. Re-measuring with unique per-file content instead +(calling `pack_write` directly, bypassing the journal/fsync path so the +measurement isn't confounded by this sandbox's separately-documented slow +`fsync` — see §2.2) surfaced it: 5,000/20,000/80,000 unique entries took +0.0138s/0.1114s/1.7389s, and the 20,000→80,000 (4x N) step showed 15.61x, +matching O(n²)'s 16x prediction. + +**A second, independent bug found in the same code while reading it to fix +the first.** The dedup check compared only `(hash, size)` before declaring +two entries duplicates and sharing their `data_off` — never the actual +bytes. `src/hash.c`'s FNV-1a64 is explicitly documented as non-cryptographic +and not collision-resistant. Two different-content entries whose +`(hash, size)` happened to collide would have been silently merged, +corrupting one of them. Never observed in practice (no test's data happened +to collide), but true of the code as written — the kind of bug that stays +latent until it doesn't. + +**Fix.** Replaced the linear scan with an open-addressing hash table +(`DedupSlot`, load factor 1/2, linear probing) *plus* an actual `memcmp` +against the candidate's stored data before ever reusing a `data_off` — a +hash match is now only ever a candidate, never accepted as proof of +equality. This closes both the complexity issue and the correctness gap +with one change, since the fix required for one directly implies the fix +for the other (the hash table alone, without `memcmp`, would still have +the collision bug; the `memcmp` alone, without a hash table, would still be +O(n²)). + +**Verification.** Post-fix, the same methodology: 80,000 unique entries in +0.044s (39.6x faster), 20,000→80,000 ratio dropped to 3.35x (O(n) predicts +4x — close, and nowhere near 16x). + +**Regression prevention.** `tests/test_pack_overlay.c` gained a white-box +assertion (`#include "internal.h"`) that `/a.txt` and `/dup.txt` (identical +content) share one `data_off` while `/b.txt` (different content) shares +neither's — this catches *both* "dedup stopped happening" and "dedup +over-matched," which a single boolean pass/fail on the benchmark could not +distinguish. `tests/test_pack_write_perf.c` is a standing regression +tripwire: 10,000 unique entries under a generous time bound, run as part of +`make test`, so a future accidental reversion to a linear scan fails loudly +and immediately rather than being rediscovered by a future audit. + +### 1.3 Mount table O(n²) — confirmed, deliberately not fixed (`684c6d9`) + +**Symptom.** None from user-facing behavior; found by extending the same +audit that found §1.2, this time to `src/vfs.c`'s mount table. + +**Diagnosis.** `MountSnapshot` uses the identical full-array-copy-per-write +pattern the file index used to (§1.1) — confirmed via a new `bench/bench.c` +category (500/2,000/8,000 mounts): both 4x-N steps showed 15–20x, matching +O(n²)'s 16x prediction, for `mount`, `resolve`, *and* `unmount` alike +(`resolve` being O(n²) too was itself a finding — longest-prefix-match +dispatch is a linear scan of the mount table per call, O(n) per call, O(n²) +across N calls). + +**Decision: not fixed.** Unlike the file index, mount points are created by +calls written into a program's own source code — bounded by how many lines +of "mount this backend at this path" a person or build script is willing to +write, not by user data or workload size. `concept.md` Section 5.3's own +stated trigger for needing a persistent structure ("not required until this +assumption is empirically violated") has not been violated here the way it +was for the file index, and converting the mount table anyway would add +real, permanent complexity for a case that doesn't occur in practice. + +**Regression prevention.** `BENCH.md`'s "Finding: mount table scaling" +section and `CLAUDE.md`'s "Known performance characteristics" record the +measured numbers and the reasoning, explicitly labeled "NOT FIXED, by +deliberate decision" — so a future reader sees a considered decision, not +an unexamined gap, and doesn't need to re-derive whether this is worth +fixing from scratch. + +--- + +## 2. Environment and tooling limitations + +### 2.1 ThreadSanitizer cannot run in this sandbox — confirmed in two independent environments + +**Symptom.** Every `-fsanitize=thread` build fails identically: +`FATAL: ThreadSanitizer: unexpected memory mapping`. + +**Diagnosis.** TSan needs `personality(ADDR_NO_RANDOMIZE)` to disable ASLR +for itself before it can set up its shadow-memory layout. Confirmed via a +direct raw syscall (Python `ctypes`, `libc.personality(0x0040000)`) that +this returns `-1`/`errno=1` (`EPERM`) — a hard, syscall-level refusal, not a +PackFS-specific symptom (a trivial, unrelated two-thread pthread program +fails identically). + +**Attempts that did *not* fix it, tried and ruled out rather than assumed +unhelpful:** +- `setarch $(uname -m) -R ./binary` — `setarch` just calls the same + `personality()` syscall internally; fails identically + (`Operation not permitted`). +- Compiling `-no-pie -fno-pie` — theorized that a non-PIE binary's fixed + load address might sidestep the need for ASLR-disabling, since ASLR + mostly affects PIE base-address randomization. Tested directly: still + fails identically. (TSan's shadow-memory requirement is about the whole + process's mmap layout — heap, libraries, stack — not just the main + executable's own base address, so this was never going to work; worth + recording precisely *why* it doesn't, so it isn't tried again on the + same mistaken theory.) +- Searching `TSAN_OPTIONS=help=1` for a flag that relaxes the startup + memory-mapping check — none exists. +- Checking for a privilege-escalation path: `/proc/self/status` shows + `CapEff` all-zero (no effective capabilities) under an active seccomp + filter (`Seccomp_filters: 1`) that *also* blocks `unshare --user` + (`Operation not permitted`) — ruling out running TSan inside a nested, + less-restricted namespace. +- Checking whether a genuinely different infrastructure provider has the + same restriction, via a dedicated remote-cloud-sandbox agent (not just + re-testing the same local machine): identical result — + `personality()` returns `EPERM`, a trivial pthread program fails TSan + identically, and all of this project's own test binaries fail with the + same `FATAL: ThreadSanitizer: unexpected memory mapping` signature. + +**Conclusion.** This is a categorical, syscall-level restriction with no +userspace workaround available, confirmed in two independent sandboxed +environments, not a configuration this project has simply failed to find +yet. **As of this writing, TSan has not completed a single run in any +environment this project has actually been built in** — this is stated +plainly in `README.md`, `CONTRIBUTING.md`, and `CLAUDE.md` rather than left +implied by CI showing green (see §2.2's segfault variant, and §6.2, for why +a green TSan CI step specifically is *not* evidence TSan ran). + +**Regression prevention.** `CONTRIBUTING.md`'s sanitizer-testing section and +`CLAUDE.md`'s equivalent paragraph state this explicitly, including the +exact confirming tests, so a future session doesn't have to re-derive "is +this fixable" from scratch — it's already been checked, thoroughly, and the +answer is recorded along with the checking. + +### 2.2 ASan/UBSan sandbox-startup flake, two variants + +**Variant A: clean, bounded.** A sanitizer-built binary occasionally +(non-deterministically) fails to start, printing `AddressSanitizer: +DEADLYSIGNAL` once and exiting nonzero. Confirmed as a sandbox race, not a +PackFS bug, by it hitting *different, unrelated* binaries across repeated +runs (in one session: `test_dir` and `test_mem`; in another: +`test_pack_overlay`; in another: nothing at all), with every affected binary +passing cleanly on a repeat run. + +**Variant B: unbounded.** The same underlying race can instead manifest as +an *unbounded repeating loop* of the same `AddressSanitizer:DEADLYSIGNAL` +line — observed directly consuming CPU/memory for minutes and, in one +extreme case during this project's own CI-script debugging (§6.2), writing +enough output within a 30-second `timeout` window to reproduce as a +264MB+ log. + +**Mitigation, not elimination:** always wrap sanitizer-build test runs in +`timeout` (bounds variant B's wall-clock cost); treat a bare +`DEADLYSIGNAL` exit as inconclusive and re-run; only treat it as a real +finding if the output actually contains `ERROR: AddressSanitizer` or +`runtime error:`. `tests/test_crash_consistency.c` hits this flake +noticeably more often than the rest of the suite (it forks 60+ subprocesses +per run — each fork is an independent chance to hit the same startup race) +— this is expected, not a sign specific to that test, and is called out in +`CONTRIBUTING.md` so a future reader doesn't misdiagnose it as a +regression in that file. + +**Regression prevention.** `CONTRIBUTING.md` documents both variants, the +required `timeout` mitigation, and the exact string check that separates a +real finding from this flake. §6.2 covers a further, serious follow-on +mistake made while automating this exact mitigation in CI — see there for +why "wrap it in timeout" was necessary but not, on its own, sufficient. + +--- + +## 3. Project professionalization + +Prompted by "do literally everything for this project to be taken +seriously." A survey of what a serious C library project needs, each +verified rather than assumed present: + +- **`SPDX-License-Identifier: MIT`** added to every file under `src/` and + `include/` (`include/packfs.h` already had one; the `src/*.c` files and + `src/internal.h` did not). +- **Version API**: `PACKFS_VERSION_MAJOR`/`MINOR`/`PATCH`/`STRING` in + `include/packfs.h`, a runtime `pfs_version()` (`src/vfs.c`, next to + `vfs_new`/`vfs_free`). Verified with a new assertion in + `tests/test_mem.c` that the compile-time macro and the runtime function + never disagree — a version API that can silently drift between its two + forms is worse than not having one. +- **`packfs.pc`** (pkg-config), generated by `make install` from a new + `packfs.pc.in`, with its `Version:` field derived from + `PACKFS_VERSION_STRING` via a Makefile-level `grep`/`sed` rather than + hand-maintained separately. Verified end-to-end with a scratch + `make install PREFIX=...` followed by an actual + `pkg-config --cflags --libs packfs` call and `make uninstall` — not just + by reading the Makefile rule. +- **`SECURITY.md`**: states precisely what this project's containment and + pack-integrity code actually claims as a security boundary (`concept.md` + Section 6/7) versus what it explicitly does not (unenforced `mode`, no + cross-process concurrency) — including, after a later audit (§5), that + the pack integrity checksum (FNV-1a64) is non-cryptographic and not + tamper-evident against a deliberate adversary, a fact that was already + documented in the context of §1.2's dedup bug but had never been + explicitly connected to its *other* use, load-time integrity validation, + where it matters more. +- **`CHANGELOG.md`** (Keep a Changelog format), built from the real git + history — corrected once already (see the `a914330` commit) when a prior + commit landed *after* the `v0.1.0` tag without ever getting its own + entry, leaving the changelog stale the moment it happened. The fix: + recognize that "I tagged a release" is not the same event as "I stopped + needing to update the changelog," and check for this specifically after + any tag. +- **Considered and explicitly declined**: a `CODE_OF_CONDUCT.md`, per the + user's own choice when asked — recorded here so a future session doesn't + re-propose it as an oversight. +- **Gitea, not GitHub**: on explicit direction, `.github/workflows/ci.yml` + moved to `.gitea/workflows/ci.yml` (Gitea Actions' convention), and every + doc that assumed GitHub-specific features was corrected — most notably + `SECURITY.md`, which had claimed "private security advisories" would be + available once hosted, a GitHub feature this project's actual host + (Gitea) was never confirmed to have; reporting is by direct email only. + `README.md`'s claim that the suite is "regularly run under + ThreadSanitizer" was also corrected at this point to reflect §2.1's + actual, confirmed status, rather than left as an aspirational statement + a reader could mistake for a tested one. + +**Regression prevention.** All of the above are either self-verifying +(the version API test, the pkg-config round-trip) or are stated as +documentation with an explicit "verified by X" attached, per this +project's own documentation standard — the standard itself is the +regression-prevention mechanism here: a claim without a verification note +is treated as suspect on sight. + +--- + +## 4. Git identity correction + +**Symptom.** None from the code; a direct user request ("My name is +literary nowhere to find in the whole log anymore, not even in met a with +grep?") revealed the actual bug: every commit's author/committer showed the +user's real name, because commits had been made under whatever local git +config was already set on the machine, without ever asking what identity +this project should use — despite the user having already established +`SECURITY.md`'s contact as "retoor." + +**Fix, first pass.** `git filter-branch --env-filter` rewrote every +commit's author *and* committer across all 11 commits at the time, since +nothing had been pushed to any remote yet (confirmed via `git remote -v` +returning empty first) — making this a safe, local-only rewrite, not a +history rewrite against shared state. + +**A real gap found only by verifying the "fixed" state exhaustively, +not by re-checking `git log`.** `git log --format='%an <%ae>'` showed only +the corrected identity — but a full object-database sweep (`git +cat-file --batch-all-objects`, dumping and `grep`-ing every commit, tree, +blob, *and tag* object, not just what `git log` surfaces) found the +annotated `v0.1.0` tag object's own `tagger` field still showed the real +name. `git filter-branch`'s tag-rewriting step recreates the tag object +pointing at the new commit hash but does not apply the `--env-filter` to +the tag object's own tagger line — a genuinely separate object type with +its own separate metadata field, easy to miss if verification stops at +"does `git log` look right." + +**Fix, second pass.** Deleted and recreated the `v0.1.0` tag (with the +local git identity already corrected by that point), producing a fresh +tag object with the correct tagger. + +**Verification, exhaustive rather than spot-checked:** dumped and grepped +the content of all ~126 packed objects (case-insensitively, for the name, +the surname alone, and the email) — zero matches; ran +`git fsck --unreachable --dangling` after `gc --prune=now` — nothing left +over from the rewrite; checked `.git/config`, `.git/packed-refs`, both +reflog files' actual content (not just `git reflog show`), notes, and +stash — all clean; raw byte-level `grep -a -r -i` across the entire +`.git` directory — zero matches. + +**Regression prevention.** None needed as an ongoing mechanism (this was a +one-time correction, not a recurring class of bug) — but the *methodology* +is worth keeping: `git log` alone is not a complete verification of "is +this identity anywhere in this repository," because it doesn't surface tag +objects, reflogs, or dangling objects. A full object-database sweep is the +actual bar for "confirmed gone," and is cheap enough (a few seconds for a +repository this size) to just do rather than trust a partial check. + +--- + +## 5. Data-integrity fault injection + +Prompted by a direct question ("How safe is packfs to use for data +integrity?") that got an honest answer identifying two real, then-open +gaps: no fault-injection testing of the documented crash-safety claims, and +TSan having never actually verified the concurrency-safety claims (§2.1). +The user's follow-up ("Do whatever you need to do to make you trust it") +turned this from a documentation exercise into real engineering work. + +### 5.1 `tests/test_crash_consistency.c`: real `fork()`+`SIGKILL` fault injection (`e41bd23`) + +**What it does.** Forks a real child process, lets it run for an +empirically-calibrated delay (measured via throwaway scripts against this +build, not guessed — e.g. ~6ms per individually-journaled write, ~12ms for +a 4,000-entry/2KB-payload compaction), then `SIGKILL`s it and checks what a +fresh reopen recovers. Two scenarios: a burst of individually-journaled +writes (25 trials), and a compaction (`vfs_sync`) call (40 trials). + +**A real bug in the test itself, found before trusting its results.** The +first draft's compaction scenario reported 128 failures. Every one was a +bug in the test's own oracle, not in PackFS: it checked "is extra write *i* +present after the crash" without distinguishing "the child was killed +before it ever attempted write *i*" (expected, not a bug) from "write *i* +completed and was then lost" (would be a real bug) — `SIGKILL` cannot be +caught, so the child has no way to report its own progress through the +normal API once it's been killed. Fixed by adding an independent progress +side-channel: a plain POSIX `write()`+`fsync()` on a dedicated file, +entirely outside packfs, recording "N extras durably completed" after each +one — giving the test's own verification step ground truth for how far the +child actually got, independent of (and not trusting) the thing being +tested. + +**Result, after the test's own bug was fixed.** 20–22/25 burst trials and +40/40 compaction trials land a genuine interruption (`WIFSIGNALED`, not +`WIFEXITED`) per run; zero corruption or gaps found across dozens of runs, +including under ASan/UBSan. + +**Regression prevention.** This test itself, run as part of `make test` and +CI on every push. + +### 5.2 Silent journal-write failure — a real, previously-unknown data-loss bug (`153d44e`) + +**How it was found.** Not by a test — by reading `src/overlay.c`'s journal +code while building a fault-injection test for the "disk full mid-write" +case §5.1 didn't cover. + +**The bug.** `journal_append_record` and everything that called it +(`journal_append_put`/`_delete`/`_mkdir`, `journal_put_current`) were +`void`, and none of `journal_append_record`'s `fwrite`/`fflush`/`fsync` +calls had their return values checked. A real write failure (disk full, +quota, an I/O error) was silently reported as success by +`vfs_write`/`vfs_mkdir`/`vfs_unlink`/`vfs_rename` on an overlay-backed +file — directly contradicting Section 4.4's premise that a successful +journal append means the write is durable. + +**Fix.** Made the whole call chain return and propagate success/failure; +the affected `vfs_*` call now returns `VFS_ERR_IO` instead of silently +succeeding — while leaving the already-applied in-memory change as-is +(readers in the same process still see it), the same asymmetry a real +`write()`-succeeds-but-a-later-`fsync()`-fails has. There is no way to +"undo" the in-memory update, and the return value's job is to report +durability, not roll back visible state. + +**A second, deeper bug found only by reproducing the first fix's edge +case, not by reasoning about it.** Fixing the silent-failure bug alone was +not enough: a partial write leaves a torn record sitting in the middle of +the journal file, and `journal_replay` correctly stops at the first record +it can't fully read (Section 4.3, by design). A torn record left behind by +a *failed* write therefore poisons every record appended *after* it too — +including ones that themselves complete successfully later. Reproduced +directly before fixing: a forced-failed write followed immediately by a +genuinely successful one was unrecoverable after reopening — the good +record existed in the file, replay just never got past the torn one sitting +in front of it. + +**Fix.** Roll the journal file back to its exact pre-record byte length +(`ftell` captured before any of the record's bytes are written, `ftruncate` +on failure) whenever a record fails partway, keeping "the journal on disk +is valid up to EOF" true even when an individual write fails. + +**A third bug, found by inspection while in the same code.** +`journal_put_current` used to pass a `NULL` buffer into +`journal_append_record`'s `memcpy` of a nonzero size when `malloc(size)` +failed — an OOM-triggered NULL-pointer dereference. Closed with an +explicit `if (size && !buf) return -1;` guard. Not test-triggered +(reliably forcing `malloc()` failure in a portable, safe way isn't +practical here) — verified by code inspection and stated as such, not +claimed as tested. + +**Regression prevention.** `tests/test_journal_failure.c`, which forces a +*real* write failure via `RLIMIT_FSIZE` + ignoring `SIGXFSZ` (so `write()` +returns `EFBIG` instead of killing the process) rather than a mock, and +checks all three properties in one place: the failure is reported (not +swallowed), a fresh reopen does not see the torn record as if valid, and a +later genuinely-successful write on the same overlay session survives +reopening (the exact scenario that was broken before the rollback fix). + +--- + +## 6. CI as a second, independent reviewer + +Two real bugs were found not by local testing but by Gitea CI running the +exact same code under a genuinely different invocation — worth recording +as its own category, because both were invisible locally for structural +reasons, not bad luck. + +### 6.1 A real memory leak, masked by a local sanitizer habit (`4aad7d6`) + +**What CI reported.** `LeakSanitizer: detected memory leaks` — 256 bytes +across 4 allocations, from `vfs_new`/`vfs_unmount` call sites. + +**Why local testing never caught it.** Local ASan/UBSan verification had +been using `ASAN_OPTIONS=detect_leaks=0`. The reasoning behind that +override was sound on its own terms: a `SIGKILL`ed forked child (§5.1) +never runs its own exit-time leak check, so its allocations were never the +actual concern. The mistake was applying it to the *entire* test binary's +run, not just scoping it to the child's own allocations — this also +suppressed LeakSanitizer for the *parent* process's own code, which is +exactly where the real bug was sitting. + +**The actual bug.** `tests/test_journal_failure.c`'s two "reopen after the +failure, verify recovery" blocks called +`vfs_unmount`/`backend_free`/`backend_free` inside the `if (ov2)` branch +(the normal, expected path, always taken since the code's own `CHECK` +asserts `ov2 != NULL`) but `vfs_free(v2)` only on the `else` branch, which +in practice is never reached. + +**Fix.** Moved `vfs_free(v2)` to run unconditionally after the `if`, in +both blocks. + +**Verification.** Reproduced the leak first — dropped the +`detect_leaks=0` override locally, matching CI's actual invocation exactly, +*before* touching any code — then confirmed the fix the same way: all 8 +test binaries clean under ASan/UBSan with leak detection *on*, run +multiple times. + +**Regression prevention.** `CONTRIBUTING.md` now states this gap +explicitly: do not add `detect_leaks=0` (or any other blanket +sanitizer-weakening option) to a local verification habit without it also +being in `.gitea/workflows/ci.yml` — if local and CI check different +things, a real finding can pass locally and only surface once it reaches +CI, which is exactly what happened here. + +### 6.2 The `set -e` bug: CI's own script was the actual root cause of a reported failure (`c414a27`) + +This is the most involved finding in this document and the one most worth +reading in full before touching `.gitea/workflows/ci.yml` again. + +**What was reported.** Gitea CI's "Build and run under ThreadSanitizer" +step failing with `exitcode '66': failure`, after the build and test-suite +steps passed. 66 is TSan's own raw exit code for the `FATAL: +ThreadSanitizer: unexpected memory mapping` failure (§2.1) — the step's own +classification logic (added specifically to *not* fail the build over that +known, environment-caused failure) was supposed to catch this and turn it +into a warning, not a build failure. + +**Root cause, confirmed by direct reproduction, not theorized.** The +step's script assigned captured output via a bare, unwrapped +`OUT=$("./binary" 2>&1)`. Gitea Actions' `run:` steps execute under `bash +--noprofile --norc -eo pipefail {0}` — `set -e` is on by default. Under +`-e`, a command substitution's own nonzero exit status counts as that +simple command's failure, which aborts the whole script *immediately* — +*before* the very next line, even one that only reads `$?`, ever runs. +Reproduced directly with a two-line script: +```sh +set -e +OUT=$(false) +RC=$? +echo "after" # never printed +``` +This meant the classification logic a few lines further down the real +script never executed at all: the first TSan binary to hit the FATAL/ +exit-66 case (all of them, on this runner) killed the step outright with +that raw exit code, exactly the outcome the classification logic existed +to prevent. + +**Fix.** Wrap the invocation in `if cmd; then RC=0; else RC=$?; fi` — +bash's `-e` rules specifically exempt a command used as an `if` condition +from triggering an abort. Reproduced the fix working, the same way: +```sh +set -e +if OUT=$(false); then RC=0; else RC=$?; fi +echo "after, RC=$RC" # prints: after, RC=1 +``` + +**A follow-on bug, found only while verifying the fix under real +conditions, not assumed absent.** With the `-e` bug fixed, re-running the +corrected script repeatedly to verify it eventually hit §2.2 Variant B (the +flake's unbounded-loop form) — and when it did, the classification logic +misbehaved: an error line reported `(exit 0)`, which should have been +impossible. Root cause: capturing hundreds of megabytes of repeated +`AddressSanitizer:DEADLYSIGNAL` lines into a bash variable via +`OUT=$(cmd)` is not just slow — at that scale, the shell's own +string-handling stopped behaving reliably enough to trust the +classification built on top of it. **Fixed by redirecting output straight +to a file instead of a shell variable, and reading back only a bounded +64 KiB prefix** for both classification and logging (chosen generously — +this project's own real ASan/UBSan failure reports have historically been +a few dozen lines, nowhere near 64 KiB, while the flake's worst case was +hundreds of megabytes). This was applied to *both* the ASan/UBSan and TSan +steps, since both had the same fragility once genuinely stressed. + +**A mistake made while applying that exact fix, caught by testing it, not +by review.** The first attempt at the file-redirect fix wrote +`timeout 30 "./binary" > "$LOG" 2>&1` as a bare statement — reintroducing +the *exact same* `-e`-abort bug the whole exercise started from, just in a +new shape (redirecting to a file doesn't change whether the command itself +is subject to `-e`'s abort rule; only wrapping it in a tested context +does). Caught immediately by re-running the same two-line reproduction +technique against the new form before trusting it, not by inspection: +```sh +set -e +timeout 5 false > /tmp/out.log 2>&1 +RC=$? +echo "after" # never printed -- same bug, new location +``` +Fixed the same way as the first bug: `if timeout 30 "./binary" > "$LOG" +2>&1; then RC=0; else RC=$?; fi`. + +**A second, previously undocumented flake variant, discovered while +repeatedly reproducing the above.** TSan's broken startup on this runner +does not always print the clean `FATAL: ThreadSanitizer: unexpected memory +mapping` message — it sometimes segfaults outright instead (`timeout` +reports "the monitored command dumped core"). Confirmed this is the *same* +environmental cause, not a bug in any specific test file, by watching it +hit three different, unrelated binaries across repeated full-suite runs +(`test_journal_failure` in one run; `test_crash_consistency` and `test_dir` +together in another) — a real bug in one file's own code would not migrate +between files at random like that. The TSan step's classification now also +recognizes this variant: a log containing only `timeout`'s own "dumped +core" notice and nothing else (no program output, no real +`WARNING`/`SUMMARY: ThreadSanitizer:` race report) is treated the same as +the clean FATAL-message case. + +**A retry-budget gap, found by observing real failures during this same +verification work, not estimated in advance.** The ASan/UBSan step retries +a binary up to a fixed count before giving up; with a budget of 3, a real +run during this exact debugging session hit the DEADLYSIGNAL flake three +times in a row on the same binary purely by chance, exhausting the budget +and failing the step even though every individual attempt was correctly +classified as the known flake, not a real finding. This sandbox's actual +flake rate is evidently higher in practice than the "roughly 1 in 5–10" +`CONTRIBUTING.md` documents elsewhere. Fixed by raising the budget to 5, +which reduces (does not eliminate — this is a probabilistic mitigation, +not a fix for the underlying flake) the chance of exhausting it on bad luck +alone. + +**Verification, cumulative, all under `bash -eo pipefail` locally +(matching Gitea Actions' actual shell invocation) rather than assumed +correct from reading the diff:** +- The original `-e` bug: reproduced and fixed, confirmed with the two-line + repro above. +- The TSan step: re-run 10 full-suite times (80 individual binary + executions) after the fixes above, with both flake variants recurring + naturally and both correctly classified as warnings, zero false + failures. +- The ASan/UBSan step: re-run 10 full-suite times with the corrected + bounded-file logic and the 5-attempt budget, zero false failures. +- A separate, unrelated `-Wunused-result` warning on an intentionally- + ignored `write()` return value in `tests/test_crash_consistency.c` + (§5.1's progress side-channel) was *also* flagged by this same CI run. + The `(void)` cast used to silence it built warning-free locally but + still warned on the Gitea runner's gcc — reproduced clean locally with + the exact same compiler flags first, confirming this is a real + toolchain version/configuration difference between the two machines, + not a local misconfiguration on either side. `(void)`-cast suppression + of `warn_unused_result` is documented as unreliable across gcc + configurations for exactly this reason; fixed with an actual + conditional branch on the return value (`if (write(...) < 0) { }`) + instead, which every gcc/clang version this project has been built with + honors. + +**Regression prevention.** `.gitea/workflows/ci.yml` itself now carries +inline comments at each fixed site explaining exactly what would break and +why, so a future edit to these scripts doesn't reintroduce the same class +of bug without at least being warned by the comment sitting right there. +This document is the second layer: read §6.2 in full before touching the +sanitizer steps' shell scripts again, and re-run the exact two-line +`set -e` reproduction technique above against any new command-substitution +pattern before trusting it — that technique, cheap and fast, is what +caught every bug in this section, including the one introduced while fixing +the previous one. + +--- + +## 7. Distilled lessons + +These are the patterns that actually caught something above, stated once +here rather than only implicitly in each entry, so they can be applied to +a *new* problem, not just recognized in hindsight on this one: + +1. **A benchmark or test's own data can accidentally avoid the exact case + being measured.** §1.2 was invisible because the benchmark's identical + test-file content made a linear scan's worst case never happen. When + auditing for a known bug shape elsewhere, deliberately construct the + adversarial input, don't just re-run the existing benchmark and trust a + clean result. +2. **A fault-injection test's own oracle can be wrong, and has to be + checked with the same rigor as the code it's testing.** §5.1's first + 128 "failures" were a bug in the test. The fix (an independent + ground-truth side-channel, entirely outside the system under test) is + the general pattern: when the thing being tested is also the thing + reporting whether it worked, the report can't be trusted. +3. **Fixing one bug in a code path can leave a nearby, related bug + unfixed, discoverable only by reproducing the fix's own edge cases.** + §5.2's torn-record-poisoning-later-records bug was found only by + confirming the *first* fix actually solved the whole problem, not by + inspecting the diff and assuming it did. +4. **A local verification shortcut that diverges from what CI actually + runs can hide a real bug indefinitely.** §6.1: `detect_leaks=0` was + reasonable for one specific reason, applied too broadly, and CI (which + didn't share the shortcut) caught what dozens of local runs couldn't. +5. **`bash -e` does not do what it looks like it does around command + substitution.** §6.2, hit twice in the same debugging session (once as + the original bug, once as a mistake made while fixing it): `OUT=$(cmd)` + or `cmd > file` as a bare statement aborts the whole script on failure, + even one line before a line that reads `$?`. The fix is always + `if cmd; then ...; else RC=$?; fi`. Test this specific pattern with the + two-line reproduction in §6.2 before trusting any new script that + relies on inspecting a command's exit code under `set -e`. +6. **Capturing genuinely unbounded output into a shell variable is not + just a performance concern — it can make downstream logic behave + incorrectly at scale**, not just slowly. §6.2's second bug. Redirect to + a file and bound what's ever read back. +7. **A crash's signature is not necessarily unique — the same underlying + cause can manifest in more than one way, and the way to tell "same + cause, different symptom" from "different bug entirely" is to check + whether it's tied to specific code or migrates across unrelated + files/binaries at random.** §6.2's segfault variant of the already-known + TSan-can't-start issue was confirmed this way, not assumed. +8. **A compiler-warning suppression that works locally is not guaranteed + to work on a different toolchain build, even nominally "the same + compiler."** §6.2's `(void)`-cast case. Prefer suppressions that are + specified to work (an actual branch on the value) over idioms that + merely happen to compile clean once. +9. **Verifying "is this identity/string anywhere in this repository" means + more than `git log`.** §4: tag objects, reflogs, and dangling objects + all needed their own explicit check; a full object-database sweep is + cheap enough to just do. +10. **When a claim can be reproduced directly, reproduce it — don't reason + about whether it's true.** Every fix in this document was confirmed by + actually re-running the failing case under the same conditions that + produced the failure (the same shell mode, the same compiler flags, + the same sandbox), not by reading the diff and concluding it must now + be correct. This is the one pattern underlying all the others above. diff --git a/README.md b/README.md index 748f130..b5d5121 100644 --- a/README.md +++ b/README.md @@ -321,7 +321,11 @@ security boundary, and how to report a vulnerability. See [`CONTRIBUTING.md`](CONTRIBUTING.md). Read `concept.md` and `CLAUDE.md` first — they are the project's actual specification and its enforced documentation standard, respectively, and every design decision in the code -traces back to one of them. +traces back to one of them. [`POSTMORTEM.md`](POSTMORTEM.md) is a detailed, +permanent record of every real bug and environment issue found during this +project's development — what happened, how it was diagnosed, the fix, and +the regression-prevention artifact for each. Check it before re-diagnosing +something that might already be answered there. ## License