feedback7 G-TOOLS: SP_VERIFY re-runs slice work in the existing 8 ms budget instead of blocking the event loop (PR #352 by @siruimei07)

Applied as-is. All-mode verification runs the existing HeadlessJob in headlessSliceMs slices (8 ms on a real scheduler; synchronous when that value is not finite, including the virtual scheduler). The field still settles with the server digest. Sample mode still accepts the client result immediately and logs afterwards. A comparison error in all mode falls back to the server result. Dispose cancels the pending slice timer.

Tests: node --test test/match/verification-slices.test.js — 11 pass, 0 fail; node --test test/match/clientCombat.test.js test/match/clientCombat-review.test.js — 39 pass, 0 fail.

server/match/Match.js

@@ -106,7 +106,7 @@
 // (g.bandFocus → timeoutBand); g.unitStats answers m.unitStats: the stats the board's units start their next battle with.
 //   opts.clientCombat  default true (env SP_COMBAT=server → false: the legacy server-run + snapshot streaming mode)
 //   opts.verify        'off' | 'sample' | 'all' (env SP_VERIFY, default 'off'): re-simulate accepted client results
-//                      ('sample': ~1 in 8, in a later callback, mismatches logged; 'all': before accepting — the
+//                      ('sample': ~1 in 8, in later slices, mismatches logged; 'all': before accepting — the
 //                      server's result wins on a mismatch)
 //
 // Engine-only extra options (tests / tools; the lobby never passes them):
@@ -121,7 +121,7 @@
 //   opts.botSliceMs    wall-clock ms of rehearsal per scheduler callback (default 8 with a real scheduler, unbounded
 //                      with a virtual one); the rest runs in later callbacks (scheduleBotPrep)
 //   opts.headlessSliceMs  wall-clock ms per callback of a server-run normal / 联防 field (client-side combat: bots,
-//                      takeovers; default 8 with a real scheduler, at once with a virtual one)
+//                      takeovers, result verification; default 8 with a real scheduler, at once with a virtual one)
 // Seats may be all bots (tools/matchrun.mjs); the lobby always has ≥ 1 human.
 //
 // Diagnostics: m.errors / m.errorCount (engine), m.dispatcher.errors / .errorsByKey (meta handlers), m.simErrors

server/match/match/clientCombat.js

@@ -24,8 +24,9 @@ export class MatchClientCombat {
 
   _clearFieldTimers(f) {
     if (!f || !f.cc) return;
-    for (const k of ['deadlineTimer', 'doneTimer', 'waitTimer', 'sliceTimer']) if (f[k]) { this.cancel(f[k]); f[k] = null; }
+    for (const k of ['deadlineTimer', 'doneTimer', 'waitTimer', 'sliceTimer', 'verifyTimer']) if (f[k]) { this.cancel(f[k]); f[k] = null; }
     f.job = null;
+    f.verifyJob = null;
   }
 
   /** A client-combat field record: the JSON BattleSpec of its Battle options plus the authority / result state. */
@@ -84,7 +85,7 @@ export class MatchClientCombat {
     return {
       t: 'b.start', battleId: f.battleId, fieldId: f.fieldId, kind: f.kind,
       spec: this.spectators.has(pid) ? this._spectatorSpec(f) : f.spec,
-      authoritative: !!(!f.done && f.mode === 'client' && f.authority === pid && !watch),
+      authoritative: !!(!f.done && !f.verifyJob && f.mode === 'client' && f.authority === pid && !watch),
       startAt: f.startAt, serverNow: this.sched.now(), elapsed: Math.round(this._fieldElapsed(f) * 1000) / 1000,
       speed: this.gameSpeed, watch: !!watch, done: !!f.done,
     };
@@ -121,6 +122,7 @@ export class MatchClientCombat {
   /** A client field's result deadline: its time limit on the field clock + RESULT_GRACE_MS (then the server takes over). */
   _armDeadline(f) {
     if (f.deadlineTimer) { this.cancel(f.deadlineTimer); f.deadlineTimer = null; }
+    if (f.verifyJob) return;
     const lim = f.spec.timeLimit > 0 ? f.spec.timeLimit : 60;
     const at = f.startAt + Math.round((lim / this.gameSpeed) * 1000) + RESULT_GRACE_MS;
     f.deadlineTimer = this.later(Math.max(0, at - this.sched.now()), () => {
@@ -225,7 +227,7 @@ export class MatchClientCombat {
   /** An authoritative human disconnected / left: normal & 联防 fields → server takeover; boss → the partner or the server. */
   _authorityLost(ps, why) {
     for (const f of this.fields) {
-      if (!f.cc || f.done || f.mode !== 'client' || f.authority !== ps.playerId) continue;
+      if (!f.cc || f.done || f.verifyJob || f.mode !== 'client' || f.authority !== ps.playerId) continue;
       if (f.kind === 'boss' || f.kind === 'hidden') this._bossHandover(f, why);
       else this._runOnServer(f, why);
     }

server/match/match/reports.js

@@ -5,7 +5,7 @@
 // Installed on Match.prototype by server/match/Match.js (a method container: never instantiated; `this` is the match).
 
 import { ERR } from '../../../shared/constants.js';
-import { runHeadless, syntheticResult, validateClientResult, HARD_CAP_SECONDS } from '../fields.js';
+import { HeadlessJob, syntheticResult, validateClientResult, HARD_CAP_SECONDS } from '../fields.js';
 import { resultDigest, compactResult as compactForVerify } from '../../sim/spec.js';
 import { OK, fail } from './common.js';
 
@@ -18,7 +18,7 @@ export class MatchReports {
   _onProgress(ps, msg) {
     if (!this.clientCombat) return fail(ERR.WRONG_PHASE, 'server-run combat');
     const f = this._fieldByBattle(msg.battleId);
-    if (!f || f.done || f.mode !== 'client' || f.authority !== ps.playerId) return OK;
+    if (!f || f.done || f.verifyJob || f.mode !== 'client' || f.authority !== ps.playerId) return OK;
     const p = f.progress;
     const maxTotal = Math.max(p.total, (f.spec.spawns.length + 1) * 400);
     p.gt = Math.max(p.gt, Math.min(Number(msg.gt) || 0, HARD_CAP_SECONDS));
@@ -46,7 +46,7 @@ export class MatchReports {
   _onResult(ps, msg) {
     if (!this.clientCombat) return fail(ERR.WRONG_PHASE, 'server-run combat');
     const f = this._fieldByBattle(msg.battleId);
-    if (!f || f.done || f.heldResult || f.mode !== 'client' || f.authority !== ps.playerId) return OK;
+    if (!f || f.done || f.heldResult || f.verifyJob || f.mode !== 'client' || f.authority !== ps.playerId) return OK;
     const bossLike = f.kind === 'boss' || f.kind === 'hidden';
     const v = validateClientResult(f.spec, msg.result, { gd: this.gd });
     if (!v.ok) {
@@ -57,7 +57,7 @@ export class MatchReports {
       else this._runOnServer(f, 'invalid');
       return OK;
     }
-    let result = v.result;
+    const result = v.result;
     if (bossLike) {
       // the final b.progress normally carried everything; the result's per-player damage is a lower bound
       const by = {};
@@ -91,13 +91,15 @@ export class MatchReports {
         return OK;
       }
       this._bossResultDamage(f, result);
-    } else {
-      result = this._verifyResult(f, result);
     }
-    f.result = result;
-    f.resultSource = 'client';
-    this._fieldDone(f);
-    if (bossLike) { this._checkFinalEnd(); this._broadcastPool(false); }
+    const accept = (verified) => {
+      f.result = verified;
+      f.resultSource = 'client';
+      this._fieldDone(f);
+      if (bossLike) { this._checkFinalEnd(); this._broadcastPool(false); }
+    };
+    if (bossLike) accept(result);
+    else this._verifyResult(f, result, accept);
     return OK;
   }
 
@@ -107,27 +109,59 @@ export class MatchReports {
   }
 
   /**
-   * SP_VERIFY: re-simulate an accepted client result ('all': now, the server's result wins on a mismatch; 'sample':
-   * ~1 battle in 8 in a later callback, mismatches are only logged).
+   * SP_VERIFY: re-simulate in headless slices. 'all' waits before accepting (the server wins on a mismatch);
+   * 'sample' accepts immediately and only logs differences for ~1 battle in 8, even after the field's phase ends.
    */
-  _verifyResult(f, result) {
-    if (this.verifyMode === 'off') return result;
-    const check = () => {
-      const run = runHeadless(this._specBattle(f.spec), { players: f.players });
-      const mine = validateClientResult(f.spec, compactForVerify(run.result), { gd: this.gd });
-      const server = mine.ok ? mine.result : run.result;
-      this.verifyStats.checked++;
-      if (resultDigest(server).hash !== resultDigest(result).hash) {
-        this.verifyStats.mismatches++;
-        this.log.warn?.(`[match ${this.roomCode}] ${f.fieldId}: client result differs from the server's simulation`);
-        return server;
+  _verifyResult(f, result, accept) {
+    if (this.verifyMode === 'off') { accept(result); return; }
+    const required = this.verifyMode === 'all';
+    const start = () => {
+      const job = new HeadlessJob(this._specBattle(f.spec), { players: f.players, onError: (e) => this.reportError('verify', e) });
+      if (required) {
+        // The result has arrived: duplicate reports, disconnects and the old deadline must not start another run.
+        f.verifyJob = job;
+        this.cancel(f.deadlineTimer);
+        f.deadlineTimer = null;
+        f.rearmDeadline = false;
       }
-      return null;
+      const schedule = () => {
+        const timer = this.later(0, slice);
+        if (required) f.verifyTimer = timer;
+      };
+      const slice = () => {
+        if (required) f.verifyTimer = null;
+        if (this.disposed || this.ended) return;
+        if (required && (f.verifyJob !== job || f.done || f.mode !== 'client' || !this.fields.includes(f))) return;
+        let verified = result;
+        try {
+          if (!job.run(this.headlessSliceMs)) { schedule(); return; }
+          const run = job.output();
+          const mine = validateClientResult(f.spec, compactForVerify(run.result), { gd: this.gd });
+          const server = mine.ok ? mine.result : run.result;
+          this.verifyStats.checked++;
+          if (resultDigest(server).hash !== resultDigest(result).hash) {
+            this.verifyStats.mismatches++;
+            this.log.warn?.(`[match ${this.roomCode}] ${f.fieldId}: client result differs from the server's simulation`);
+            verified = server;
+          }
+        } catch (e) {
+          this.reportError('verify', e);
+          if (required) {
+            this._clearFieldTimers(f);
+            this._runOnServer(f, 'verify-error');
+          }
+          return;
+        }
+        if (required) { f.verifyJob = null; accept(verified); }
+      };
+      if (Number.isFinite(this.headlessSliceMs)) schedule();
+      else slice(); // Virtual schedulers retain their synchronous fast path.
     };
-    if (this.verifyMode === 'all') return check() || result;
+    if (required) { start(); return; }
     let h = 0;
     for (let i = 0; i < f.battleId.length; i++) h = (h * 31 + f.battleId.charCodeAt(i)) >>> 0;
-    if (h % 8 === 0) this.later(0, () => { try { check(); } catch (e) { this.reportError('verify', e); } });
-    return result;
+    // Sample jobs use only match-level timers: field completion must not cancel the diagnostic work.
+    if (h % 8 === 0) this.later(0, start);
+    accept(result);
   }
 }

test/match/verification-slices.test.js

@@ -0,0 +1,249 @@
+import { test } from 'node:test';
+import assert from 'node:assert/strict';
+import { setTimeout as pause } from 'node:timers/promises';
+import { PHASE } from '../../shared/constants.js';
+import { runHeadless, validateClientResult, RESULT_GRACE_MS } from '../../server/match/fields.js';
+import { RealScheduler } from '../../server/match/scheduler.js';
+import { compactResult, createBattleFromSpec, resultDigest } from '../../server/sim/spec.js';
+import { makeMatch } from './harness.js';
+
+const SLICE_MS = 0.000001;
+
+function combat(t, verify = 'all', options = {}) {
+  const h = makeMatch({ mode: 'coop', humans: 1, bots: 0, seed: 345, clientCombat: true,
+    clients: false, verify, headlessSliceMs: SLICE_MS, timerScale: 0, ...options });
+  t.after(() => h.m.dispose());
+  h.start();
+  assert.ok(h.drive(() => h.m.phase === PHASE.COMBAT));
+  return h;
+}
+
+function results(h, f) {
+  const run = runHeadless(createBattleFromSpec(f.spec, h.m.ds, { recordEvents: false, quiet: true }), { players: f.players });
+  const checked = validateClientResult(f.spec, compactResult(run.result), { gd: h.m.gd });
+  assert.ok(checked.ok, checked.reason);
+  const server = checked.result;
+  assert.ok(server.perPlayer.p_0.leaked.length > 0, 'the empty board leaks real enemies');
+  const forged = structuredClone(server);
+  forged.killed = forged.total;
+  Object.assign(forged.perPlayer.p_0, { leaked: [], perfect: true, killed: forged.perPlayer.p_0.total });
+  const plausible = validateClientResult(f.spec, forged, { gd: h.m.gd });
+  assert.ok(plausible.ok, plausible.reason);
+  return { server, forged: plausible.result };
+}
+
+function report(h, f, result) {
+  assert.deepEqual(h.m.handle('p_0', { t: 'b.result', battleId: f.battleId, result }), { ok: true });
+}
+
+function observeSimulation(m, onStep = () => {}) {
+  const seen = { battles: 0, steps: 0 };
+  const create = m._specBattle.bind(m);
+  m._specBattle = (...args) => {
+    const battle = create(...args);
+    seen.battles++;
+    const step = battle.step.bind(battle);
+    battle.step = (...stepArgs) => {
+      const result = step(...stepArgs);
+      seen.steps++;
+      onStep(battle, seen);
+      return result;
+    };
+    return battle;
+  };
+  return seen;
+}
+
+test('all verification yields between slices and settles with the synchronous server digest', (t) => {
+  const h = combat(t);
+  const m = h.m;
+  const f = m.fields[0];
+  const { server, forged } = results(h, f);
+  let between = null;
+  const seen = observeSimulation(m, (battle, state) => {
+    if (state.steps === 1) h.sched.setTimeout(() => {
+      between = { steps: state.steps, finished: battle.finished, checked: m.verifyStats.checked, done: f.done };
+    }, 0);
+  });
+  report(h, f, forged);
+  assert.equal(seen.steps, 0, 'report handling schedules simulation without stepping it');
+  assert.equal(f.done, false, 'the result awaits verification');
+  assert.equal(m.lastResults.has('p_0'), false, 'settlement cannot consume the unverified report');
+  assert.ok(h.run(() => m.verifyStats.checked === 1));
+  assert.ok(between && between.steps > 0, 'an unrelated timer runs after simulation starts');
+  assert.deepEqual([between.finished, between.checked, between.done], [false, 0, false], 'the timer runs between unfinished slices');
+  assert.equal(resultDigest(f.result).hash, resultDigest(server).hash, 'sliced verification matches synchronous simulation');
+  assert.equal(m.verifyStats.mismatches, 1);
+  assert.equal(m.verifyStats.rejected, 0, 'the forgery passes plausibility validation');
+  h.runToPhase(PHASE.SETTLE);
+  assert.deepEqual(m.lastResults.get('p_0').leaked, server.perPlayer.p_0.leaked);
+  assert.equal(m.errorCount, 0);
+});
+
+for (const verify of ['all', 'sample']) {
+  test(`${verify} verification lets an unrelated real timer run between battle slices`, async (t) => {
+    const h = makeMatch({ mode: 'coop', humans: 1, bots: 0, seed: 345, clientCombat: true,
+      clients: false, verify, headlessSliceMs: SLICE_MS, timerScale: 0 });
+    const m = h.m;
+    // Install the real scheduler before start, while the harness has no queued timers.
+    const scheduler = new RealScheduler();
+    m.sched = scheduler;
+    t.after(() => { m.dispose(); scheduler.dispose(); });
+    const waitFor = async (predicate) => {
+      const deadline = Date.now() + 10000;
+      while (!predicate() && Date.now() < deadline) await pause(1);
+      assert.ok(predicate(), `timed out in phase ${m.phase}`);
+    };
+    h.autoHumans().start();
+    await waitFor(() => m.phase === PHASE.COMBAT);
+    const f = m.fields[0];
+    const result = compactResult(runHeadless(createBattleFromSpec(f.spec, m.ds, { recordEvents: false, quiet: true }), { players: f.players }).result);
+    let between = null;
+    observeSimulation(m, (battle, seen) => {
+      if (seen.steps === 1) setTimeout(() => {
+        between = { steps: seen.steps, finished: battle.finished, checked: m.verifyStats.checked, done: f.done };
+      }, 0);
+    });
+    report(h, f, result);
+    await waitFor(() => between !== null);
+    assert.ok(between.steps > 0, 'the timer was scheduled by the first actual battle step');
+    assert.deepEqual([between.finished, between.checked, between.done], [false, 0, verify === 'sample'], 'Node executes the timer while verification is unfinished');
+    await waitFor(() => m.verifyStats.checked === 1);
+    assert.equal(resultDigest(f.result).hash, resultDigest(result).hash);
+    assert.equal(m.verifyStats.mismatches, 0);
+    assert.equal(m.errorCount, 0);
+  });
+}
+
+test('duplicate reports during all verification start one simulation and settle once', (t) => {
+  const h = combat(t);
+  const m = h.m;
+  const f = m.fields[0];
+  const { forged } = results(h, f);
+  const seen = observeSimulation(m);
+  let settlements = 0;
+  const settle = m.settle.bind(m);
+  m.settle = (...args) => { settlements++; return settle(...args); };
+  report(h, f, forged);
+  assert.equal(f.done, false, 'the duplicate arrives while verification is pending');
+  report(h, f, forged);
+  assert.ok(h.run(() => seen.steps > 0));
+  report(h, f, forged);
+  h.runToPhase(PHASE.SETTLE);
+  report(h, f, forged);
+  assert.equal(seen.battles, 1);
+  assert.equal(m.verifyStats.checked, 1);
+  assert.equal(m.verifyStats.mismatches, 1);
+  assert.equal(settlements, 1);
+});
+
+test('sample verification keeps the accepted result and finishes after the phase changes', (t) => {
+  // Seed 345 selects the first field for sampling; zero phase delays let settlement overtake verification.
+  const h = combat(t, 'sample');
+  const m = h.m;
+  const f = m.fields[0];
+  const { forged } = results(h, f);
+  const seen = observeSimulation(m);
+  report(h, f, forged);
+  assert.equal(f.done, true, 'sampling accepts the report immediately');
+  assert.equal(seen.steps, 0);
+  h.runToPhase(PHASE.SETTLE);
+  assert.equal(m.verifyStats.checked, 0, 'the sampled battle is still running after settlement');
+  assert.ok(h.run(() => m.verifyStats.checked === 1));
+  assert.equal(m.verifyStats.mismatches, 1);
+  assert.equal(resultDigest(f.result).hash, resultDigest(forged).hash);
+  assert.deepEqual(m.lastResults.get('p_0').leaked, [], 'sampling never replaces the accepted result');
+  assert.ok(h.logs.warn.some((line) => line.includes('client result differs')));
+  assert.equal(m.errorCount, 0);
+});
+
+for (const event of ['disconnect and reconnect', 'expired deadline']) {
+  test(`pending all verification does not restart simulation after ${event}`, (t) => {
+    const h = combat(t);
+    const m = h.m;
+    const f = m.fields[0];
+    const { forged } = results(h, f);
+    const seen = observeSimulation(m);
+    // Leave an already-due deadline callback queued when the result arrives.
+    if (event === 'expired deadline') h.sched.t += f.spec.timeLimit / m.gameSpeed * 1000 + RESULT_GRACE_MS + 1;
+    report(h, f, forged);
+    assert.equal(f.done, false);
+    if (event === 'disconnect and reconnect') {
+      m.onDisconnect('p_0');
+      m.onReconnect('p_0');
+      assert.equal(h.lastTo('p_0', 'b.start').authoritative, false, 'reconnect does not request a second result');
+    }
+    h.runToPhase(PHASE.SETTLE);
+    assert.equal(seen.battles, 1);
+    assert.equal(m.verifyStats.takeovers, 0, 'a received result no longer needs a client authority');
+    assert.equal(m.verifyStats.checked, 1);
+    assert.equal(m.verifyStats.mismatches, 1);
+  });
+}
+
+test('resuming a solo pause does not rearm a result deadline while verification is pending', (t) => {
+  const h = combat(t, 'all', { mode: 'solo' });
+  const m = h.m;
+  const f = m.fields[0];
+  const { forged } = results(h, f);
+  const seen = observeSimulation(m);
+  assert.deepEqual(m.handle('p_0', { t: 'g.pause', on: true }), { ok: true });
+  report(h, f, forged);
+  assert.equal(f.done, false);
+  assert.deepEqual(m.handle('p_0', { t: 'g.pause', on: false }), { ok: true });
+  h.sched.t += f.spec.timeLimit / m.gameSpeed * 1000 + RESULT_GRACE_MS + 1;
+  h.runToPhase(PHASE.SETTLE);
+  assert.equal(seen.battles, 1);
+  assert.equal(m.verifyStats.takeovers, 0);
+  assert.equal(m.verifyStats.checked, 1);
+});
+
+test('a verification comparison error falls back to a server result and completes the field', (t) => {
+  const h = combat(t);
+  const m = h.m;
+  const f = m.fields[0];
+  const { server, forged } = results(h, f);
+  const seen = observeSimulation(m);
+  const create = m._specBattle.bind(m);
+  m._specBattle = (...args) => {
+    const battle = create(...args);
+    if (seen.battles === 1) {
+      const result = battle.result.bind(battle);
+      battle.result = () => {
+        const out = result();
+        Object.defineProperty(out.perPlayer.p_0, 'unitStats', { get() { throw new Error('verification result cannot be normalized'); } });
+        return out;
+      };
+    }
+    return battle;
+  };
+  report(h, f, forged);
+  h.runToPhase(PHASE.SETTLE);
+  assert.equal(seen.battles, 2, 'the failed comparison is followed by one independent server run');
+  assert.equal(f.resultSource, 'server');
+  assert.equal(resultDigest(f.result).hash, resultDigest(server).hash, 'fallback never accepts the forged result');
+  assert.equal(m.errorCount, 1);
+  assert.ok(h.logs.error.some((line) => line.includes('verification result cannot be normalized')));
+  assert.deepEqual(h.sched.errors, []);
+});
+
+for (const verify of ['all', 'sample']) {
+  test(`dispose stops pending ${verify} verification without later completion`, (t) => {
+    const h = combat(t, verify, { timerScale: 1 });
+    const m = h.m;
+    const f = m.fields[0];
+    const { forged } = results(h, f);
+    const seen = observeSimulation(m);
+    report(h, f, forged);
+    assert.ok(h.run(() => seen.steps > 0));
+    assert.equal(m.verifyStats.checked, 0, 'dispose interrupts an unfinished verification');
+    m.dispose();
+    const steps = seen.steps;
+    h.sched.runAll({ maxSteps: 10000 });
+    assert.equal(seen.steps, steps, 'no further battle steps execute');
+    assert.equal(m.verifyStats.checked, 0);
+    assert.equal(m.verifyStats.mismatches, 0);
+    assert.equal(f.done, verify === 'sample');
+    assert.equal(m.errorCount, 0);
+  });
+}