From f3653abe926c8486f0177f2ef05b0cac0eab5f01 Mon Sep 17 00:00:00 2001 From: Richard van der Hoff <1389908+richvdh@users.noreply.github.com> Date: Mon, 24 Mar 2025 16:43:53 +0000 Subject: [PATCH] Fix bug which caused startup to hang if the clock was wound back since a previous session (#29558) * SessionLock: reduce the stale time 30 seconds staring at a spinner while we wait for a stale lock to expire is rather painful. Pretty sure 15 seconds will be fine. * SessionLock: deal with the clock having been wound back If a previous session terminated uncleanly, and then the clock is wound back, we could be waiting a very long time for the previous session's claim to expire. We can fix this by simply treating a future claim the same as "now", and waiting for the normal stale timeout. * fixup! SessionLock: deal with the clock having been wound back --- src/utils/SessionLock.ts | 19 +++++++++-- test/unit-tests/utils/SessionLock-test.ts | 40 +++++++++++++++++++++-- 2 files changed, 53 insertions(+), 6 deletions(-) diff --git a/src/utils/SessionLock.ts b/src/utils/SessionLock.ts index 861c87ead5..c93097aba1 100644 --- a/src/utils/SessionLock.ts +++ b/src/utils/SessionLock.ts @@ -57,7 +57,7 @@ export const SESSION_LOCK_CONSTANTS = { /** * The number of milliseconds after which we consider a lock claim stale */ - LOCK_EXPIRY_TIME_MS: 30000, + LOCK_EXPIRY_TIME_MS: 15000, }; /** @@ -140,7 +140,10 @@ export async function getSessionLock(onNewInstance: () => Promise): Promis } const timeAgo = Date.now() - parseInt(lastPingTime); - const remaining = SESSION_LOCK_CONSTANTS.LOCK_EXPIRY_TIME_MS - timeAgo; + // If the last ping time is in the future (i.e., timeAgo is negative), the chances are that the system clock has + // been wound back since the ping. Rather than waiting hours/days/millenia for us to get there, treat a future + // ping as "just now" by clipping to 0. + const remaining = SESSION_LOCK_CONSTANTS.LOCK_EXPIRY_TIME_MS - Math.max(timeAgo, 0); if (remaining <= 0) { // another session claimed the lock, but it is stale. prefixedLogger.info(`Last ping (from ${lockHolder}) was ${timeAgo}ms ago: proceeding with startup`); @@ -242,13 +245,23 @@ export async function getSessionLock(onNewInstance: () => Promise): Promis }; }); + // We construct our own promise here rather than using the `sleep` utility, to make it easier to test the + // SessionLock in a separate Window. const sleepPromise = new Promise((resolve) => { setTimeout(resolve, remaining, undefined); }); window.addEventListener("storage", onStorageUpdate!); - await Promise.race([sleepPromise, storageUpdatePromise]); + const winner = await Promise.race([sleepPromise, storageUpdatePromise]); window.removeEventListener("storage", onStorageUpdate!); + + // If we got through the whole of the sleep without any writes to the store, we know that the + // ping is now stale. There's no point in going round and calling `checkLock` again: we know that + // nothing has changed since last time. + if (!(winner instanceof StorageEvent)) { + prefixedLogger.info("Existing claim went stale: proceeding with startup"); + break; + } } // If we get here, we know the lock is ours for the taking. diff --git a/test/unit-tests/utils/SessionLock-test.ts b/test/unit-tests/utils/SessionLock-test.ts index fb3ab7e6ea..67202c7193 100644 --- a/test/unit-tests/utils/SessionLock-test.ts +++ b/test/unit-tests/utils/SessionLock-test.ts @@ -71,15 +71,15 @@ describe("SessionLock", () => { jest.advanceTimersByTime(5000); expect(checkSessionLockFree()).toBe(false); - // second instance tries to start. This should block for 25 more seconds + // second instance tries to start. This should block for 10 more seconds const onNewInstance2 = jest.fn(); let session2Result: boolean | undefined; getSessionLock(onNewInstance2).then((res) => { session2Result = res; }); - // after another 24.5 seconds, we are still waiting - jest.advanceTimersByTime(24500); + // after another 9.5 seconds, we are still waiting + jest.advanceTimersByTime(9500); expect(session2Result).toBe(undefined); expect(checkSessionLockFree()).toBe(false); @@ -92,6 +92,40 @@ describe("SessionLock", () => { expect(onNewInstance2).not.toHaveBeenCalled(); }); + it("A second instance starts up when the first terminated uncleanly and the clock was wound back", async () => { + // first instance starts... + expect(await getSessionLock(() => Promise.resolve())).toBe(true); + expect(checkSessionLockFree()).toBe(false); + + // oops, now it dies. We simulate this by forcibly clearing the timers. + const time = Date.now(); + jest.clearAllTimers(); + expect(checkSessionLockFree()).toBe(false); + + // Now, the clock gets wound back an hour. + jest.setSystemTime(time - 3600 * 1000); + expect(checkSessionLockFree()).toBe(false); + + // second instance tries to start. This should block for 15 seconds + const onNewInstance2 = jest.fn(); + let session2Result: boolean | undefined; + getSessionLock(onNewInstance2).then((res) => { + session2Result = res; + }); + + // after another 14.5 seconds, we are still waiting + jest.advanceTimersByTime(14500); + expect(session2Result).toBe(undefined); + expect(checkSessionLockFree()).toBe(false); + + // another 500ms and we get the lock + await jest.advanceTimersByTimeAsync(500); + expect(session2Result).toBe(true); + expect(checkSessionLockFree()).toBe(false); // still false, because the new session has claimed it + + expect(onNewInstance2).not.toHaveBeenCalled(); + }); + it("A second instance waits for the first to shut down", async () => { // first instance starts. Once it gets the shutdown signal, it will wait two seconds and then release the lock. await getSessionLock(