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
This commit is contained in:
committed by
GitHub
parent
a6e8d512d0
commit
f3653abe92
@@ -57,7 +57,7 @@ export const SESSION_LOCK_CONSTANTS = {
|
|||||||
/**
|
/**
|
||||||
* The number of milliseconds after which we consider a lock claim stale
|
* 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<void>): Promis
|
|||||||
}
|
}
|
||||||
|
|
||||||
const timeAgo = Date.now() - parseInt(lastPingTime);
|
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) {
|
if (remaining <= 0) {
|
||||||
// another session claimed the lock, but it is stale.
|
// another session claimed the lock, but it is stale.
|
||||||
prefixedLogger.info(`Last ping (from ${lockHolder}) was ${timeAgo}ms ago: proceeding with startup`);
|
prefixedLogger.info(`Last ping (from ${lockHolder}) was ${timeAgo}ms ago: proceeding with startup`);
|
||||||
@@ -242,13 +245,23 @@ export async function getSessionLock(onNewInstance: () => Promise<void>): 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) => {
|
const sleepPromise = new Promise((resolve) => {
|
||||||
setTimeout(resolve, remaining, undefined);
|
setTimeout(resolve, remaining, undefined);
|
||||||
});
|
});
|
||||||
|
|
||||||
window.addEventListener("storage", onStorageUpdate!);
|
window.addEventListener("storage", onStorageUpdate!);
|
||||||
await Promise.race([sleepPromise, storageUpdatePromise]);
|
const winner = await Promise.race([sleepPromise, storageUpdatePromise]);
|
||||||
window.removeEventListener("storage", onStorageUpdate!);
|
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.
|
// If we get here, we know the lock is ours for the taking.
|
||||||
|
|||||||
@@ -71,15 +71,15 @@ describe("SessionLock", () => {
|
|||||||
jest.advanceTimersByTime(5000);
|
jest.advanceTimersByTime(5000);
|
||||||
expect(checkSessionLockFree()).toBe(false);
|
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();
|
const onNewInstance2 = jest.fn();
|
||||||
let session2Result: boolean | undefined;
|
let session2Result: boolean | undefined;
|
||||||
getSessionLock(onNewInstance2).then((res) => {
|
getSessionLock(onNewInstance2).then((res) => {
|
||||||
session2Result = res;
|
session2Result = res;
|
||||||
});
|
});
|
||||||
|
|
||||||
// after another 24.5 seconds, we are still waiting
|
// after another 9.5 seconds, we are still waiting
|
||||||
jest.advanceTimersByTime(24500);
|
jest.advanceTimersByTime(9500);
|
||||||
expect(session2Result).toBe(undefined);
|
expect(session2Result).toBe(undefined);
|
||||||
expect(checkSessionLockFree()).toBe(false);
|
expect(checkSessionLockFree()).toBe(false);
|
||||||
|
|
||||||
@@ -92,6 +92,40 @@ describe("SessionLock", () => {
|
|||||||
expect(onNewInstance2).not.toHaveBeenCalled();
|
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 () => {
|
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.
|
// first instance starts. Once it gets the shutdown signal, it will wait two seconds and then release the lock.
|
||||||
await getSessionLock(
|
await getSessionLock(
|
||||||
|
|||||||
Reference in New Issue
Block a user