TD-2668: judge test progress by ping count, not elapsed time

CHANGELOG.md

@@ -13,6 +13,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 - The grunt task passed config values to bedrock without type coercion, so string values for `Number` or `Boolean` options (e.g. `--webdriverPort=14444` or `--useSelenium=false` via `grunt.option`) were rejected or misread. #TINYMCE-14879
 - Extended test start pings to every page load, allowing updates during a chunk or fail-retry reload. This should reduce how often the server's no-updates watchdog is tripped. #TINYMCE-14879
 - Safari 26 failed to load the test page through the LambdaTest tunnel on `localhost`. The LT tunnel URL now uses LambdaTest's `localhost.lambdatest.com` DNS alias for all browsers. #TINYMCE-14879
+- The server used a single 55 second budget for both "the browser has stopped responding" and "the browser has not finished a test", so a slow remote browser was killed as if the driver had died. Liveness is now tracked separately from progress: silence from the browser is still caught after 55 seconds, while lack of progress is measured in client pings rather than elapsed time, so a slower connection widens the tolerance by the same factor. #TD-2600
+- The runner only posted to the server when a test finished, so a browser running one slow test looked the same as a browser that had died. It now posts on a fixed heartbeat regardless of test activity, rescheduled after each post completes so a slow connection cannot stack requests. #TD-2600
+- `/tests/init` did not record browser activity, so the bundle re-fetch after a chunk or retry reload counted as silence. #TD-2600
 
 ## 17.0.1 - 2026-08-28
 

modules/runner/src/main/ts/reporter/Reporter.ts

@@ -17,6 +17,7 @@ export interface TestReporter {
 export interface Reporter {
   readonly summary: () => { offset: number; passed: number; failed: number; skipped: number };
   readonly test: (file: string, name: string, totalNumTests: number) => TestReporter;
+  readonly startHeartbeat: (intervalMs?: number) => void;
   readonly strayFailure: (file: string, name: string, e: LoggedError) => void;
   readonly waitForResults: () => Promise<void>;
   readonly retry: () => Promise<void>;
@@ -49,9 +50,16 @@ const mapError = (e: LoggedError) => mapStackTrace(e.stack).then((mappedStack) =
   return e;
 });
 
+/*
+ * How often the runner posts to the server whether or not a test has finished. The server counts
+ * these to decide whether a run has stalled, so the value is a cadence and not a budget: slowing
+ * the connection slows the pings and widens the server's tolerance by the same factor.
+ */
+const HEARTBEAT_INTERVAL = 20 * 1000;
+
 export const Reporter = (params: UrlParams, callbacks: Callbacks, ui: ReporterUi, mouse: MouseWatch): Reporter => {
   const initial = Date.now();
-  let timeOfLastReport = initial;
+  let heartbeatTimer: ReturnType<typeof setTimeout> | null = null;
   let currentCount = params.offset || 0;
   let passCount = 0;
   let skipCount = 0;
@@ -66,8 +74,6 @@ export const Reporter = (params: UrlParams, callbacks: Callbacks, ui: ReporterUi
   const requestsInFlight: Promise<void>[] = [];
 
   const takeResults = (): TestReport[] => {
-    // Assume the results will be posted once they are returned
-    timeOfLastReport = Date.now();
     // splice deletes the values specified and returns them
     return testResults.splice(0, testResults.length);
   };
@@ -80,9 +86,33 @@ export const Reporter = (params: UrlParams, callbacks: Callbacks, ui: ReporterUi
 
   const reportResult = (result: TestReport): void => {
     testResults.push(result);
-    if (Date.now() - timeOfLastReport > 30 * 1000) {
-      // ping the server with results every 30 seconds or so, as a form of keep-alive
-      reportResults();
+  };
+
+  // Posts even when the batch is empty. An empty post is how the server tells a browser that is
+  // slow from one that is gone, so this must not be skipped when nothing has finished.
+  const reportProgress = (): Promise<void> => {
+    const sent = callbacks.sendTestResults(params.session, takeResults());
+    requestsInFlight.push(sent);
+    return sent;
+  };
+
+  // Rescheduled only once the previous post settles, so a slow connection stretches the gap
+  // instead of stacking requests on top of one that has not come back.
+  const scheduleHeartbeat = (intervalMs: number = HEARTBEAT_INTERVAL): void => {
+    heartbeatTimer = setTimeout(() => {
+      const again = (): void => {
+        if (!finished) {
+          scheduleHeartbeat(intervalMs);
+        }
+      };
+      reportProgress().then(again, again);
+    }, intervalMs);
+  };
+
+  const stopHeartbeat = (): void => {
+    if (heartbeatTimer !== null) {
+      clearTimeout(heartbeatTimer);
+      heartbeatTimer = null;
     }
   };
 
@@ -266,6 +296,7 @@ export const Reporter = (params: UrlParams, callbacks: Callbacks, ui: ReporterUi
 
   const done = (error?: LoggedError): void => {
     finished = true;
+    stopHeartbeat();
     const setAsDone = (): void => {
       const totalTime = elapsed(initial);
       ui.done(totalTime);
@@ -282,6 +313,7 @@ export const Reporter = (params: UrlParams, callbacks: Callbacks, ui: ReporterUi
   return {
     summary,
     test,
+    startHeartbeat: scheduleHeartbeat,
     strayFailure,
     retry,
     waitForResults,

modules/runner/src/main/ts/runner/Runner.ts

@@ -78,7 +78,6 @@ export const Runner = (rootSuite: Suite, params: UrlParams, callbacks: Callbacks
     ui.render(params.offset, numTests, actions.restartTests, retryTest, loadNextTest);
 
     return Promise.all([callbacks.sendInit(params.session), callbacks.loadHarness()]).then(([_, harness]) => {
-      // we don't need a keep-alive timer in auto mode,
       if (harness.mode === 'manual') {
         // delay this ajax call until after the reporter status elements are in the page
         const keepAliveTimer = setInterval(() => {
@@ -87,6 +86,9 @@ export const Runner = (rootSuite: Suite, params: UrlParams, callbacks: Callbacks
             clearInterval(keepAliveTimer);
           });
         }, KEEP_ALIVE_INTERVAL);
+      } else {
+        // only auto mode has the watchdog that counts these pings; manual keeps its keep-alive
+        reporter.startHeartbeat();
       }
 
       return harness;

modules/runner/src/test/ts/reporter/ReporterTest.ts

@@ -52,6 +52,7 @@ describe('Reporter.test', () => {
   let doneCalled: boolean, doneError: string | undefined, offset: number;
   let mouseMoved: boolean, startFails: boolean;
   let startGate: Promise<void> | null;
+  let resultsPosts: number;
   const mouse: MouseWatch = {
     hasMoved: () => mouseMoved,
     clear: () => {
@@ -71,6 +72,7 @@ describe('Reporter.test', () => {
       return startGate !== null ? startGate : Promise.resolve();
     },
     sendTestResults: (session, results) => {
+      resultsPosts++;
       results.forEach(r => endTestData.push({session, ...r}));
       return Promise.resolve();
     },
@@ -86,6 +88,7 @@ describe('Reporter.test', () => {
     mouseMoved = false;
     startFails = false;
     startGate = null;
+    resultsPosts = 0;
     reporter = Reporter({ ...params, offset }, callbacks, ui, mouse);
     startTestData = [];
     endTestData = [];
@@ -95,6 +98,18 @@ describe('Reporter.test', () => {
 
   beforeEach(() => reset());
 
+  it('TD-2668: the heartbeat posts even when no test has finished', () => {
+    reset(0);
+    // The server counts these posts to tell a slow browser from a dead one, so an empty batch
+    // still has to go out. Without that there is nothing to count while one slow test runs.
+    reporter.startHeartbeat(10);
+    return new Promise<void>((resolve) => setTimeout(resolve, 60)).then(() => {
+      assert.isAtLeast(resultsPosts, 2, 'Checking the heartbeat posted repeatedly with nothing to send');
+      assert.lengthOf(endTestData, 0, 'Checking the posts carried no results');
+      reporter.done();
+    });
+  });
+
   it('should report the session id, number tests, file and name on start', () => {
     return fc.assert(fc.asyncProperty(fc.string(), fc.string(), fc.integer({ max: offset }), (fileName, testName, testCount) => {
       reset(0);

modules/runner/src/test/ts/runner/RunnerTestUtils.ts

@@ -53,6 +53,7 @@ export const MockReporter = (): MockReporter => {
 
   return {
     test,
+    startHeartbeat: noop,
     strayFailure: (_file, name, e) => {
       failures.push(e);
       failedNames.push(name);

modules/server/src/main/ts/bedrock/server/Apis.ts

@@ -160,9 +160,14 @@ export const create = (master: DriverMaster | null, pMaybeDriver: Promise<Attemp
       driverRouter('/mouse', 'Mouse', MouseEffects.executor, true),
       Routes.effect('POST', '/tests/alive', (data: { session: string }) => {
         c.recordAlive(data.session);
-        return keepAliveAction();
+        // manual mode pings this every few seconds, so it must be the throttled variant or a
+        // run would issue a webdriver command on every ping
+        return maybeSendKeepAlive();
+      }),
+      Routes.effect('POST', '/tests/init', (data: { session: string }) => {
+        c.recordAlive(data.session);
+        return resetMousePositionAction(true);
       }),
-      Routes.effect('POST', '/tests/init', () => resetMousePositionAction(true)),
       Routes.effect('POST', '/tests/start', (data: StartData) => {
         c.recordTestResults(data.session, data.results);
         c.recordTestStart(data.session, data.name, data.file, data.number, data.totalTests);

modules/server/src/main/ts/bedrock/server/Controller.ts

@@ -35,6 +35,8 @@ interface TestSession {
   readonly lookup: Record<string, Record<string, number>>;
   alive: number;
   updated: number;
+  pings: number;
+  pingsAtLastProgress: number;
   previous: PreviousTest | null;
   done: boolean;
   error?: string;
@@ -51,6 +53,23 @@ export interface Controller {
   readonly awaitDone: () => Promise<TestResults>;
 }
 
+/*
+ * How long the browser may go without contacting the server at all before we treat the driver
+ * as dead. Every route bumps `session.alive`, and the runner posts on a fixed heartbeat whether
+ * or not a test has finished, so silence for this long means nothing is getting through.
+ */
+const LIVENESS_TIMEOUT = 55 * 1000;
+
+/*
+ * How many client pings may arrive without a single test finishing before we treat the run as
+ * stuck. The runner posts on a fixed interval whether or not a test has completed, so this is
+ * deliberately a count and not a duration: a link that halves in speed stretches the tolerance
+ * by the same factor instead of tripping it, which a wall-clock budget cannot do. The count times
+ * the heartbeat interval must stay above the longest single-test timeout in use, or one
+ * slow-but-legal test would be mistaken for a stuck run.
+ */
+const STALE_PINGS = 4;
+
 export const create = (stickyFirstSession: boolean, overallTimeout: number, testfiles: string[], loglevel: 'simple' | 'advanced'): Controller => {
   const hud = Hud.create(testfiles, loglevel);
   const sessions: Record<string, TestSession> = {};
@@ -84,6 +103,8 @@ export const create = (stickyFirstSession: boolean, overallTimeout: number, test
         id: sessionId,
         alive: now,
         updated: now,
+        pings: 0,
+        pingsAtLastProgress: 0,
         results: [],
         lookup: {},
         previous: null,
@@ -122,6 +143,7 @@ export const create = (stickyFirstSession: boolean, overallTimeout: number, test
     const session = getSession(id);
     const now = Date.now();
     session.updated = now;
+    session.pingsAtLastProgress = session.pings;
     session.totalTests = totalTests;
     session.currentTest = currentCount;
     session.done = false;
@@ -154,9 +176,14 @@ export const create = (stickyFirstSession: boolean, overallTimeout: number, test
   const recordTestResults = (id: string, results: TestResult[]) => {
     const now = Date.now();
     const session = getSession(id);
-    session.updated = now;
-    session.done = false;
+    // Every post counts as a ping, including the empty ones the runner sends on its heartbeat.
+    // Only a post that actually carries results counts as progress, otherwise the heartbeat
+    // would keep feeding the very clock it exists to let us read.
+    session.pings++;
     if (results.length > 0) {
+      session.updated = now;
+      session.done = false;
+      session.pingsAtLastProgress = session.pings;
       const {name, file} = results.slice(-1)[0];
       session.previous = {
         name,
@@ -179,6 +206,7 @@ export const create = (stickyFirstSession: boolean, overallTimeout: number, test
       session.currentTest = session.totalTests;
     }
     session.updated = Date.now();
+    session.pingsAtLastProgress = session.pings;
     updateHud(session);
   };
 
@@ -203,6 +231,11 @@ export const create = (stickyFirstSession: boolean, overallTimeout: number, test
       return Promise.reject({message, results, start, now});
     }
     return new Promise((resolve, reject) => {
+      const failRun = (message: string, results: TestResult[], now: number) => {
+        reject({message, results, start, now});
+        clearInterval(poller);
+        timeoutError = true;
+      };
       const poller = setInterval(() => {
         const now = Date.now();
         const allElapsed = now - start;
@@ -218,12 +251,14 @@ export const create = (stickyFirstSession: boolean, overallTimeout: number, test
             }
             clearInterval(poller);
           } else {
-             if ((now - session.updated) > (55 * 1000)) {
-              // sticky sessions have longer before they time out, but we still can't sit around if the driver has failed
-              const message = `No updates from the browser in ${formatTime(now - session.updated)}, assuming driver has failed.`;
-              reject({message, results, start, now});
-              clearInterval(poller);
-              timeoutError = true;
+             if ((now - session.alive) > LIVENESS_TIMEOUT) {
+              // nothing at all is reaching us: the driver really has failed
+              failRun(`No updates from the browser in ${formatTime(now - session.alive)}, assuming driver has failed.`, results, now);
+            } else if ((session.pings - session.pingsAtLastProgress) >= STALE_PINGS) {
+              // the browser is still talking to us, it just isn't finishing tests
+              failRun(`No test progress for ${session.pings - session.pingsAtLastProgress} client pings ` +
+                  `(${formatTime(now - session.updated)}), but the browser is still responding. ` +
+                  `Assuming the run is stuck. Limit is set to ${STALE_PINGS} pings.`, results, now);
             } else if (allElapsed > overallTimeout) {
               // combined tests took too long
               let lastTest;
@@ -240,18 +275,12 @@ export const create = (stickyFirstSession: boolean, overallTimeout: number, test
               const estimatedTotal = Math.ceil(((allElapsed / session.results.length) * testfiles.length) / 1000) * 1000;
               const message = 'Tests timed out: ' + formatTime(allElapsed) + '. Limit is set to ' + formatTime(overallTimeout) +
                   '. Estimated required time ' + formatTime(estimatedTotal) + '.\n' + lastTest + '\nTop 10 longest running tests:\n' + longest;
-              reject({message, results, start, now});
-              clearInterval(poller);
-              timeoutError = true;
+              failRun(message, results, now);
             }
           }
         } else if (allElapsed > overallTimeout) {
           // combined tests took too long
-          const message = 'Tests took too long to start';
-          const results: TestResult[] = [];
-          reject({message, results, start, now});
-          clearInterval(poller);
-          timeoutError = true;
+          failRun('Tests took too long to start', [], now);
         }
       }, 1000);
     });