From 8f63c6df704cad0ad1583eb8501938fb6f8ee017 Mon Sep 17 00:00:00 2001 From: "A.Shakhmatov" Date: Sun, 9 Aug 2026 17:44:05 +0300 Subject: [PATCH] tests/e2e: the churn gate, as a committed harness D7.4 was the only block in `tests/e2e/results/m0-gates.txt` without a `reproduce:` line. The numbers were real and the harness was not committed, so the one measurement the whole free-list decision rested on could not be re-run against a change. This is that harness. Self-contained like `e2e6.js`: it spawns its own server on a fresh database. Two modes, delete-and-refill and repeated update, over `--docs` documents of `--doc-size`, with `--index` to put index maintenance inside the churn rather than beside it. Three things it does that the ad-hoc version did not: Live bytes are computed here, from the serialized size of one document, rather than read off the server. That is what makes a run against an older binary comparable -- and the first thing this harness was used for was measuring the pre-Stage-3 binary, which has no `multifora` section at all. Deleted ids are sampled from the ids actually live. Sampling blind from the id space re-picks dead ones, so a round deletes fewer documents than it inserts and a supposedly flat-live measurement quietly grows. The first run of this harness ended with 3211 documents where it should have had 2000. And it prints `inUse` beside `ratio`. The data file never shrinks, so `file / live` is a high-water mark and cannot come down however well reclamation works; `inUse` is `(allocTail - freeReady) / live`, which is what the database is actually occupying. On the update line those two read 2.46x and 1.06-1.26x for the same run, and the difference between them is the whole finding. A fixed seed, so two runs churn the same documents in the same order and a difference between them is the code rather than the dice. `--target x` fails the run above a ratio, for use as a gate; without it the harness measures and reports. --- tests/e2e/churn.js | 360 +++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 360 insertions(+) create mode 100644 tests/e2e/churn.js diff --git a/tests/e2e/churn.js b/tests/e2e/churn.js new file mode 100644 index 0000000..c03a08c --- /dev/null +++ b/tests/e2e/churn.js @@ -0,0 +1,360 @@ +// The churn gate: how large the data file settles at, relative to the live +// data, under sustained rewriting. +// +// This is the measurement PLAN D7.4 was decided on, and until now it was the +// only gate in `tests/e2e/results/m0-gates.txt` without a `reproduce:` line -- +// the numbers were real but the harness was not committed, so nobody could +// re-run them against a change. That is what this file fixes. +// +// It spawns its own server on a fresh database, so it needs nothing running: +// +// node tests/e2e/churn.js --docs 40000 --doc-size 16k --index \ +// --mode delete-refill --rounds 6 +// node tests/e2e/churn.js --docs 40000 --doc-size 16k --index \ +// --mode update --multiple 5 +// +// What to read. The ratio alone does not say whether reclamation is working: +// a file that grows and is periodically halved by a rebuild averages out to a +// respectable number. So every round prints `reclaimed`, `allocTail` and +// `compactions` beside it. Reclamation is carrying the workload when +// `reclaimed` climbs while `allocTail` stays put. If instead `allocTail` grows +// by the full write volume of each round, the free list is decorative however +// good the ratio looks -- and that is a failure even at 1.2x. +// +// Small documents are expected not to improve on the delete-refill line, and +// that is a pass rather than a fault. Reclamation gives back whole system +// pages, so a 16 KiB page holds ~82 documents of 200 bytes and the chance all +// 82 are dead at once is nil. The mechanism to check there is that the +// counters decay correctly, not that the ratio moves. +// +// Options: +// --docs documents in the collection (default 40000) +// --doc-size payload bytes per document (default 16k) +// --index create one secondary index over a churned field +// --mode delete-refill (default) | update +// --rounds delete-refill rounds (default 6) +// --multiple update mode: total writes as a multiple of --docs +// --target fail unless the steady-state ratio is at or under x +// --port listen port (default 27320) +// --keep leave the database file behind +const { MongoClient } = require('mongodb'); +const { spawn } = require('child_process'); +const fs = require('fs'); +const path = require('path'); + +function parseSize(s) { + const m = String(s).match(/^(\d+)([kKmMgG]?)$/); + if (!m) throw new Error(`bad size: ${s}`); + const mult = { '': 1, k: 1 << 10, m: 1 << 20, g: 1 << 30 }[m[2].toLowerCase()]; + return Number(m[1]) * mult; +} + +function parseArgs(argv) { + const o = { + docs: 40000, docSize: 16 << 10, index: false, mode: 'delete-refill', + rounds: 6, multiple: 5, target: null, port: 27320, keep: false, + }; + for (let i = 0; i < argv.length; i++) { + const a = argv[i]; + const next = () => { + if (i + 1 >= argv.length) throw new Error(`${a} needs a value`); + return argv[++i]; + }; + switch (a) { + case '--docs': o.docs = Number(next()); break; + case '--doc-size': o.docSize = parseSize(next()); break; + case '--index': o.index = true; break; + case '--mode': o.mode = next(); break; + case '--rounds': o.rounds = Number(next()); break; + case '--multiple': o.multiple = Number(next()); break; + case '--target': o.target = Number(next()); break; + case '--port': o.port = Number(next()); break; + case '--keep': o.keep = true; break; + default: throw new Error(`unknown option ${a}`); + } + } + if (o.mode !== 'delete-refill' && o.mode !== 'update') { + throw new Error(`--mode must be delete-refill or update, got ${o.mode}`); + } + return o; +} + +const opt = parseArgs(process.argv.slice(2)); +const BIN = process.env.MFDB_BIN || path.resolve(__dirname, '../../zig-out/bin/multiforadb'); +const DBFILE = process.env.CHURN_DB || + path.resolve(__dirname, `../../.zig-cache/churn-${opt.port}.log`); +const URL = `mongodb://127.0.0.1:${opt.port}`; + +const sleep = (ms) => new Promise((r) => setTimeout(r, ms)); + +// A fixed seed, so two runs churn the same documents in the same order and a +// difference between them is the code rather than the dice. +let seed = 0x9e3779b9; +function rnd() { + seed ^= seed << 13; seed >>>= 0; + seed ^= seed >> 17; + seed ^= seed << 5; seed >>>= 0; + return seed / 0x100000000; +} +const pick = (n) => Math.floor(rnd() * n); + +let server = null; +let serverDead = false; +let serverLog = ''; + +function cleanup() { + if (server && !serverDead) { + try { server.kill('SIGKILL'); } catch {} + } +} +process.on('exit', cleanup); +process.on('SIGINT', () => { cleanup(); process.exit(130); }); +process.on('SIGTERM', () => { cleanup(); process.exit(143); }); + +function startServer() { + return new Promise((resolve, reject) => { + fs.rmSync(DBFILE, { force: true }); + fs.rmSync(DBFILE + '.data', { force: true }); + serverDead = false; + server = spawn(BIN, ['--port', String(opt.port), '--db', DBFILE], { + stdio: ['ignore', 'pipe', 'pipe'], + }); + server.stdout.on('data', (d) => (serverLog += d)); + server.stderr.on('data', (d) => (serverLog += d)); + server.on('error', (e) => reject(new Error(`cannot start ${BIN}: ${e.message}`))); + server.on('exit', (code, sig) => { + // A child that dies must fail the start, or the poll below would find a + // *stale* server on the same port and measure the wrong database. + serverDead = true; + if (code !== null && sig === null) serverLog += `\n[child exited rc=${code}]`; + }); + const deadline = Date.now() + 15000; + (async () => { + while (Date.now() < deadline) { + if (serverDead) { + reject(new Error(`server child exited during start (port ${opt.port} busy?)\n${serverLog}`)); + return; + } + const c = new MongoClient(URL, { serverSelectionTimeoutMS: 1000 }); + try { + await c.connect(); + await c.db('admin').command({ ping: 1 }); + await c.close(); + return resolve(); + } catch { + try { await c.close(); } catch {} + await sleep(100); + } + } + reject(new Error(`server did not come up on :${opt.port}\n${serverLog}`)); + })(); + }); +} + +async function stopServer() { + if (!server) return; + const exited = new Promise((r) => server.once('exit', r)); + server.kill('SIGTERM'); + await Promise.race([exited, sleep(5000)]); + serverDead = true; + server = null; +} + +function dataFileBytes() { + try { + return fs.statSync(DBFILE + '.data').size; + } catch { + return 0; + } +} + +const MB = (n) => (n / (1 << 20)).toFixed(1); + +// Live bytes are computed here rather than read off the server, so the ratio +// means the same thing whatever binary is under test. A `multifora` section is +// a recent addition; without it the counters print as n/a and the ratio -- the +// number the gate is actually about -- is still measured, which is what makes +// a run against an older build comparable. +let docBytes = 0; + +async function stats(client, coll) { + const s = await client.db('admin').command({ serverStatus: 1 }); + const m = s.multifora || null; + const num = (v) => Number(v); + const count = await coll.countDocuments({}); + return { + live: count * docBytes, + count, + file: dataFileBytes(), + m: m && { + live: num(m.liveBytes), + dead: num(m.deadBytes), + reclaimed: num(m.reclaimedBytes), + runs: num(m.slabRuns), + freeReady: num(m.freeReadyPages), + allocTail: num(m.allocTail), + compactions: num(m.compactions), + }, + }; +} + +function report(label, s) { + const ratio = s.live > 0 ? s.file / s.live : 0; + let line = ` ${label.padEnd(12)} ratio ${ratio.toFixed(2)}x file ${MB(s.file)}MB live ${MB(s.live)}MB`; + if (s.m) { + // What the database is actually occupying, as opposed to what it has ever + // had to occupy. The file never shrinks, so `ratio` is a high-water mark + // and cannot come down however well reclamation works; `inUse` is the + // number that moves when it does. + const inUse = (s.m.allocTail - s.m.freeReady) * 4096; + line += ` inUse ${(inUse / s.live).toFixed(2)}x` + + ` dead ${MB(s.m.dead)}MB reclaimed ${MB(s.m.reclaimed)}MB` + + ` allocTail ${MB(s.m.allocTail * 4096)}MB freeReady ${MB(s.m.freeReady * 4096)}MB` + + ` runs ${s.m.runs} compactions ${s.m.compactions}`; + } else { + line += ' (no multifora section: counters n/a)'; + } + console.log(line); + return ratio; +} + +// One document of about `opt.docSize` payload bytes. `k` is the field a +// secondary index covers and an update rewrites, so index maintenance is part +// of the churn rather than a constant. +const PAD = 'x'.repeat(Math.max(1, opt.docSize)); +function makeDoc(id) { + return { _id: id, k: id % 1000, pad: PAD }; +} + +// Batches sized so one insertMany stays well under the 48 MB wire limit +// whatever --doc-size is. +function batchSize() { + return Math.max(1, Math.min(1000, Math.floor((8 << 20) / (opt.docSize + 64)))); +} + +async function insertRange(coll, from, to) { + const bs = batchSize(); + for (let i = from; i < to; i += bs) { + const docs = []; + for (let j = i; j < Math.min(i + bs, to); j++) docs.push(makeDoc(j)); + await coll.insertMany(docs, { ordered: false }); + } +} + +async function main() { + console.log( + `churn: ${opt.docs} x ${opt.docSize} B, mode ${opt.mode}` + + `${opt.index ? ', one secondary index' : ''}` + + `${opt.mode === 'delete-refill' ? `, ${opt.rounds} rounds` : `, ${opt.multiple}x writes`}`, + ); + console.log(`churn: platform ${process.platform}/${process.arch}, binary ${BIN}`); + await startServer(); + const client = new MongoClient(URL, { serverSelectionTimeoutMS: 5000 }); + await client.connect(); + const db = client.db('churn'); + const coll = db.collection('c'); + + const t0 = Date.now(); + // The exact serialized size of one document, so `live` is a real byte count + // rather than the payload size the caller asked for. + docBytes = require('mongodb').BSON.serialize(makeDoc(0)).length; + await insertRange(coll, 0, opt.docs); + if (opt.index) await coll.createIndex({ k: 1 }); + const base = await stats(client, coll); + report('loaded', base); + + const ratios = []; + let nextId = opt.docs; + if (opt.mode === 'delete-refill') { + // Half the collection dies and is replaced by fresh documents, so the live + // size is flat and everything the file gains is garbage that was not + // reclaimed. + const half = Math.floor(opt.docs / 2); + // The ids actually live, so a round deletes exactly `half` documents and + // the collection stays the same size. Sampling blind from the id space + // re-picks already-dead ids, which deletes fewer than it inserts and turns + // a flat-live measurement into a growing one. + const live = Array.from({ length: opt.docs }, (_, i) => i); + for (let r = 0; r < opt.rounds; r++) { + const ids = []; + for (let i = 0; i < half; i++) { + const at = pick(live.length); + ids.push(live[at]); + live[at] = live[live.length - 1]; + live.pop(); + } + const bs = 5000; + for (let i = 0; i < ids.length; i += bs) { + await coll.deleteMany({ _id: { $in: ids.slice(i, i + bs) } }); + } + await insertRange(coll, nextId, nextId + ids.length); + for (let i = 0; i < ids.length; i++) live.push(nextId + i); + nextId += ids.length; + ratios.push(report(`round ${r + 1}`, await stats(client, coll))); + } + } else { + // The same documents rewritten over and over: every rewrite leaves the old + // copy behind, and old copies die in insertion order, which is the best + // case for reclaiming whole windows. + const total = opt.docs * opt.multiple; + const per = Math.floor(total / opt.rounds); + for (let r = 0; r < opt.rounds; r++) { + let done = 0; + while (done < per) { + const ops = []; + for (let i = 0; i < Math.min(2000, per - done); i++) { + const id = pick(opt.docs); + ops.push({ updateOne: { filter: { _id: id }, update: { $set: { k: pick(1000) } } } }); + } + await coll.bulkWrite(ops, { ordered: false }); + done += ops.length; + } + ratios.push(report(`round ${r + 1}`, await stats(client, coll))); + } + } + + const final = await stats(client, coll); + const count = final.count; + const elapsed = ((Date.now() - t0) / 1000).toFixed(0); + console.log(`churn: ${count} documents live at the end, ${elapsed}s`); + + // Steady state is the second half of the rounds: the first ones are still + // filling the file out and say nothing about where it settles. + const tail = ratios.slice(Math.floor(ratios.length / 2)); + const steady = tail.reduce((a, b) => a + b, 0) / tail.length; + const drift = tail.length > 1 ? tail[tail.length - 1] - tail[0] : 0; + console.log( + `churn: steady state ${steady.toFixed(2)}x over the last ${tail.length} rounds, ` + + `drift ${drift >= 0 ? '+' : ''}${drift.toFixed(2)}x`, + ); + if (final.m) { + console.log( + `churn: reclaimed ${MB(final.m.reclaimed)}MB total, ` + + `${final.m.compactions} collection rebuilds`, + ); + } + + await client.close(); + if (!opt.keep) { + fs.rmSync(DBFILE, { force: true }); + fs.rmSync(DBFILE + '.data', { force: true }); + } + await stopServer(); + + if (count !== opt.docs) { + console.log(`CHURN_FAIL: ${count} documents live, expected ${opt.docs}`); + process.exit(1); + } + if (opt.target !== null && steady > opt.target) { + console.log(`CHURN_FAIL: steady state ${steady.toFixed(2)}x is above the ${opt.target}x target`); + process.exit(1); + } + console.log('CHURN_OK'); +} + +main().catch((e) => { + console.error('CHURN_FAIL', e); + console.log('--- server log tail ---'); + console.log(serverLog.split('\n').slice(-40).join('\n')); + process.exit(1); +});