diff --git a/docs/TOOLS.md b/docs/TOOLS.md index 49fa5d1e7..37c30e745 100644 --- a/docs/TOOLS.md +++ b/docs/TOOLS.md @@ -372,6 +372,8 @@ scripts/stack-release.sh pm-on BUSINESS [--timeout S] scripts/stack-release.sh rollback BUSINESS [--restore ACTIVATION [--events N]] [--timeout S] [--plan] scripts/stack-release.sh status BUSINESS common options: --copies DIR, --bin DIR +--events N is the total of the per-table counts the post-backup-events refusal prints: events and +every table in COUNTED. ``` This is an operator plan, not an action agents run. Both reviews and the @@ -433,10 +435,13 @@ refuses `capture-failed` before it stops anything. Adopt uses the same rule. Jason or Mos settles it from the rollback set the message names. 7. `rollback BUSINESS` returns to the copy before the pointer's, taken from the log. When the schemas differ it needs `--restore ACTIVATION`, with or - without a `-1` to `-9` suffix; events - written after that backup need `--events N` with the count it prints, and - Jason decides first. It refuses `business-unreadable` and - `unknown-kind-for-target` like `activate`. For the second, set each kind + without a `-1` to `-9` suffix. Rows written after that backup need + `--events N`, and Jason decides first. The count covers events and every + table in `COUNTED` (row 181), the tables a bus writer fills without an + event. The `post-backup-events` refusal prints one count per table with + rows, in that order, for example `1 event(s), 1 instance_names row(s)`. + N is the total of those printed counts, read off the refusal. It refuses + `business-unreadable` and `unknown-kind-for-target` like `activate`. For the second, set each kind it names to `null` through the live bus first, with the `plugins set` command in step 2 of the next section. 8. Jason's plain `mosaic talk pm "..."` must print sent and a reply. Keep the diff --git a/packages/cli/tests/stack-release.test.mjs b/packages/cli/tests/stack-release.test.mjs index c7d9478c9..19ee850e9 100644 --- a/packages/cli/tests/stack-release.test.mjs +++ b/packages/cli/tests/stack-release.test.mjs @@ -134,6 +134,14 @@ function systemctl(){ if(isBus(u)){ // One-shot: the stop leaves an empty -wal or -shm beside the store, as an unclean close would. for(const [name,ext] of [['stop-leaves-wal','-wal'],['stop-leaves-shm','-shm']])if(fault(name)){fs.rmSync(faultFile(name));fs.writeFileSync(path.join(data,'bus','bus.sqlite'+ext),'')} + // One-shot (T45): the stop writes one row after any STAMP into the table the fault names, as a + // write the bus made between rollback's count and its stop would. The close leaves no -wal. + if(fault('stop-writes-row')){ + const t=fs.readFileSync(faultFile('stop-writes-row'),'utf8');fs.rmSync(faultFile('stop-writes-row')); + const db=new (process.getBuiltinModule('node:sqlite').DatabaseSync)(path.join(data,'bus','bus.sqlite')); + db.exec(`CREATE TABLE IF NOT EXISTS ${t} (seq INTEGER PRIMARY KEY, at TEXT NOT NULL)`); + db.prepare(`INSERT INTO ${t} (at) VALUES (?)`).run('2999-01-01T00:00:00.000Z');db.close(); + } snap('stop'); } process.exit(0); @@ -1197,3 +1205,84 @@ test('T44 row 180 item 2: --plan lists tester-port-invalid and tester-port-targe await refused(e,['activate',A,'acme','--tester-port','7333'],'tester-port-target',`${A}'s Console does not support --tester-port`); }); }); + +// Row 181 (#1679, P19 390): COUNTED and STORE_JS as the script under test has them. The fixture +// tables carry only seq and at, which is all the count reads. +const srText=readFileSync(SR,'utf8'); +const COUNTED=/^COUNTED="([^"]*)"$/m.exec(srText)[1].split(' '); +const STORE_JS=/^STORE_JS='([\s\S]*?)'$/m.exec(srText)[1]; +// sage-1163's list 2, written out so that a table dropped from the script's COUNTED fails T45 as +// well as T46. +const LISTED=['role_claims','thread_claims','decision_events','messages','deliveries','task_snapshots','projects','threads','thread_opens','instance_names','usage_records']; +const LATE='2999-01-01T00:00:00.000Z'; +const addRow=(file,table,at=LATE)=>{const db=new DatabaseSync(file);db.exec(`CREATE TABLE IF NOT EXISTS ${table} (seq INTEGER PRIMARY KEY, at TEXT NOT NULL)`);db.prepare(`INSERT INTO ${table} (at) VALUES (?)`).run(at);db.close()}; + +test('T45 row 181 items 2 and 3: the restore guard counts events and every COUNTED table',async(t)=>{ + await t.test('both modes count events and each listed table, and a table the store lacks counts 0',async(t)=>{ + const d=mkdtempSync(join(tmpdir(),'sr181-'));t.after(()=>rmSync(d,{recursive:true,force:true})); + const stamp='2020-01-01T00:00:00.000Z',count=(f,mode)=>execFileSync(NODE,['-e',STORE_JS,'--',mode,f,stamp,COUNTED.join(' ')],{encoding:'utf8'}); + const store=(name,rows,tables=rows)=>{ + const f=join(d,name);for(const x of ['events',...tables])addRow(f,x,'2000-01-01T00:00:00.000Z');for(const x of rows)addRow(f,x);return f; + }; + const both=(f,want)=>{const s=sha(f);for(const mode of ['count','heldcount'])assert.equal(count(f,mode),want,`${basename(f)} ${mode}`);assert.equal(sha(f),s);assert.deepEqual(readdirSync(d).filter((n)=>n.startsWith(`${basename(f)}-`)),[])}; + for(const x of LISTED)both(store(`${x}.sqlite`,['events',x]),`2\t1 event(s), 1 ${x} row(s)\n`); + both(store('brief.sqlite',['events','usage_records','instance_names']),'3\t1 event(s), 1 instance_names row(s), 1 usage_records row(s)\n'); + // A 3f store: no usage_records table, and nothing to refuse. + both(store('3f.sqlite',['events'],['events','instance_names']),'1\t1 event(s)\n'); + both(store('none.sqlite',[],['instance_names']),'0\t0 event(s)\n'); + }); + for(const x of ['instance_names','usage_records'])await t.test(`one ${x} row and no event refuses before any stop; --events 1 restores`,async(t)=>{ + const e=await mk(t);await seed(e); + assert.equal((await run(e,'activate',C,'acme','--migrate')).code,0);const act=pointer(e).activation; + addRow(e.store,x); + const want=`stack-release: refusing post-backup-events: 0 event(s), 1 ${x} row(s) were written after the backup; Jason decides, then --events 1\n`; + for(const extra of [[],['--events','2']]){ + const before=fp(e),n=calls(e).length,r=await run(e,'rollback','acme','--restore',act,...extra); + assert.equal(r.code,3,extra.join(' '));assert.equal(r.err,want);assert.deepEqual(fp(e),before);assert.deepEqual(startsStops(e,n),[]); + } + const r=await run(e,'rollback','acme','--restore',act,'--events','1');assert.equal(r.code,0,r.out+r.err); + assert.ok(r.out.includes(`; 0 event(s), 1 ${x} row(s) were written after the backup\n`),r.out); + assert.deepEqual([pointer(e).copy,pointer(e).schema],[B,'3g']);assert.equal(sha(e.store),backupSum(e,act)); + }); + await t.test('a listed table that cannot be read refuses restore-mismatch before any stop',async(t)=>{ + const e=await mk(t);await seed(e); + assert.equal((await run(e,'activate',C,'acme','--migrate')).code,0);const act=pointer(e).activation; + const stamp=readFileSync(join(e.data,'backups','stack',act,'STAMP'),'utf8').replace(/\n+$/,''); + const db=new DatabaseSync(e.store);db.exec('CREATE TABLE usage_records (seq INTEGER PRIMARY KEY)');db.close(); + const before=fp(e),n=calls(e).length,r=await run(e,'rollback','acme','--restore',act); + assert.equal(r.code,3,r.out+r.err);assert.ok(r.err.endsWith(`stack-release: refusing restore-mismatch: cannot count the rows after ${stamp}\n`),r.err); + assert.deepEqual(fp(e),before);assert.deepEqual(startsStops(e,n),[]);assert.equal(logLines(e).at(-1).code,'restore-mismatch'); + }); + await t.test('the in-run recount counts the listed tables too',async(t)=>{ + const e=await mk(t);await seed(e); + assert.equal((await run(e,'activate',C,'acme','--migrate')).code,0);const act=pointer(e).activation; + fault(e,'stop-writes-row','thread_opens'); + const r=await run(e,'rollback','acme','--restore',act);assert.equal(r.code,1,r.out+r.err); + assert.equal(r.err,rolledBack('post-backup-events',C)); + assert.ok(r.out.includes('; 0 event(s) were written after the backup\n'),r.out); + assert.deepEqual([pointer(e).copy,pointer(e).schema],[C,'3h']);assert.equal(posts(e).length,0); + const l=logLines(e).at(-1);assert.deepEqual([l.result,l.code,l.rollback],['gate-failed','post-backup-events','ok']); + }); +}); + +test('T46 row 181 item 4: every table in the bus schema is in exactly one of four lists',()=>{ + // The schema a target copy's store gets. Lists 1 and 2 come from the script, so a table added to + // COUNTED or dropped from it shows here. Row 181's BUILD.md names each writer. + const db=new DatabaseSync(':memory:');db.exec(readFileSync(join(ROOT,'packages','bus','schema.sql'),'utf8')); + const tables=db.prepare("SELECT name FROM sqlite_master WHERE type='table' ORDER BY name").all().map((r)=>r.name); + const hasAt=(n)=>db.prepare(`SELECT count(*) AS n FROM pragma_table_info(?) WHERE name='at'`).get(n).n===1; + const always={decisions:'decision.raise writes action.allowed in the same transaction'}; + const untimed={ + meta:'key and value only; its one UPDATE is the migration step', + message_threads:'no time column; each row goes with a messages row, which is counted', + sqlite_sequence:'SQLite\'s own AUTOINCREMENT table', + task_comment_cursors:'no time column; a restore drops its advances uncounted (BUILD.md)', + }; + const lists=[['events'],COUNTED,Object.keys(always),Object.keys(untimed)],all=lists.flat(); + assert.equal(new Set(all).size,all.length,`a table is in two lists: ${all.filter((n,i)=>all.indexOf(n)!==i)}`); + assert.deepEqual(tables.filter((n)=>!all.includes(n)),[],'tables in no list'); + assert.deepEqual(all.filter((n)=>!tables.includes(n)),[],'listed tables the schema lacks'); + for(const n of lists.slice(0,3).flat())assert.ok(hasAt(n),`${n} has at`); + for(const n of lists[3])assert.ok(!hasAt(n),`${n} has no at`); + db.close(); +}); diff --git a/scripts/stack-release.sh b/scripts/stack-release.sh index f70295e99..7b2381d45 100755 --- a/scripts/stack-release.sh +++ b/scripts/stack-release.sh @@ -36,6 +36,8 @@ usage: stack-release.sh adopt BUSINESS stack-release.sh rollback BUSINESS [--restore ACTIVATION [--events N]] [--timeout S] [--plan] stack-release.sh status BUSINESS common options: --copies DIR, --bin DIR +--events N is the total of the per-table counts the post-backup-events refusal prints: events and +every table in COUNTED. USAGE exit "${1:-4}" } @@ -288,16 +290,32 @@ plugin_checks() { # --- The store --- +# Row 181: the tables a bus writer fills without an event in the same transaction, in schema +# order. A restore drops their rows after STAMP as it drops events, so the guard counts them too. +# BUILD.md for row 181 names each writer; the T46 guard classifies every table in the schema. +COUNTED="role_claims thread_claims decision_events messages deliveries task_snapshots projects threads thread_opens instance_names usage_records" + STORE_JS=' const {DatabaseSync}=require("node:sqlite");const {pathToFileURL}=require("node:url"); -const [mode,file,stamp]=process.argv.slice(1); +const [mode,file,stamp,tables=""]=process.argv.slice(1); // immutable=1 on a stopped store with no -wal or -shm: it creates no file and leaves the main // file mtime and sha256 as they were (the row 162 probe). A plain readOnly open of a stopped // WAL store creates -shm and -wal, so it is used only on a store the running bus holds. const db=mode.startsWith("held")?new DatabaseSync(file,{readOnly:true}):new DatabaseSync(pathToFileURL(file).href+"?immutable=1",{readOnly:true}); try{ if(mode.endsWith("version"))process.stdout.write(db.prepare("SELECT value FROM meta WHERE key=?").get("schema_version").value+"\n"); - else process.stdout.write(db.prepare("SELECT count(*) AS n FROM events WHERE at > ?").get(stamp).n+"\n"); + else{ + // "TOTALTEXT": events, then each listed table with rows after STAMP, in list order. A + // listed table the store lacks counts 0 (no instance_names before 3g, no usage_records before + // 3h). One that is there but cannot be read throws, as a failed events count does. + const ev=db.prepare("SELECT count(*) AS n FROM events WHERE at > ?").get(stamp).n;let total=ev,text=ev+" event(s)"; + for(const t of tables.split(" ").filter(Boolean)){ + if(!db.prepare("SELECT 1 FROM sqlite_master WHERE type=? AND name=?").get("table",t))continue; + const n=db.prepare("SELECT count(*) AS n FROM "+t+" WHERE at > ?").get(stamp).n; + if(n){total+=n;text+=", "+n+" "+t+" row(s)"} + } + process.stdout.write(total+"\t"+text+"\n"); + } }finally{db.close()}' # Sets UNCLEAN and returns 0 when a -wal or -shm sits beside the store. An immutable read would @@ -310,8 +328,8 @@ store_unclean() { done return 1 } -# A read of the stopped store: version, or count STAMP. Call store_unclean first. -store_read() { node -e "$STORE_JS" -- "$1" "$STORE" "${2:-}"; } +# A read of the stopped store: version, or count STAMP TABLES. Call store_unclean first. +store_read() { node -e "$STORE_JS" -- "$1" "$STORE" "${2:-}" "${3:-}"; } # No writer.lock, and no process with a file open under /bus/ (stopped-check.sh's # test). One find over the /proc fd links, not a readlink per link: this host has about 16,000. @@ -824,8 +842,8 @@ run_steps() { [ "$STORE_SCHEMA" = "$P_SCHEMA" ] || rollback_in_run store-differs if [ -n "$RESTORE" ]; then local n - n="$(store_read count "$(cat "$DATA/backups/stack/$RESTORE/STAMP")")" || rollback_in_run schema-unreadable - [ "$n" = "$COUNT" ] || rollback_in_run post-backup-events + n="$(store_read count "$(cat "$DATA/backups/stack/$RESTORE/STAMP")" "$COUNTED")" || rollback_in_run schema-unreadable + [ "${n%%$'\t'*}" = "$COUNT" ] || rollback_in_run post-backup-events restore_store "$RESTORE" || after_fail restore fi fi @@ -880,22 +898,23 @@ do_rollback() { [ "$P_SCHEMA" = "$T_SCHEMA" ] || [ -n "$RESTORE" ] || refuse schema-differs "the store is at $P_SCHEMA and $TO expects $T_SCHEMA; pass --restore ACTIVATION" new_activation if [ -n "$RESTORE" ]; then - local o="$DATA/backups/stack/$RESTORE" rc=0 + local o="$DATA/backups/stack/$RESTORE" rc=0 c="" text [ -f "$o/SHA256SUMS" ] && [ "$(cat "$o/DATA_ROOT" 2>/dev/null)" = "$DATA" ] && [ "$(cat "$o/SCHEMA" 2>/dev/null)" = "$T_SCHEMA" ] && [ -f "$o/STAMP" ] \ || refuse restore-mismatch "$o is not a backup of this root at $T_SCHEMA" # Before anything stops. A store the running bus holds is read with readOnly, which adds # no file (the probe); a stopped one falls under the store_unclean rule. if systemctl --user is-active --quiet "$BUS_UNIT"; then - COUNT="$(node -e "$STORE_JS" -- heldcount "$STORE" "$(cat "$o/STAMP")")" || rc=1 + c="$(node -e "$STORE_JS" -- heldcount "$STORE" "$(cat "$o/STAMP")" "$COUNTED")" || rc=1 # plan_store's recheck (row 166 item 2), before anything stops. systemctl --user is-active --quiet "$BUS_UNIT" || refuse restore-mismatch "the bus stopped while the events after $(cat "$o/STAMP") were counted, so the store state changed; nothing was stopped" else ! store_unclean || refuse store-unclean "$UNCLEAN is present; the bus did not close the store cleanly" - COUNT="$(store_read count "$(cat "$o/STAMP")")" || rc=1 + c="$(store_read count "$(cat "$o/STAMP")" "$COUNTED")" || rc=1 fi - [ "$rc" = 0 ] || refuse restore-mismatch "cannot count the events after $(cat "$o/STAMP")" - echo "restore: $o; the store now in place moves to $POST and is kept; $COUNT event(s) were written after the backup" - [ "$COUNT" = 0 ] || [ "$EVENTS" = "$COUNT" ] || refuse post-backup-events "$COUNT event(s) were written after the backup; Jason decides, then --events $COUNT" + [ "$rc" = 0 ] || refuse restore-mismatch "cannot count the rows after $(cat "$o/STAMP")" + COUNT="${c%%$'\t'*}" text="${c#*$'\t'}" + echo "restore: $o; the store now in place moves to $POST and is kept; $text were written after the backup" + [ "$COUNT" = 0 ] || [ "$EVENTS" = "$COUNT" ] || refuse post-backup-events "$text were written after the backup; Jason decides, then --events $COUNT" BACKUP="$RESTORE" fi run_steps restore