test(multichain-testing): stir for no AVA timeout in long awaits

multichain-testing/package.json

@@ -58,8 +58,7 @@
       "**/*.test.ts"
     ],
     "concurrency": 1,
-    "serial": true,
-    "timeout": "125s"
+    "serial": true
   },
   "eslintConfig": {
     "root": true,

multichain-testing/test/stake-ica.test.ts

@@ -243,7 +243,10 @@ const stakeScenario = test.macro(async (t, scenario: StakeIcaScenario) => {
 
   console.log('waiting for unbonding period');
   // XXX reference `120000` from chain state + `maxClockSkew`
-  await sleep(120000);
+  await sleep(120000, {
+    stir: description =>
+      t.pass(`stirring while waiting for unbonding period: ${description}`),
+  });
   const { balances: rewardsWithUndelegations } = await retryUntilCondition(
     () => queryClient.queryBalances(address),
     ({ balances }) => {

multichain-testing/test/stir.test.ts

@@ -0,0 +1,26 @@
+import test from '@endo/ses-ava/prepare-endo.js';
+import { sleep } from '../tools/sleep.js';
+
+test('sleep without tripping AVA timeout', async t => {
+  const stirred: string[] = [];
+  t.timeout(500);
+  const sleepTime = 4_000;
+  await sleep(sleepTime, {
+    log: t.log,
+    stirEveryMs: 300,
+    stir: description => {
+      stirred.push(description);
+      t.pass(description);
+    },
+  });
+  t.like(stirred, {
+    length: 15,
+    0: `sleeping for ${sleepTime}ms...`,
+    1: `while sleeping (1/14)`,
+    2: `while sleeping (2/14)`,
+    // ...
+    13: `while sleeping (13/14)`,
+    14: `while sleeping (14/14)`,
+    15: undefined,
+  });
+});

multichain-testing/test/support.ts

@@ -61,6 +61,10 @@ export const commonSetup = async (t: ExecutionContext) => {
   const retryUntilCondition = makeRetryUntilCondition({
     log: t.log,
     setTimeout: globalThis.setTimeout,
+    setInterval: globalThis.setInterval,
+    clearInterval: globalThis.clearInterval,
+    stir: description =>
+      t.pass(`stirring in retryUntilCondition ${description}`),
   });
   const hermes = makeHermes(childProcess);
 

multichain-testing/tools/sleep.ts

@@ -1,21 +1,68 @@
+const ambientSetInterval = globalThis.setInterval;
+const ambientClearInterval = globalThis.clearInterval;
 const ambientSetTimeout = globalThis.setTimeout;
 
+// Derived from the fact that AVA's "default timeout is 10 seconds."
+// https://github.com/avajs/ava/blob/main/docs/07-test-timeouts.md#test-timeouts
+const DEFAULT_STIR_EVERY_MS = 8_000;
+
 type Log = (...values: unknown[]) => void;
 
 type SleepOptions = {
   log?: Log;
+  clearInterval?: typeof ambientClearInterval;
+  setInterval?: typeof ambientSetInterval;
   setTimeout?: typeof ambientSetTimeout;
+  stirEveryMs?: number;
+  /**
+   * Call every `stirEveryMs` during sleeping so that the sleeper isn't timed
+   * out by, e.g. a test runner.
+   * @param description - A bit of context as to why we're stirring.
+   */
+  stir?: (description: string) => void;
 };
 
-export const sleep = (
+/**
+ *
+ * @param {number} ms Sleep duration in milliseconds
+ * @param {SleepOptions} opts
+ * @returns {Promise<void>}
+ */
+export const deepSleep = (
   ms: number,
-  { log = () => {}, setTimeout = ambientSetTimeout }: SleepOptions = {},
+  { setTimeout = ambientSetTimeout }: SleepOptions = {},
 ) =>
   new Promise(resolve => {
-    log(`Sleeping for ${ms}ms...`);
     setTimeout(resolve, ms);
   });
 
+export const sleep = async (
+  ms: number,
+  {
+    log = () => {},
+    stir,
+    stirEveryMs = DEFAULT_STIR_EVERY_MS,
+    setTimeout = ambientSetTimeout,
+  }: SleepOptions = {},
+) => {
+  log(`Sleeping for ${ms}ms...`);
+  await (stir && stir(`sleeping for ${ms}ms...`));
+  let remaining = ms;
+  let nStirs = 0;
+  const totalStirs = Math.ceil(ms / stirEveryMs);
+  const doStir = async () => {
+    nStirs += 1;
+    await (stir && stir(`while sleeping (${nStirs}/${totalStirs})`));
+  };
+  while (stir && remaining >= stirEveryMs) {
+    remaining -= stirEveryMs;
+    await deepSleep(stirEveryMs, { setTimeout });
+    await doStir();
+  }
+  await deepSleep(remaining, { setTimeout });
+  await doStir();
+};
+
 export type RetryOptions = {
   maxRetries?: number;
   retryIntervalMs?: number;
@@ -29,13 +76,27 @@ const retryUntilCondition = async <T>(
     maxRetries = 6,
     retryIntervalMs = 3500,
     log = () => {},
+    stirEveryMs,
+    stir,
     setTimeout = ambientSetTimeout,
+    setInterval = ambientSetInterval,
+    clearInterval = ambientClearInterval,
   }: RetryOptions = {},
 ): Promise<T> => {
   console.log({ maxRetries, retryIntervalMs, message });
   let retries = 0;
 
   while (retries < maxRetries) {
+    let conditionStirring;
+    if (stir) {
+      let nStirs = 0;
+      conditionStirring = setInterval(() => {
+        nStirs += 1;
+        stir(
+          `during ${message} condition (${retries + 1}/${maxRetries})#${nStirs}`,
+        );
+      }, stirEveryMs);
+    }
     try {
       const result = await operation();
       if (condition(result)) {
@@ -47,13 +108,15 @@ const retryUntilCondition = async <T>(
       } else {
         log(`Unknown error: ${String(error)}`);
       }
+    } finally {
+      conditionStirring === undefined || clearInterval(conditionStirring);
     }
 
     retries++;
     console.log(
       `Retry ${retries}/${maxRetries} - Waiting for ${retryIntervalMs}ms for ${message}...`,
     );
-    await sleep(retryIntervalMs, { log, setTimeout });
+    await sleep(retryIntervalMs, { log, setTimeout, stirEveryMs, stir });
   }
 
   throw Error(`${message} condition failed after ${maxRetries} retries.`);