igneum/tools/reliability/app-run.mjs

#!/usr/bin/env node
// The app engine's watchdog measured end to end on a Mac: a scratch Igneum Miner engine with its own private node
// (ports 29960 and 29961, devnet suffix 9960, no peers, unsynced mining allowed, so the node counts as synced) and
// fake-worker.mjs standing in for the Metal worker, driven through the control file and with signals.
//
//   node tools/reliability/app-run.mjs --app <igneum-app> --miner <igneum-miner> [--node <igneumd>]
//
// Steps, in one engine run (each states what must happen and what must not):
//   own-restart   the worker reports jobs done in 0.3 ms: the miner's guard restarts the worker; the app shows the
//                 fault and does NOT restart the miner (same pid, no app restart)
//   zero-once     the worker completes jobs with 0 hashes: hash rate 0 for 60 s while synced, the app restarts the
//                 miner once; the worker is healthy again: mining resumes
//   zero-faulted  the same again inside five minutes: the card is marked faulted with the reason, its miner is not
//                 restarted, the node keeps running; "resume" clears it
//   no-status     the miner process is stopped with SIGSTOP: no status line for 90 s, the app restarts it
//   node-silent   the node is stopped with SIGSTOP: no reading for 120 s, the app restarts the node in-process and
//                 the miner comes back once it is synced
// Never touches the live devnet. The app's own log is in the scratch directory.

import { spawn } from 'node:child_process';
import { mkdirSync, rmSync, writeFileSync, existsSync, symlinkSync, readFileSync, appendFileSync, chmodSync } from 'node:fs';
import { fileURLToPath } from 'node:url';
import { dirname, join } from 'node:path';

const here = dirname(fileURLToPath(import.meta.url));
const args = process.argv.slice(2);
const opt = (n, d) => { const i = args.indexOf(n); return i >= 0 ? args[i + 1] : d; };
const APP = opt('--app');
const MINER = opt('--miner');
const NODE = opt('--node', join(here, '../../vendor/igneum-node/target-integration/release/igneumd'));
const ONLY = opt('--only', '').split(',').filter(Boolean);
const SCRATCH = process.env.SCRATCH || `/tmp/igneum-reliability-app-${process.pid}`;
const RPC = 29960, P2P = 29961, SUFFIX = 9960;
for (const [k, v] of Object.entries({ APP, MINER, NODE })) if (!v || !existsSync(v)) { console.error(`missing ${k} (${v})`); process.exit(2); }

const t0 = Date.now();
const since = () => ((Date.now() - t0) / 1000).toFixed(1);
const log = (...a) => console.log(new Date().toISOString().slice(11, 23), `t=${since()}s`, ...a);
const sleep = (ms) => new Promise(r => setTimeout(r, ms));
const s = (ms) => (ms / 1000).toFixed(1) + ' s';

rmSync(SCRATCH, { recursive: true, force: true });
const bin = join(SCRATCH, 'stage', 'bin'); mkdirSync(bin, { recursive: true });
symlinkSync(NODE, join(bin, 'igneumd'));
symlinkSync(MINER, join(bin, 'igneum-miner'));
chmodSync(join(here, 'fake-worker.mjs'), 0o755);
symlinkSync(join(here, 'fake-worker.mjs'), join(bin, 'igneum-bench'));
const data = join(SCRATCH, 'data'); mkdirSync(join(data, 'app'), { recursive: true });
const logs = join(SCRATCH, 'logs'); mkdirSync(logs, { recursive: true });
const CTL = join(SCRATCH, 'ctl');
const setMode = (m) => { writeFileSync(CTL, m + '\n'); log(`fake worker mode -> ${m}`); };
setMode('ok');
writeFileSync(join(data, 'app', 'settings.json'), JSON.stringify({
  setup_done: true, address: '0x4242424242424242424242424242424242424242', address_source: 'pasted', key_saved: true, identities: 1,
  cards: { 'apple::Fake GPU': { enabled: true, identities: 1, power_pct: 0 } }, vote: false, paused: false, accepted_total: 0,
  auto_update: false, remote_jobs: false, prove: false,
}, null, 2));

const env = {
  ...process.env, IGNEUM_APP_DATA: data, IGNEUM_APP_LOGS: logs, IGNEUM_APP_BIN: bin, IGNEUM_APP_RPC_PORT: String(RPC), IGNEUM_APP_P2P_PORT: String(P2P),
  IGNEUM_APP_PEERS: '', IGNEUM_APP_UNSYNCED: '1', IGNEUM_APP_DEVNET_SUFFIX: String(SUFFIX), IGNEUM_APP_STATUS_SECS: '10', FAKE_WORKER_CTL: CTL,
};
const app = spawn(APP, ['--no-open'], { stdio: ['pipe', 'pipe', 'pipe'], env });
const appOut = join(SCRATCH, 'app.out');
app.stdout.on('data', d => appendFileSync(appOut, d)); app.stderr.on('data', d => appendFileSync(appOut, d));
let appExit = null;
app.on('exit', c => { appExit = c; log(`app exited ${c}`); });
process.on('exit', () => { try { app.kill('SIGKILL'); } catch {} });
process.on('SIGINT', () => process.exit(130));
log(`app pid ${app.pid}, scratch ${SCRATCH}`);

let url = null;
for (let i = 0; i < 100 && !url; i++) { try { url = readFileSync(join(data, 'app', 'app.url'), 'utf8').trim(); } catch { await sleep(200); } }
if (!url) { log('no app.url'); process.exit(1); }
async function state() {
  try { const r = await fetch(url + 'api/state'); return await r.json(); } catch { return null; }
}
const card = (st) => (st && st.mining && st.mining.cards && st.mining.cards[0]) || {};
const events = []; // (t, card state, message, hash, pid, restarts, faults, node state) transitions, for the record
let last = '';
async function poll() {
  const st = await state();
  if (!st) return null;
  const c = card(st);
  const key = [c.state, c.message, c.pid, c.restarts, c.faults, st.node.state, c.hash_now > 0 ? '>0' : '0'].join('|');
  if (key !== last) { last = key; events.push({ t: Date.now(), key }); log(`card ${c.state} pid ${c.pid} restarts ${c.restarts} faults ${c.faults} hash ${Number(c.hash_now).toFixed(1)} node ${st.node.state} ${c.message ? '"' + c.message + '"' : ''}`); }
  return st;
}
async function until(pred, timeoutMs, what) {
  const end = Date.now() + timeoutMs;
  while (Date.now() < end) { const st = await poll(); if (st && pred(st, card(st))) return st; if (appExit !== null) return null; await sleep(1000); }
  log(`timeout waiting for: ${what}`);
  return null;
}
const mining = (st, c) => c.state === 'mining' && c.hash_now > 0 && st.node.synced;
const results = [];
function verdict(name, checks, metrics) {
  const pass = checks.every(c => c.ok);
  results.push({ name, pass, checks, metrics });
  log(`${pass ? 'PASS' : 'FAIL'} ${name}`);
  for (const c of checks) log(`  ${c.ok ? 'ok  ' : 'FAIL'} ${c.what}`);
  for (const [k, v] of Object.entries(metrics)) log(`  ${k}: ${v}`);
}
async function steady(ms) { const end = Date.now() + ms; while (Date.now() < end) { await poll(); await sleep(1000); } }

const S = {};
S['own-restart'] = async () => {
  const st0 = await until(mining, 180000, 'first mining');
  const pid0 = card(st0).pid, r0 = card(st0).restarts;
  const tInject = Date.now();
  setMode('fast');
  const faulted = await until((st, c) => c.faults >= 1, 90000, 'the worker fault to reach the card');
  const tFault = Date.now();
  setMode('ok');
  const back = await until((st, c) => mining(st, c) && c.faults >= 1, 90000, 'mining again after the worker restart');
  const tBack = Date.now();
  await steady(20000);
  const st1 = await poll();
  verdict('own-restart', [
    { ok: !!st0, what: 'the card mined with a rate above 0 on the fake worker' },
    { ok: !!faulted && /worker fault|killed by a guard/.test(card(faulted).message || ''), what: `the card showed the worker fault (${JSON.stringify(card(faulted || {}).message)})` },
    { ok: !!back, what: 'mining resumed after the miner restarted its own worker' },
    { ok: st1 && card(st1).pid === pid0 && card(st1).restarts === r0, what: `the app did not restart the miner (pid ${pid0} -> ${card(st1 || {}).pid}, app restarts ${r0} -> ${card(st1 || {}).restarts})` },
  ], { inject_to_fault_on_card: s(tFault - tInject), fault_to_mining_again: s(tBack - tFault) });
};
S['zero-once'] = async () => {
  const st0 = await until(mining, 60000, 'mining');
  const pid0 = card(st0).pid, r0 = card(st0).restarts;
  const tInject = Date.now();
  setMode('zero');
  const rs = await until((st, c) => c.restarts > r0 || /watchdog/.test(c.message || ''), 150000, 'the watchdog restart');
  const tRestart = Date.now();
  setMode('ok');
  const back = await until((st, c) => mining(st, c) && c.pid !== pid0, 120000, 'mining on the restarted miner');
  const tBack = Date.now();
  await steady(15000);
  const st1 = await poll();
  verdict('zero-once', [
    { ok: !!rs && /hash rate 0/.test(card(rs).message || ''), what: `the watchdog restarted the miner for a zero rate (${JSON.stringify(card(rs || {}).message)})` },
    { ok: rs && tRestart - tInject >= 55000 && tRestart - tInject <= 100000, what: `between 55 and 100 s after the rate went to 0 (${s(tRestart - tInject)})` },
    { ok: !!back, what: 'mining resumed on a new miner process' },
    { ok: st1 && card(st1).restarts === r0 + 1, what: `exactly one app restart (${r0} -> ${card(st1 || {}).restarts})` },
  ], { zero_to_restart: s(tRestart - tInject), restart_to_mining: s(tBack - tRestart), zero_to_mining: s(tBack - tInject) });
};
S['zero-faulted'] = async () => {
  const st0 = await until(mining, 60000, 'mining');
  const r0 = card(st0).restarts;
  const tInject = Date.now();
  setMode('zero');
  const f = await until((st, c) => c.state === 'faulted', 150000, 'the card to be marked faulted');
  const tFault = Date.now();
  await steady(45000);
  const st1 = await poll();
  setMode('ok');
  app.stdin.write('resume\n');
  const back = await until(mining, 90000, 'mining after resume');
  verdict('zero-faulted', [
    { ok: !!f && /restarted once already/.test(card(f).message || ''), what: `the card was marked faulted with the reason (${JSON.stringify(card(f || {}).message)})` },
    { ok: st1 && card(st1).state === 'faulted' && card(st1).pid === 0 && card(st1).restarts === r0, what: `45 s later: still faulted, no miner process, no further restart (restarts ${r0} -> ${card(st1 || {}).restarts})` },
    { ok: st1 && st1.node.synced && appExit === null, what: 'the node kept running and the app stayed up' },
    { ok: !!back, what: 'resume cleared the fault and mining resumed' },
  ], { zero_to_faulted: s(tFault - tInject) });
};
S['no-status'] = async () => {
  const st0 = await until(mining, 60000, 'mining');
  const pid0 = card(st0).pid, r0 = card(st0).restarts;
  const tInject = Date.now();
  process.kill(pid0, 'SIGSTOP');
  log(`SIGSTOP miner pid ${pid0}`);
  const rs = await until((st, c) => c.restarts > r0 || /no status line/.test(c.message || ''), 150000, 'the watchdog restart');
  const tRestart = Date.now();
  const back = await until((st, c) => mining(st, c) && c.pid !== pid0 && c.pid > 0, 120000, 'mining on the restarted miner');
  const tBack = Date.now();
  let gone = false; try { process.kill(pid0, 0); } catch { gone = true; }
  if (!gone) { try { process.kill(pid0, 'SIGKILL'); } catch {} }
  verdict('no-status', [
    { ok: !!rs && /no status line/.test(card(rs).message || ''), what: `the watchdog restarted the miner for missing status lines (${JSON.stringify(card(rs || {}).message)})` },
    { ok: rs && tRestart - tInject >= 85000 && tRestart - tInject <= 130000, what: `between 85 and 130 s after the miner went quiet (${s(tRestart - tInject)})` },
    { ok: !!back, what: 'mining resumed on a new miner process' },
    { ok: gone, what: 'the stopped miner process was killed' },
  ], { quiet_to_restart: s(tRestart - tInject), restart_to_mining: s(tBack - tRestart) });
};
S['node-silent'] = async () => {
  const st0 = await until(mining, 60000, 'mining');
  const npid = st0.node.pid, starts0 = st0.node.starts;
  const tInject = Date.now();
  process.kill(npid, 'SIGSTOP');
  log(`SIGSTOP node pid ${npid}`);
  const rs = await until((st) => st.node.state === 'restarting' || st.node.starts > starts0, 200000, 'the node restart');
  const tRestart = Date.now();
  const synced = await until((st) => st.node.starts > starts0 && st.node.synced, 120000, 'the restarted node to sync');
  const tSynced = Date.now();
  const back = await until(mining, 120000, 'mining again');
  const tBack = Date.now();
  let gone = false; try { process.kill(npid, 0); } catch { gone = true; }
  if (!gone) { try { process.kill(npid, 'SIGKILL'); } catch {} }
  verdict('node-silent', [
    { ok: !!rs, what: 'the app restarted the node' },
    { ok: rs && tRestart - tInject >= 115000 && tRestart - tInject <= 170000, what: `between 115 and 170 s after the node went quiet (${s(tRestart - tInject)})` },
    { ok: !!synced, what: `the new node synced (starts ${starts0} -> ${synced ? synced.node.starts : '?'})` },
    { ok: !!back, what: 'mining resumed' },
    { ok: gone, what: 'the stopped node process was killed' },
  ], { quiet_to_restart: s(tRestart - tInject), restart_to_synced: s(tSynced - tRestart), quiet_to_mining: s(tBack - tInject) });
};

const names = ONLY.length ? ONLY : Object.keys(S);
for (const n of names) {
  if (!S[n]) { log(`unknown step ${n}`); continue; }
  log(`=== ${n}`);
  try { await S[n](); } catch (e) { log(`step ${n} threw: ${e.stack || e}`); results.push({ name: n, pass: false, checks: [{ ok: false, what: String(e) }], metrics: {} }); }
}
app.stdin.write('quit\n');
await sleep(8000);
const report = { date: new Date().toISOString(), app: APP, miner: MINER, node: NODE, scratch: SCRATCH, results, transitions: events.map(e => ({ t: new Date(e.t).toISOString(), key: e.key })) };
writeFileSync(join(SCRATCH, 'report.json'), JSON.stringify(report, null, 2));
console.log(JSON.stringify({ ...report, transitions: undefined }, null, 2));
process.exit(results.every(r => r.pass) ? 0 : 1);