Files
packfs/tests/test_crash_consistency.c
T
retoorandClaude Sonnet 5 4aad7d6f64
CI / build-and-test (push) Failing after 38s
Fix real memory leak Gitea CI caught, that local testing had been masking
Gitea CI flagged two things on the last push:

1. A -Wunused-result warning on an intentionally-ignored write() return
   value in test_crash_consistency.c's progress side-channel. Fixed with
   an explicit (void) cast and a comment explaining why ignoring it is
   safe (a short write there only makes the progress count more
   conservative, per that function's own existing documented tolerance).

2. A real LeakSanitizer failure -- 256 bytes across 4 allocations from
   vfs_new/vfs_unmount. Root cause: tests/test_journal_failure.c's two
   "reopen after the failure, verify recovery" blocks called
   vfs_unmount/backend_free/backend_free inside their `if (ov2)` branch
   (the normal, expected path) but vfs_free(v2) only on the `else`
   branch, which is never actually reached in practice. Fixed by moving
   vfs_free(v2) to run unconditionally after the if, in both blocks.

This bug was invisible locally across many runs because local sanitizer
verification had been using ASAN_OPTIONS=detect_leaks=0 -- adopted
originally for a real reason (a SIGKILLed forked child in
test_crash_consistency.c never runs its own exit-time leak check, so its
allocations were never the actual concern) but applied to the whole test
run, which also suppressed detection of this real bug in the *parent*
process's own code. CI doesn't set that option, so it caught what local
runs couldn't. Documented in CONTRIBUTING.md as a real process gap, not
just a code bug: a local verification habit that diverges from what CI
actually runs can let a real finding through until it reaches CI.

Verified: confirmed the leak directly first (reproduced locally by
dropping the detect_leaks=0 override, matching CI exactly, before
touching any code), then confirmed the fix by re-running the same
no-override sweep across all 8 test binaries with zero leaks found, plus
a clean make all + make test.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01UqJpkdJ6Njnt1pw3CbghzB
2026-09-14 20:10:25 +00:00

406 lines
16 KiB
C

/*
* test_crash_consistency.c — real fault injection for Section 4.3/4.4's
* crash-safety claims (self-checking journal records, atomic-rename
* compaction), via an actual fork()+SIGKILL of a child mid-operation and
* a fresh reopen afterward, not a hand-truncated file standing in for a
* crash. The two scenarios below (journal writes, compaction) were the
* two concrete claims CLAUDE.md/concept.md make about crash behavior;
* before this file, neither had ever actually been exercised by killing
* a real process mid-write — only by static reasoning about the design
* and by test_pack_overlay.c's separate (unrelated) test of loading an
* already-corrupted pack file.
*
* Timing constants below are empirically calibrated for this project's
* own build (see the comment above each scenario), not arbitrary: the
* goal is to sample kill delays across the real duration of the
* operation under test, confirmed per-run by reporting how many trials
* actually landed a genuine mid-operation kill (WIFSIGNALED) versus how
* many the child outran (WIFEXITED) — a run reporting zero interrupted
* trials would mean this test verified nothing and should be treated as
* a test bug, not a pass; see the CHECK on INTERRUPTED_MIN below.
*/
#include <fcntl.h>
#include <signal.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/wait.h>
#include <time.h>
#include <unistd.h>
#include "packfs.h"
#include "test_harness.h"
static void sleep_sec(double s) {
struct timespec ts;
ts.tv_sec = (time_t)s;
ts.tv_nsec = (long)((s - (double)ts.tv_sec) * 1e9);
nanosleep(&ts, NULL);
}
/* fork the given child function, let it run for kill_delay seconds, then
* SIGKILL it. Returns 1 if the child was genuinely still running (killed
* by the signal), 0 if it had already exited on its own. */
static int run_and_kill(void (*child_fn)(void *), void *arg, double kill_delay) {
pid_t pid = fork();
if (pid < 0) { perror("fork"); exit(1); }
if (pid == 0) {
child_fn(arg);
_exit(99); /* child_fn must _exit itself; this is a safety net */
}
sleep_sec(kill_delay);
kill(pid, SIGKILL);
int status = 0;
waitpid(pid, &status, 0);
return WIFSIGNALED(status) && WTERMSIG(status) == SIGKILL;
}
/* ================= scenario A: kill mid-burst of journaled writes ===== */
/*
* Calibrated: ~6ms per individual journaled create+write+close on this
* build/environment (fopen+fwrite+fflush+fsync per record, Section 4.4).
* BURST=60 writes takes ~0.36s; sampling kill delays across [0, 0.40s]
* covers the whole burst including its very start and its tail.
*/
#define BURST_N 60
#define BURST_TRIALS 25
#define BURST_MAX_DELAY 0.40
typedef struct { char pack_path[512]; } BurstArg;
static void mk_burst_content(char *buf, size_t n, int i) {
snprintf(buf, n, "burst-content-%06d", i);
}
static void burst_child(void *arg_) {
BurstArg *arg = (BurstArg *)arg_;
Vfs *v = vfs_new();
Backend *mem = backend_mem_new();
int oerr = 0;
Backend *ov = backend_overlay_new(arg->pack_path, mem, &oerr);
if (!ov) _exit(2);
if (vfs_mount(v, "/", ov) != VFS_OK) _exit(3);
char name[64], content[64];
for (int i = 0; i < BURST_N; i++) {
snprintf(name, sizeof(name), "/f%05d.txt", i);
mk_burst_content(content, sizeof(content), i);
int err = 0;
VfsFile *f = vfs_open(v, name, VFS_O_WRONLY | VFS_O_CREAT, &err);
if (!f) _exit(4);
if (vfs_write(f, content, strlen(content)) != (pfs_isize)strlen(content)) _exit(5);
if (vfs_close(f) != VFS_OK) _exit(6);
}
_exit(0); /* all BURST_N writes durably committed */
}
static void test_journal_burst_crash(void) {
BurstArg arg;
snprintf(arg.pack_path, sizeof(arg.pack_path), "/tmp/packfs_test_crash_burst_%d.img", (int)getpid());
char jpath[600];
snprintf(jpath, sizeof(jpath), "%s.jnl", arg.pack_path);
int interrupted_count = 0;
for (int trial = 0; trial < BURST_TRIALS; trial++) {
unlink(arg.pack_path);
unlink(jpath);
double delay = (BURST_MAX_DELAY * (double)trial) / (double)(BURST_TRIALS - 1);
int interrupted = run_and_kill(burst_child, &arg, delay);
if (interrupted) interrupted_count++;
Vfs *v2 = vfs_new();
Backend *mem2 = backend_mem_new();
int oerr2 = 0;
Backend *ov2 = backend_overlay_new(arg.pack_path, mem2, &oerr2);
CHECK(ov2 != NULL); /* a crash mid-journal must never make reopening fail */
if (!ov2) { vfs_free(v2); backend_free(mem2); continue; }
CHECK_EQ_INT(vfs_mount(v2, "/", ov2), VFS_OK);
/* clean-prefix invariant: every present file has exactly correct
* content, and there is no gap (file i missing, file i+1 present) */
int last_present = -1;
char name[64], expect[64], buf[64];
for (int i = 0; i < BURST_N; i++) {
snprintf(name, sizeof(name), "/f%05d.txt", i);
int err = 0;
VfsFile *f = vfs_open(v2, name, VFS_O_RDONLY, &err);
if (!f) continue;
mk_burst_content(expect, sizeof(expect), i);
memset(buf, 0, sizeof(buf));
pfs_isize n = vfs_read(f, buf, sizeof(buf));
vfs_close(f);
if (n != (pfs_isize)strlen(expect) || memcmp(buf, expect, strlen(expect)) != 0) {
fprintf(stderr, "FAIL trial %d: %s has wrong/corrupt content after crash (delay=%.4f)\n",
trial, name, delay);
pfs_test_failures++;
}
if (i != last_present + 1) {
fprintf(stderr, "FAIL trial %d: gap in journal replay prefix at %s (delay=%.4f)\n",
trial, name, delay);
pfs_test_failures++;
}
last_present = i;
}
vfs_unmount(v2, "/");
backend_free(ov2);
backend_free(mem2);
vfs_free(v2);
}
unlink(arg.pack_path);
unlink(jpath);
fprintf(stderr, "journal-burst crash test: %d/%d trials genuinely interrupted mid-burst\n",
interrupted_count, BURST_TRIALS);
/* if this is ever 0, the delay schedule no longer matches this
* machine's write latency and the test isn't exercising the crash
* path at all -- that is itself a failure, not a quiet pass. */
CHECK(interrupted_count >= BURST_TRIALS / 4);
}
/* ================= scenario B: kill mid-compaction ===================== */
/*
* Calibrated: a 100-file, 2KB-payload durable baseline (built once,
* untimed, then compacted once to get a clean golden pack.img) plus a
* per-trial 10-file durable "extras" batch takes ~0.058s to journal and
* the following compaction takes ~0.012s on this build/environment.
* Sampling kill delays across [0, 0.08s] covers extras-journaling,
* compaction start, mid-compaction, and post-rename.
*
* The invariant under test is not "pre-state XOR post-state" -- it's
* simpler and is the actual documented guarantee (concept.md's crash-
* safety constraints, CLAUDE.md's "if writing pack.img.tmp or its fsync
* fails, compaction aborts and the existing pack + journal are
* untouched"): anything durably journaled (fsynced) *before* vfs_sync is
* even called must survive a crash during that vfs_sync call, no matter
* where in it the crash lands -- either via journal replay (if
* compaction didn't finish) or by being included in the fresh pack (if
* it did).
*/
#define GOLDEN_N 100
#define EXTRA_N 10
#define PAYLOAD_SIZE 2048
#define COMPACT_TRIALS 40
#define COMPACT_MAX_DELAY 0.08
typedef struct { char pack_path[512]; char golden_path[512]; char progress_path[512]; } CompactArg;
static void mk_payload(char *buf, size_t n, const char *tag, int i) {
int len = snprintf(buf, n, "%s-%06d-", tag, i);
for (size_t j = (size_t)len; j < n; j++) buf[j] = (char)('a' + (int)(j % 26));
}
static int copy_file(const char *from, const char *to) {
FILE *in = fopen(from, "rb");
if (!in) return -1;
FILE *out = fopen(to, "wb");
if (!out) { fclose(in); return -1; }
char buf[65536];
size_t n;
while ((n = fread(buf, 1, sizeof(buf), in)) > 0) fwrite(buf, 1, n, out);
fclose(in);
fclose(out);
return 0;
}
/* Records "N extras durably completed" via a plain POSIX write+fsync on a
* dedicated file, entirely independent of packfs. This is the test's
* ground truth for how far the child actually got before SIGKILL landed
* -- without it, an extra that the child simply never reached in time
* (expected, not a bug) is indistinguishable from one that completed and
* was then lost (a real bug), since SIGKILL cannot be caught to report
* progress any other way. The one imprecision this leaves: the tiny gap
* between vfs_close() returning (extra i durably in the journal) and
* this progress write's own fsync landing can make the progress count
* undercount by one extra in the worst case -- which only makes the
* check *less* strict at the margin (skips verifying the most recent
* extra), never produces a false failure. */
static void record_progress(const char *progress_path, int n_done) {
int fd = open(progress_path, O_WRONLY | O_CREAT | O_TRUNC, 0644);
if (fd < 0) return;
char buf[16];
int len = snprintf(buf, sizeof(buf), "%d", n_done);
/* Best-effort: a short write here only makes read_progress()'s count
* more conservative (see the imprecision note above), never wrong in
* the unsafe direction, so there is nothing more useful to do with a
* partial-write return value than the explicit (void) already says. */
(void)write(fd, buf, (size_t)len);
fsync(fd);
close(fd);
}
static int read_progress(const char *progress_path) {
FILE *fp = fopen(progress_path, "r");
if (!fp) return 0;
int n = 0;
if (fscanf(fp, "%d", &n) != 1) n = 0;
fclose(fp);
return n;
}
static void compact_child(void *arg_) {
CompactArg *arg = (CompactArg *)arg_;
record_progress(arg->progress_path, 0);
Vfs *v = vfs_new();
Backend *mem = backend_mem_new();
int oerr = 0;
Backend *ov = backend_overlay_new(arg->pack_path, mem, &oerr);
if (!ov) _exit(2);
if (vfs_mount(v, "/", ov) != VFS_OK) _exit(3);
char payload[PAYLOAD_SIZE];
for (int i = 0; i < EXTRA_N; i++) {
char name[64];
snprintf(name, sizeof(name), "/extra%04d.dat", i);
mk_payload(payload, sizeof(payload), "extra", i);
int err = 0;
VfsFile *f = vfs_open(v, name, VFS_O_WRONLY | VFS_O_CREAT, &err);
if (!f) _exit(4);
if (vfs_write(f, payload, sizeof(payload)) != (pfs_isize)sizeof(payload)) _exit(5);
if (vfs_close(f) != VFS_OK) _exit(6);
record_progress(arg->progress_path, i + 1); /* extra i is now durable */
}
/* every extra above is already durable (each fsynced individually);
* this is the operation actually being crash-tested */
if (vfs_sync(v, "/") != VFS_OK) _exit(7);
_exit(0);
}
static void build_golden_baseline(CompactArg *arg) {
unlink(arg->pack_path);
char jpath[600];
snprintf(jpath, sizeof(jpath), "%s.jnl", arg->pack_path);
unlink(jpath);
Vfs *v = vfs_new();
Backend *mem = backend_mem_new();
int oerr = 0;
Backend *ov = backend_overlay_new(arg->pack_path, mem, &oerr);
CHECK(ov != NULL);
CHECK_EQ_INT(vfs_mount(v, "/", ov), VFS_OK);
char payload[PAYLOAD_SIZE];
for (int i = 0; i < GOLDEN_N; i++) {
char name[64];
snprintf(name, sizeof(name), "/base%05d.dat", i);
mk_payload(payload, sizeof(payload), "base", i);
int err = 0;
VfsFile *f = vfs_open(v, name, VFS_O_WRONLY | VFS_O_CREAT, &err);
CHECK(f != NULL);
CHECK_EQ_INT(vfs_write(f, payload, sizeof(payload)), (pfs_isize)sizeof(payload));
CHECK_EQ_INT(vfs_close(f), VFS_OK);
}
CHECK_EQ_INT(vfs_sync(v, "/"), VFS_OK); /* clean, untimed compaction */
vfs_unmount(v, "/");
backend_free(ov);
backend_free(mem);
vfs_free(v);
unlink(jpath); /* golden state: compacted pack, no pending journal */
CHECK_EQ_INT(copy_file(arg->pack_path, arg->golden_path), 0);
}
static void test_compaction_crash(void) {
CompactArg arg;
snprintf(arg.pack_path, sizeof(arg.pack_path), "/tmp/packfs_test_crash_compact_%d.img", (int)getpid());
snprintf(arg.golden_path, sizeof(arg.golden_path), "/tmp/packfs_test_crash_golden_%d.img", (int)getpid());
snprintf(arg.progress_path, sizeof(arg.progress_path), "/tmp/packfs_test_crash_progress_%d.txt", (int)getpid());
char jpath[600];
snprintf(jpath, sizeof(jpath), "%s.jnl", arg.pack_path);
build_golden_baseline(&arg);
int interrupted_count = 0;
for (int trial = 0; trial < COMPACT_TRIALS; trial++) {
CHECK_EQ_INT(copy_file(arg.golden_path, arg.pack_path), 0);
unlink(jpath);
double delay = (COMPACT_MAX_DELAY * (double)trial) / (double)(COMPACT_TRIALS - 1);
int interrupted = run_and_kill(compact_child, &arg, delay);
if (interrupted) interrupted_count++;
Vfs *v2 = vfs_new();
Backend *mem2 = backend_mem_new();
int oerr2 = 0;
Backend *ov2 = backend_overlay_new(arg.pack_path, mem2, &oerr2);
CHECK(ov2 != NULL); /* a crash mid-compaction must never make reopening fail */
if (!ov2) { vfs_free(v2); backend_free(mem2); continue; }
CHECK_EQ_INT(vfs_mount(v2, "/", ov2), VFS_OK);
/* the pre-existing golden baseline must always survive */
char name[64], expect[PAYLOAD_SIZE], buf[PAYLOAD_SIZE];
for (int i = 0; i < GOLDEN_N; i++) {
snprintf(name, sizeof(name), "/base%05d.dat", i);
mk_payload(expect, sizeof(expect), "base", i);
int err = 0;
VfsFile *f = vfs_open(v2, name, VFS_O_RDONLY, &err);
if (!f) {
fprintf(stderr, "FAIL trial %d: baseline file %s LOST after compaction crash (delay=%.4f)\n",
trial, name, delay);
pfs_test_failures++;
continue;
}
memset(buf, 0, sizeof(buf));
pfs_isize n = vfs_read(f, buf, sizeof(buf));
vfs_close(f);
if (n != (pfs_isize)sizeof(buf) || memcmp(buf, expect, sizeof(buf)) != 0) {
fprintf(stderr, "FAIL trial %d: baseline file %s CORRUPTED after compaction crash (delay=%.4f)\n",
trial, name, delay);
pfs_test_failures++;
}
}
/* Every "extra" write the child actually completed (vfs_close
* returned VFS_OK) before it was killed was already durably
* journaled at that point -- it must survive regardless of
* whether the subsequent vfs_sync (compaction) itself completed.
* completed_extras, from the independent progress side-channel,
* is the ground truth for how many extras the child actually
* finished; extras beyond that were never attempted and their
* absence is expected, not a bug. */
int completed_extras = read_progress(arg.progress_path);
CHECK(completed_extras >= 0 && completed_extras <= EXTRA_N);
for (int i = 0; i < completed_extras; i++) {
snprintf(name, sizeof(name), "/extra%04d.dat", i);
mk_payload(expect, sizeof(expect), "extra", i);
int err = 0;
VfsFile *f = vfs_open(v2, name, VFS_O_RDONLY, &err);
if (!f) {
fprintf(stderr, "FAIL trial %d: durably-completed %s LOST after compaction crash "
"(delay=%.4f, completed_extras=%d)\n", trial, name, delay, completed_extras);
pfs_test_failures++;
continue;
}
memset(buf, 0, sizeof(buf));
pfs_isize n = vfs_read(f, buf, sizeof(buf));
vfs_close(f);
if (n != (pfs_isize)sizeof(buf) || memcmp(buf, expect, sizeof(buf)) != 0) {
fprintf(stderr, "FAIL trial %d: durably-completed %s CORRUPTED after compaction crash "
"(delay=%.4f, completed_extras=%d)\n", trial, name, delay, completed_extras);
pfs_test_failures++;
}
}
vfs_unmount(v2, "/");
backend_free(ov2);
backend_free(mem2);
vfs_free(v2);
}
unlink(arg.pack_path);
unlink(arg.golden_path);
unlink(arg.progress_path);
unlink(jpath);
fprintf(stderr, "compaction crash test: %d/%d trials genuinely interrupted mid-compaction\n",
interrupted_count, COMPACT_TRIALS);
CHECK(interrupted_count >= COMPACT_TRIALS / 4);
}
int main(void) {
test_journal_burst_crash();
test_compaction_crash();
TEST_MAIN_END();
}