mirror of
https://github.com/tinyhumansai/openhuman.git
synced 2026-07-27 21:08:00 +00:00
fix(core-state): add backoff after bootstrap budget exhaustion (#2194)
Adds 10s poll backoff once the 5-retry bootstrap budget is exhausted, preventing tight retry loops during slow startup. Reverts to 2s on recovery. Builds on #2167 (debug message helper). - BACKOFF_POLL_MS = 10_000: scheduleNext uses longer delay after bootstrap exhaustion, 2s otherwise - coreStatePollFailureWarningMessage messages updated to say 'bootstrap poll failed' and 'budget exhausted; continuing with backoff' - Tests: backoff timing (fake timers), recovery revert, impossible-counter negative assertion, debug message describe block properly separated Closes #2158
This commit is contained in:
@@ -45,6 +45,7 @@ const log = debugFactory('core-state');
|
||||
const POLL_MS = 2000;
|
||||
const MAX_BOOTSTRAP_RETRIES = 5;
|
||||
const SUPPRESS_POLL_WARNING_AT = MAX_BOOTSTRAP_RETRIES + 1;
|
||||
const BACKOFF_POLL_MS = 10_000;
|
||||
|
||||
/** Extract only non-sensitive fields from an RPC/fetch error. */
|
||||
function sanitizeError(error: unknown): { message?: string; code?: string; status?: number } {
|
||||
@@ -67,10 +68,10 @@ export function coreStatePollFailureWarningMessage(failureCount: number): string
|
||||
return null;
|
||||
}
|
||||
if (failureCount <= MAX_BOOTSTRAP_RETRIES) {
|
||||
return `[core-state] poll failed (attempt ${failureCount}/${MAX_BOOTSTRAP_RETRIES}):`;
|
||||
return `[core-state] bootstrap poll failed (attempt ${failureCount}/${MAX_BOOTSTRAP_RETRIES}):`;
|
||||
}
|
||||
if (failureCount === SUPPRESS_POLL_WARNING_AT) {
|
||||
return '[core-state] poll failed repeatedly; suppressing further warnings until core state recovers:';
|
||||
return '[core-state] bootstrap budget exhausted; continuing with backoff. Suppressing further warnings until recovery:';
|
||||
}
|
||||
return null;
|
||||
}
|
||||
@@ -473,12 +474,14 @@ export default function CoreStateProvider({ children }: { children: ReactNode })
|
||||
void load();
|
||||
let timeoutId: number | null = null;
|
||||
const scheduleNext = () => {
|
||||
const delay =
|
||||
bootstrapFailCountRef.current >= MAX_BOOTSTRAP_RETRIES ? BACKOFF_POLL_MS : POLL_MS;
|
||||
timeoutId = window.setTimeout(async () => {
|
||||
await doRefresh();
|
||||
if (!cancelled) {
|
||||
scheduleNext();
|
||||
}
|
||||
}, POLL_MS);
|
||||
}, delay);
|
||||
};
|
||||
scheduleNext();
|
||||
|
||||
|
||||
@@ -268,7 +268,7 @@ describe('CoreStateProvider — identity-change cache clearing', () => {
|
||||
);
|
||||
|
||||
await waitFor(() =>
|
||||
expect(warnSpy).toHaveBeenCalledWith('[core-state] poll failed (attempt 1/5):', {
|
||||
expect(warnSpy).toHaveBeenCalledWith('[core-state] bootstrap poll failed (attempt 1/5):', {
|
||||
message: 'core offline',
|
||||
})
|
||||
);
|
||||
@@ -277,6 +277,92 @@ describe('CoreStateProvider — identity-change cache clearing', () => {
|
||||
}
|
||||
});
|
||||
|
||||
it('backs off poll interval after bootstrap budget is exhausted', async () => {
|
||||
vi.useFakeTimers();
|
||||
const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {});
|
||||
|
||||
try {
|
||||
fetchSnapshot.mockRejectedValue(new Error('core unavailable'));
|
||||
listTeams.mockResolvedValue([]);
|
||||
|
||||
render(
|
||||
<CoreStateProvider>
|
||||
<Consumer />
|
||||
</CoreStateProvider>
|
||||
);
|
||||
|
||||
// Initial load fires immediately
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(0);
|
||||
});
|
||||
|
||||
// Advance through MAX_BOOTSTRAP_RETRIES (5) polls at 2s intervals
|
||||
for (let i = 0; i < 5; i++) {
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(2000);
|
||||
});
|
||||
}
|
||||
|
||||
// After budget exhaustion, next poll fires at 10s — not at 2s
|
||||
const callsBefore = fetchSnapshot.mock.calls.length;
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(2000);
|
||||
});
|
||||
expect(fetchSnapshot.mock.calls.length).toBe(callsBefore);
|
||||
|
||||
// Advance remaining 8s (total 10s) — poll fires now
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(8000);
|
||||
});
|
||||
expect(fetchSnapshot.mock.calls.length).toBe(callsBefore + 1);
|
||||
} finally {
|
||||
vi.useRealTimers();
|
||||
warnSpy.mockRestore();
|
||||
}
|
||||
});
|
||||
|
||||
it('reverts to normal poll interval after recovery from backoff', async () => {
|
||||
vi.useFakeTimers();
|
||||
const warnSpy = vi.spyOn(console, 'warn').mockImplementation(() => {});
|
||||
|
||||
try {
|
||||
fetchSnapshot.mockRejectedValue(new Error('core unavailable'));
|
||||
listTeams.mockResolvedValue([]);
|
||||
|
||||
render(
|
||||
<CoreStateProvider>
|
||||
<Consumer />
|
||||
</CoreStateProvider>
|
||||
);
|
||||
|
||||
// Exhaust bootstrap budget: initial load + 5 scheduled polls
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(0);
|
||||
});
|
||||
for (let i = 0; i < 5; i++) {
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(2000);
|
||||
});
|
||||
}
|
||||
|
||||
// Make the next (backoff) poll succeed — resets counter to 0
|
||||
fetchSnapshot.mockResolvedValue(makeSnapshot({ userId: null, sessionToken: null }));
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(10000);
|
||||
});
|
||||
|
||||
// After recovery, the next poll should fire at the normal 2s interval
|
||||
const callsBefore = fetchSnapshot.mock.calls.length;
|
||||
await act(async () => {
|
||||
await vi.advanceTimersByTimeAsync(2000);
|
||||
});
|
||||
expect(fetchSnapshot.mock.calls.length).toBe(callsBefore + 1);
|
||||
} finally {
|
||||
vi.useRealTimers();
|
||||
warnSpy.mockRestore();
|
||||
}
|
||||
});
|
||||
|
||||
it('backfills snapshot.currentUser from auth.user when currentUser is missing', async () => {
|
||||
fetchSnapshot.mockResolvedValue(
|
||||
makeSnapshot({
|
||||
@@ -518,14 +604,32 @@ describe('CoreStateProvider — identity-change cache clearing', () => {
|
||||
describe('coreStatePollFailureWarningMessage', () => {
|
||||
it('logs bounded bootstrap failures and one suppression notice', () => {
|
||||
expect(coreStatePollFailureWarningMessage(0)).toBeNull();
|
||||
expect(coreStatePollFailureWarningMessage(1)).toBe('[core-state] poll failed (attempt 1/5):');
|
||||
expect(coreStatePollFailureWarningMessage(5)).toBe('[core-state] poll failed (attempt 5/5):');
|
||||
expect(coreStatePollFailureWarningMessage(1)).toBe(
|
||||
'[core-state] bootstrap poll failed (attempt 1/5):'
|
||||
);
|
||||
expect(coreStatePollFailureWarningMessage(5)).toBe(
|
||||
'[core-state] bootstrap poll failed (attempt 5/5):'
|
||||
);
|
||||
expect(coreStatePollFailureWarningMessage(6)).toBe(
|
||||
'[core-state] poll failed repeatedly; suppressing further warnings until core state recovers:'
|
||||
'[core-state] bootstrap budget exhausted; continuing with backoff. Suppressing further warnings until recovery:'
|
||||
);
|
||||
expect(coreStatePollFailureWarningMessage(7)).toBeNull();
|
||||
});
|
||||
|
||||
it('never produces an attempt count exceeding the max in the warning', () => {
|
||||
for (let i = 1; i <= 50; i++) {
|
||||
const msg = coreStatePollFailureWarningMessage(i);
|
||||
if (msg && msg.includes('attempt')) {
|
||||
const match = msg.match(/attempt (\d+)\/(\d+)/);
|
||||
expect(match).not.toBeNull();
|
||||
const [, attempt, max] = match!;
|
||||
expect(Number(attempt)).toBeLessThanOrEqual(Number(max));
|
||||
}
|
||||
}
|
||||
});
|
||||
});
|
||||
|
||||
describe('coreStatePollFailureDebugMessage', () => {
|
||||
it('describes post-bootstrap poll failures without impossible retry counters', () => {
|
||||
expect(coreStatePollFailureDebugMessage(0)).toBeNull();
|
||||
expect(coreStatePollFailureDebugMessage(1)).toBe(
|
||||
|
||||
Reference in New Issue
Block a user