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.`);