Oregami
Repositories/oxedyne/daimond

oxedyne/daimond/dev/verify_pausesync.mjs

21.4 KiB, 1 run

created by r2519314175:581, which is this file's identity for as long as the history lasts, whatever it is later renamed to

download · who wrote it · its history

1// verify_pausesync.mjs — the pause tree travels between devices, and carrying it
2// does not turn the sync into a loop.
3//
4// Two properties, and the second is the dangerous one.
5//
6// TRAVELS. What may spend is a fact about the ACCOUNT, not about the browser it
7// was set in. A Diamond paused on the laptop that spends freely on the phone is
8// the control not working, so the pause tree rides in the sync parcel: sync.js
9// hangs `DaimondPause.snapshot()` on what `collectSync()` gathers, and feeds
10// what arrives to `DaimondPause.adopt()`.
11//
12// DOES NOT LOOP. `push()` skips the wire only when the parcel byte-matches what
13// it LAST SENT -- never what it last received (`www/js/sync.js`). So a section
14// that differs between two collects, or that rewrites itself on the way in,
15// makes the device permanently have news: A pushes, B merges, B now differs, B
16// pushes, A merges, and round it goes at about a second a lap with neither
17// device doing anything wrong. That has happened here twice; the second time it
18// was reported from an iPhone freshly paired by QR.
19//
20// `dev/verify_parcelstable.mjs` pins the same property on the core parcel and
21// `dev/verify_pausecore.mjs` pins the pure merge. Neither can see this: the
22// former compares `DaimondCore.collectSync()`, which does not carry what sync.js
23// hangs on it, and the latter never packs a parcel. So the checks here go
24// through `DaimondSync.parcel()` and `DaimondSync.apply()` -- the very functions
25// `push()` and `pull()` use -- and the merge checks are only the ones that need
26// a page or a second device.
27//
28// AND THE ONE VERIFY_SYNC §12 NEVER MADE. That section drives two real paired
29// profiles and asserts the CONTENT converges. It never asserts the mailbox
30// version stops moving, so an unbounded push loop passes it green: content
31// converges on every lap of the loop. §D below leaves both devices idle and
32// requires the version to sit still. It belongs in §12; it is here because
33// verify_sync.mjs is not this agent's to edit.
34//
35// node dev/verify_pausesync.mjs
36//
37// SECTION D's PRO CHECK WAS REPORTED INTERMITTENT and could not be reproduced:
38// 13 runs in world 7 on 2026-08-21 — 7 as it stood, 6 after the changes below,
39// one of them deliberately timed so the licence was asked for in the middle of a
40// console rollup walk, when the gateway store answers a prefix scan not at all —
41// and every one of them said pro=true. So nothing here is a fix for it. What is
42// here is the two things that were missing to say WHY it failed, next time it
43// does: `refreshLicence()` returns null the moment `state.authed` is false and
44// swallows every other failure into the same null, so one unanswered read and an
45// account that genuinely holds nothing arrive identically. The session is now a
46// precondition of its own, the read is asked again rather than trusted once, and
47// the raw `/api/licence` reply is printed when it still says no.
48//
49// Sections A-C need dev/serve.mjs only (DAIMOND_PORT, default 8777).
50// Section D needs a gateway on :9002 as well, and SKIPS with a line rather than
51// failing when there is none -- :9002 holds one account store and is shared.
52import fs from 'node:fs';
53import path from 'node:path';
54import { fileURLToPath } from 'node:url';
55import { open, signInAs, scratch } from './harness.mjs';
56import { makePagePro } from './pro.mjs';
57import { GW_PORT, GW_URL as GWURL } from './ports.mjs';
58
59const HERE = path.dirname(fileURLToPath(import.meta.url));
60const GWDIR = path.resolve(HERE, '..', 'gateway');
61
62let bad = 0, skipped = 0;
63const check = (pass, name, detail) => {
64 if (!pass) bad++;
65 console.log((pass ? ' ok ' : ' FAIL ') + name + (detail ? ' — ' + detail : ''));
66};
67const skip = (name, why) => { skipped++; console.log(' SKIP ' + name + ' — ' + why); };
68const sleep = ms => new Promise(r => setTimeout(r, ms));
69
70/// Which top-level sections of two parcels differ, and which fields inside them.
71/// "The parcel differs" is not a finding anybody can act on.
72function differences(a, b) {
73 const out = [];
74 const keys = [...new Set([...Object.keys(a || {}), ...Object.keys(b || {})])].sort();
75 for (const k of keys) {
76 const x = JSON.stringify(a ? a[k] : undefined);
77 const y = JSON.stringify(b ? b[k] : undefined);
78 if (x === y) continue;
79 out.push(`${k}(${String(x).slice(0, 60)} → ${String(y).slice(0, 60)})`);
80 }
81 return out;
82}
83
84/// Is a gateway answering on :9002? Section D is the only part that needs one,
85/// and :9002 is shared -- so this asks rather than assuming, and never starts one.
86async function gatewayUp() {
87 try {
88 const r = await fetch(GWURL + '/api/health', { signal: AbortSignal.timeout(2000) });
89 return r.ok;
90 } catch (e) { return false; }
91}
92
93// Two leaf ids that no tree in the app has to know about: `DaimondPause.set`
94// falls back to treating an unknown id as a leaf, which is precisely the shape
95// of the thing this is about -- one node that may or may not spend.
96const LEAF_A = 'root/diamonds/pausesync-a/self';
97const LEAF_B = 'root/diamonds/pausesync-b/self';
98
99const PROFILE = scratch('pw', 'pausesync');
100fs.rmSync(PROFILE, { recursive: true, force: true });
101
102const s = await open({ name: 'pausesync', profile: PROFILE, defaults: false });
103const { page } = s;
104let child = null;
105
106try {
107 await page.waitForFunction(
108 () => !!(window.DaimondSync && DaimondSync.parcel && window.DaimondPause
109 && window.DaimondCore && DaimondCore.collectSync),
110 null, { timeout: 15000 });
111 await page.waitForTimeout(800);
112
113 const parcel = () => page.evaluate(() => DaimondSync.parcel());
114
115 // ── A. The parcel carries it, and carrying it is stable ─────────
116 // Order matters: an empty pause section is stable for the trivial reason
117 // that there is nothing in it, so the pauses go on FIRST and every check
118 // below runs with a non-empty set.
119 await page.evaluate((ids) => {
120 DaimondPause.set(ids.a, false); // false = paused
121 DaimondPause.set(ids.b, false);
122 }, { a: LEAF_A, b: LEAF_B });
123
124 const p1 = await parcel();
125 const carried = (p1.pause && p1.pause.paused) || [];
126 check(carried.length === 2 && carried.indexOf(LEAF_A) !== -1 && carried.indexOf(LEAF_B) !== -1,
127 'the parcel carries the paused leaves', JSON.stringify(p1.pause));
128 check(!!(p1.pause && p1.pause.stamp > 0),
129 'and a stamp that says when the set last moved', String(p1.pause && p1.pause.stamp));
130 // Everything below reads `parcel.pause`. A build that carries no such section
131 // must say so in one line rather than throwing a TypeError over the top of
132 // the two checks that just named the real fault.
133 if (!p1.pause) throw new Error('no `pause` section in the parcel — nothing below can be measured');
134
135 // A gap between the two, because a stamp taken at collect time with second
136 // resolution sits still inside one millisecond and moves inside two.
137 await page.waitForTimeout(2500);
138 const p2 = await parcel();
139 const drift = differences(p1, p2);
140 check(drift.length === 0, 'two collects with pauses set are byte-identical', drift.join(' '));
141
142 // ── B. The fixed point ──────────────────────────────────────────
143 // Apply this device's OWN parcel. Nothing in it is news, so what it would
144 // send next must be exactly what it just took in. This is the check the
145 // loop is made of: a section that stamps on apply passes A and fails here.
146 const failedOwn = await page.evaluate(p => DaimondSync.apply(p), p2);
147 check(failedOwn.indexOf('pause') === -1, 'applying its own parcel does not fail the pause section',
148 failedOwn.join(','));
149 await page.waitForTimeout(600);
150 const p3 = await parcel();
151 const fixed = differences(p2, p3);
152 check(fixed.length === 0, 'and leaves the next parcel unchanged (the fixed point)',
153 fixed.join(' '));
154
155 // A parcel that IS news, from a device whose stamp is later. The record wins
156 // whole -- and this device must then send back exactly what it received, not
157 // a restamped copy of it. A restamp here is the `touchSelfDevice` bug.
158 // `Number(...)`, never `| 0`: a millisecond stamp is well past 2^31, and
159 // truncating it to 32 bits makes the "later" record the earlier one. The
160 // check below caught that when this file did it.
161 const NEWS = { paused: [LEAF_B, 'root/mail/someone%40example.com/INBOX'].sort(),
162 stamp: Number(p3.pause.stamp) + 60000 };
163 await page.evaluate(async (arg) => {
164 const p = await DaimondSync.parcel();
165 p.pause = arg.news;
166 await DaimondSync.apply(p);
167 }, { news: NEWS });
168 const p4 = await parcel();
169 check(JSON.stringify(p4.pause) === JSON.stringify(NEWS),
170 'a later record is adopted whole, and sent back unrestamped', JSON.stringify(p4.pause));
171 await page.waitForTimeout(1200);
172 const p5 = await parcel();
173 check(differences(p4, p5).length === 0, 'and the parcel is still a fixed point after adopting news',
174 differences(p4, p5).join(' '));
175
176 // A resume, which is the direction a union merge gets wrong. The other
177 // device un-paused everything at a later stamp; a merge that unioned would
178 // keep this device's leaves paused for ever and no resume would ever travel.
179 const RESUMED = { paused: [], stamp: NEWS.stamp + 60000 };
180 await page.evaluate(async (arg) => {
181 const p = await DaimondSync.parcel();
182 p.pause = arg.rec;
183 await DaimondSync.apply(p);
184 }, { rec: RESUMED });
185 const stillPaused = await page.evaluate(ids => ({
186 a: DaimondPause.isPaused(ids.a), b: DaimondPause.isPaused(ids.b),
187 }), { a: LEAF_A, b: LEAF_B });
188 check(stillPaused.a === false && stillPaused.b === false,
189 'a resume at a later stamp travels — the merge is not a union',
190 JSON.stringify(stillPaused));
191
192 // An equal stamp errs the other way, towards paused, and the device then has
193 // news EXACTLY ONCE: the union is a fixed point of the next collect.
194 await page.evaluate((ids) => { DaimondPause.set(ids.a, false); }, { a: LEAF_A });
195 const eqBase = await parcel();
196 const EQUAL = { paused: [LEAF_B], stamp: eqBase.pause.stamp };
197 await page.evaluate(async (arg) => {
198 const p = await DaimondSync.parcel();
199 p.pause = arg.rec;
200 await DaimondSync.apply(p);
201 }, { rec: EQUAL });
202 const p6 = await parcel();
203 check(JSON.stringify(p6.pause.paused) === JSON.stringify([LEAF_A, LEAF_B].sort()),
204 'two records at the same stamp merge to the union', JSON.stringify(p6.pause.paused));
205 await page.evaluate(p => DaimondSync.apply(p), p6);
206 await page.waitForTimeout(600);
207 const p7 = await parcel();
208 check(differences(p6, p7).length === 0,
209 'and the union settles in one round rather than oscillating',
210 differences(p6, p7).join(' '));
211
212 // ── C. Across a reload ──────────────────────────────────────────
213 // A device that restarts and immediately has something to send pushes on
214 // every launch: the same loop with a slower clock.
215 await page.reload({ waitUntil: 'domcontentloaded' });
216 // Unlocked again, because a reload locks the identity and section D needs a
217 // key to seal a parcel with. The pause set is read from localStorage either
218 // way, so this does not soften the check -- it makes it a device that has
219 // really been picked up again rather than one sitting at its gate.
220 await signInAs(s, 'pausesync');
221 await page.waitForFunction(() => !!(window.DaimondSync && DaimondSync.parcel),
222 null, { timeout: 15000 });
223 await page.waitForTimeout(1500);
224 const p8 = await parcel();
225 check(JSON.stringify(p8.pause) === JSON.stringify(p7.pause),
226 'a reload does not change the pause section this device would send',
227 JSON.stringify(p8.pause) + ' vs ' + JSON.stringify(p7.pause));
228
229 // ── D. Two real devices, and a version that stops moving ────────
230 if (!(await gatewayUp())) {
231 skip('two real devices converge, both ways', `no gateway on :${GW_PORT}`);
232 skip('the mailbox version stops moving when both devices are idle', `no gateway on :${GW_PORT}`);
233 } else {
234 // THE GATEWAY SESSION FIRST, AND ASKED FOR RATHER THAN ASSUMED.
235 //
236 // `makePagePro` mints the licence at the gateway and then asks the PAGE
237 // whether it holds it, through `DaimondGateway.refreshLicence()` -- whose
238 // first line is `if (!state.authed) { state.pro = null; return null; }`
239 // (www/js/gateway.js). The session follows the unlock, not the page load,
240 // and section C above has just reloaded and signed in again; ask a beat
241 // too early and the webhook says 200 while the page says pro=false, which
242 // is the shape this file was failing in and it is not about Pro at all.
243 // The mate device below already waits for exactly this state; this device
244 // never did.
245 const tAuth = Date.now();
246 const authed = await page.waitForFunction(
247 () => !!(window.DaimondGateway && DaimondGateway.state().authed),
248 null, { timeout: 20000 }).then(() => true).catch(() => false);
249 check(authed, 'this device holds a gateway session before Pro is asked for',
250 authed ? `waited ${Date.now() - tAuth} ms`
251 : 'DaimondGateway.state().authed never became true in 20 s');
252
253 const lic = await makePagePro(page, GWDIR, GWURL);
254
255 // ASKING AGAIN IS NOT THE SAME AS LOWERING THE BAR.
256 //
257 // `makePagePro` asks the page once, through `refreshLicence()`, which
258 // swallows EVERY failure into `pro = null`: a gateway that could not answer
259 // and an account that holds nothing arrive here as the same false. One
260 // unanswered read is not evidence that the licence was not issued -- the
261 // webhook's own 200 is that evidence, since a grant that fails is answered
262 // 500 and left unmarked for Stripe to retry (gateway/src/handlers/webhook.rs).
263 // So the page is asked until it has a definite answer or the budget is out,
264 // and a licence that was genuinely never issued still fails: the gateway
265 // answers `held:false` every time and this runs out and says so.
266 let pro = lic.pro === true, waited = 0;
267 const tPro = Date.now();
268 while (!pro && Date.now() - tPro < 20000) {
269 await sleep(1000);
270 pro = await page.evaluate(async () => {
271 try { return !!(await DaimondGateway.refreshLicence()); }
272 catch (e) { return false; }
273 });
274 waited = Date.now() - tPro;
275 }
276
277 // WHAT THE GATEWAY ITSELF SAYS, when the page still says no. Read raw, so
278 // the failure line names which of the two it was -- a store that could not
279 // answer, or a licence that is not there -- rather than leaving the reader
280 // to reproduce it by hand. A store timing out is defect Y, and it belongs
281 // to o3db, not to sync.
282 let why = `webhook ${lic.status}, pro=${pro}`
283 + (waited ? `, after ${waited} ms of asking` : '');
284 if (!pro) {
285 const raw = await page.evaluate(async () => {
286 try {
287 const r = await fetch('/api/licence', { credentials: 'same-origin' });
288 return r.status + ' ' + (await r.text()).slice(0, 160);
289 } catch (e) { return 'threw ' + String(e && e.message); }
290 });
291 why += `, GET /api/licence -> ${raw}`;
292 }
293 check(pro, 'the account holds Pro, so sync may run at all', why);
294
295 // A second REAL device on its own profile, paired in as verify_sync §12
296 // does it. Two windows both open and both focused is the case that broke
297 // in the field; nothing below touches either window.
298 child = await open({ name: 'pausemate', signIn: false, connect: false });
299 await child.page.waitForFunction(() => !!window.DaimondPairing, null, { timeout: 15000 })
300 .catch(() => {});
301 const code = await page.evaluate(() => DaimondPairing.create());
302 await child.page.evaluate(c => DaimondPairing.redeem(c), code.code);
303 await child.page.reload({ waitUntil: 'domcontentloaded' });
304 await signInAs(child, 'pausesync');
305 await child.page.waitForFunction(
306 () => !!window.DaimondSync && window.DaimondGateway && DaimondGateway.state().authed,
307 null, { timeout: 15000 }).catch(() => {});
308 const mine = await page.evaluate(() => DaimondIdentity.publicKeyB64url());
309 const mate = await child.page.evaluate(() => ({
310 authed: DaimondGateway.state().authed, same: DaimondIdentity.publicKeyB64url(),
311 }));
312 check(mate.authed === true && mate.same === mine,
313 'a second REAL device holds the same account and an authed session',
314 JSON.stringify(mate).slice(0, 80));
315
316 /// Push until the mailbox version actually advances. One `push()` call
317 /// proves nothing: one that finds the app busy or a round in flight only
318 /// reschedules and returns.
319 const pushLanded = async (pg) => pg.evaluate(async () => {
320 const v0 = DaimondSync.state().version;
321 const t0 = Date.now();
322 while (DaimondSync.state().version <= v0 && Date.now() - t0 < 10000) {
323 await DaimondSync.push();
324 await new Promise(r => setTimeout(r, 200));
325 }
326 return DaimondSync.state().version;
327 });
328
329 // Bring both devices onto one shared base, and quiesce the mate: whatever
330 // it would send, it has already sent. That is the state every idle device
331 // is in, and the state §D's last check measures.
332 await pushLanded(page);
333 await child.page.evaluate(() => DaimondSync.pull());
334 await pushLanded(child.page);
335 await page.evaluate(() => DaimondSync.pull());
336 await page.evaluate(() => DaimondSync.push());
337 await sleep(800);
338 await child.page.evaluate(() => DaimondSync.push());
339 await sleep(800);
340
341 const pausedOn = (pg, id) => pg.evaluate(x => DaimondPause.isPaused(x), id);
342
343 // (D1) This device pauses a leaf. The other one learns it.
344 const LIVE = 'root/diamonds/pausesync-live/self';
345 await page.evaluate(x => DaimondPause.set(x, false), LIVE);
346 await pushLanded(page);
347 await child.page.evaluate(() => DaimondSync.pull());
348 check(await pausedOn(child.page, LIVE) === true,
349 'a pause set on one device arrives paused on the other');
350
351 // (D2) And the other one resumes it, which is the direction that matters:
352 // a merge that unioned would leave this device paused for ever.
353 await child.page.evaluate(x => DaimondPause.set(x, true), LIVE);
354 await pushLanded(child.page);
355 await page.evaluate(() => DaimondSync.pull());
356 check(await pausedOn(page, LIVE) === false,
357 'and a resume on the other device travels back — not swallowed by a union');
358
359 // (D3) THE ASSERTION §12 NEVER MADE.
360 //
361 // Once both devices are idle and agreed, the mailbox version must sit
362 // still. If it climbs, the two are pushing at each other -- which is what
363 // the iPhone did, and which every convergence check in verify_sync passes
364 // happily, because content converges on every lap of the loop.
365 //
366 // Nothing is done to either window: no focus, no reload, no event. What
367 // runs is the engine's own scheduling, which is exactly what ran in the
368 // field.
369
370 /// Wait until the version has been unchanged on BOTH devices for
371 /// `quietMs`, and say whether it ever was.
372 ///
373 /// The pause that just travelled schedules one more push behind a 2.5s
374 /// debounce, so a measurement started the instant D2 returns catches a
375 /// straggler and reports a loop that is not there. Waiting for quiet is
376 /// not softening the check: a build that really loops never goes quiet,
377 /// so this arm fails first and says how long it watched.
378 const settle = async (quietMs, capMs) => {
379 const read = async () => [
380 await page.evaluate(() => DaimondSync.state().version),
381 await child.page.evaluate(() => DaimondSync.state().version),
382 ].join('/');
383 let last = '', since = Date.now();
384 const t0 = Date.now();
385 while (Date.now() - t0 < capMs) {
386 const v = await read();
387 if (v !== last) { last = v; since = Date.now(); }
388 else if (Date.now() - since >= quietMs) return { quiet: true, v: last, took: Date.now() - t0 };
389 await sleep(1000);
390 }
391 return { quiet: false, v: last, took: Date.now() - t0 };
392 };
393 const settled = await settle(5000, 40000);
394 check(settled.quiet === true,
395 'the account goes quiet after a pause has travelled both ways',
396 `versions ${settled.v} after ${Math.round(settled.took / 1000)}s`);
397
398 // And then STAYS quiet. Fifteen seconds is many laps of a one-second loop.
399 const v0 = { a: await page.evaluate(() => DaimondSync.state().version),
400 b: await child.page.evaluate(() => DaimondSync.state().version) };
401 await sleep(15000);
402 const v1 = { a: await page.evaluate(() => DaimondSync.state().version),
403 b: await child.page.evaluate(() => DaimondSync.state().version) };
404 check(v1.a === v0.a && v1.b === v0.b,
405 'the mailbox version stops moving when both devices are idle',
406 `this ${v0.a}→${v1.a}, mate ${v0.b}→${v1.b}`);
407
408 // And they still agree afterwards: a version that sat still because sync
409 // had quietly died would pass the check above for the wrong reason.
410 const agree = {
411 mine: await page.evaluate(() => DaimondSync.parcel().then(p => JSON.stringify(p.pause))),
412 mate: await child.page.evaluate(() => DaimondSync.parcel().then(p => JSON.stringify(p.pause))),
413 };
414 check(agree.mine === agree.mate,
415 'and the two devices hold the same pause tree at the end of it',
416 agree.mine + ' vs ' + agree.mate);
417 // And neither of them is stuck: a version that sat still because sync had
418 // given up would pass the check above for the wrong reason, and the two
419 // agreeing above would then be two devices agreeing about nothing new.
420 const stalls = {
421 mine: await page.evaluate(() => DaimondSync.state().stalledWhy),
422 mate: await child.page.evaluate(() => DaimondSync.state().stalledWhy),
423 };
424 check(!stalls.mine && !stalls.mate, 'and neither device is stalled',
425 JSON.stringify(stalls));
426 }
427
428} catch (e) {
429 // A throw part-way through must still land as a FAIL line and a summary. A
430 // stack trace over the top of the checks that already named the fault sends
431 // the reader looking in the wrong file.
432 check(false, 'the run got to the end', String((e && e.message) || e));
433} finally {
434 if (child) await child.close();
435 await s.close();
436}
437
438console.log(bad === 0
439 ? `\nall checks passed${skipped ? ` (${skipped} skipped)` : ''}`
440 : `\n${bad} check(s) FAILED${skipped ? `, ${skipped} skipped` : ''}`);
441process.exit(bad === 0 ? 0 : 1);