diff --git a/src/renderer/hooks/use-project-picker-data.hook.test.ts b/src/renderer/hooks/use-project-picker-data.hook.test.ts index 57771cc470f..59bf5ba9ab8 100644 --- a/src/renderer/hooks/use-project-picker-data.hook.test.ts +++ b/src/renderer/hooks/use-project-picker-data.hook.test.ts @@ -2,7 +2,11 @@ import { renderHook, act } from '@testing-library/react'; import '@testing-library/jest-dom'; import { vi } from 'vitest'; import { EVENT_NAME_ON_DID_UPDATE_WEB_VIEW } from '@shared/services/web-view.service-model'; -import { useProjectPickerData, type ProjectPickerData } from './use-project-picker-data.hook'; +import { + useProjectPickerData, + type ProjectPickerData, + MAX_METADATA_FETCH_RETRIES, +} from './use-project-picker-data.hook'; // --- Mocks --- @@ -584,5 +588,361 @@ describe('useProjectPickerData', () => { expect(projectLookupService.getMetadataForAllProjects).toHaveBeenCalledTimes(2); }); + + it('re-fetches metadata when a PDP factory registers via object:onDidCreateNetworkObject (healing)', async () => { + // Reproduces the race: the 30-second startup grace window in + // internalGetMetadataWithRetries expires before the USJ-providing layering PDPF + // (Scripture Extender) registers. The initial metadata fetch returns empty because no + // factory providing platformScripture.USJ_Chapter has registered yet. When the PDPF + // later registers, the network object service emits object:onDidCreateNetworkObject. + // The hook must subscribe to that event and refresh when the new object is a pdpFactory, + // so the project list heals without waiting for an unrelated extension reload or + // project-list change event. The refresh fires after PDPF_REGISTRATION_DEBOUNCE_MS so + // that a burst of registrations collapses to a single fan-out; fake timers advance past it. + vi.useFakeTimers(); + try { + const { getNetworkEvent, projectLookupService } = await importMocks(); + let pdpfRegistrationCallback: ((details: { objectType: string }) => void) | undefined; + vi.mocked(getNetworkEvent).mockImplementation( + (eventName: string) => + vi.fn((cb: (details: { objectType: string }) => void) => { + if (eventName === 'object:onDidCreateNetworkObject') pdpfRegistrationCallback = cb; + return vi.fn(); + }) as never, + ); + + // First fetch: grace window expired, USJ-providing layering PDPF not yet registered. + vi.mocked(projectLookupService.getMetadataForAllProjects) + .mockResolvedValueOnce([] as never) + // Second fetch after PDPF registers: project list now available. + .mockResolvedValue( + metadataList([ + { id: 'p1', fullName: 'Full p1', name: 'Short p1', isEditable: true }, + ]) as never, + ); + + const { result } = renderHook(() => useProjectPickerData()); + await settle(result); + // Initial state: empty because the layering PDPF providing USJ_Chapter has not + // registered yet (grace window already expired). + expect(result.current.allProjects).toHaveLength(0); + + // The USJ-providing layering PDPF registers after the grace window. + expect(pdpfRegistrationCallback).toBeDefined(); + act(() => pdpfRegistrationCallback!({ objectType: 'pdpFactory' })); + + // Advance past the debounce delay so the buffered refresh fires. + await act(async () => { + await vi.advanceTimersByTimeAsync(250); + }); + await settle(result); + // The hook must detect the PDPF registration and re-fetch metadata so the list heals. + expect(projectLookupService.getMetadataForAllProjects).toHaveBeenCalledTimes(2); + expect(result.current.allProjects).toHaveLength(1); + expect(result.current.allProjects[0].id).toBe('p1'); + } finally { + vi.useRealTimers(); + } + }); + + it('heals allProjects after a timed-out metadata fetch once the retry resolves (timeout recovery)', async () => { + // Reproduces the scenario observed in console logs where getAvailableProjects times out + // (JSON-RPC 30-second timeout) because the extension host is overloaded at startup. The + // late response is discarded ("Ignoring subsequent resolution"), leaving the picker empty. + // After METADATA_FETCH_RETRY_DELAY_MS the hook must issue a fresh fetch — by which time the + // extension host has drained its queue and responds quickly. + vi.useFakeTimers(); + try { + const { projectLookupService } = await importMocks(); + vi.mocked(projectLookupService.getMetadataForAllProjects) + .mockRejectedValueOnce(new Error('JSON-RPC Request timed out')) + .mockResolvedValue( + metadataList([ + { id: 'p1', fullName: 'Full p1', name: 'Short p1', isEditable: true }, + ]) as never, + ); + + const { result } = renderHook(() => useProjectPickerData()); + await settle(result); + + // First fetch timed out — picker is empty + expect(result.current.allProjects).toHaveLength(0); + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes(1); + + // Advance past the retry delay + await act(async () => { + await vi.runAllTimersAsync(); + }); + await settle(result); + + // Retry resolved — picker healed + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes(2); + expect(result.current.allProjects).toHaveLength(1); + expect(result.current.allProjects[0].id).toBe('p1'); + } finally { + vi.useRealTimers(); + } + }); + + it('stops retrying metadata after MAX_METADATA_FETCH_RETRIES consecutive failures', async () => { + // Guards against an infinite retry loop when the extension host is permanently unavailable. + // After MAX_METADATA_FETCH_RETRIES failures the hook must stop scheduling retries. + vi.useFakeTimers(); + try { + const { projectLookupService } = await importMocks(); + vi.mocked(projectLookupService.getMetadataForAllProjects).mockRejectedValue( + new Error('Persistent failure'), + ); + + const { result } = renderHook(() => useProjectPickerData()); + await settle(result); + + // Drive through all allowed retries + for (let i = 0; i < MAX_METADATA_FETCH_RETRIES; i += 1) { + // Each iteration must be sequential: advance the timer first, then drain the resulting + // async work before the next retry cycle starts. + // eslint-disable-next-line no-await-in-loop + await act(async () => { + await vi.runAllTimersAsync(); + }); + // Same reason as above: sequential drain after each timer advance. + // eslint-disable-next-line no-await-in-loop + await settle(result); + } + + const callCountAfterExhaustion = vi.mocked(projectLookupService.getMetadataForAllProjects) + .mock.calls.length; + expect(callCountAfterExhaustion).toBe(1 + MAX_METADATA_FETCH_RETRIES); + + // One more timer advance must NOT trigger an additional fetch + await act(async () => { + await vi.runAllTimersAsync(); + }); + await settle(result); + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes( + callCountAfterExhaustion, + ); + } finally { + vi.useRealTimers(); + } + }); + + it('does not re-fetch metadata when object:onDidCreateNetworkObject fires for a non-PDPF network object', async () => { + // Only PDP factory registrations should heal the project list. Registrations of other + // network object types (PDPs, services, etc.) must not trigger an unnecessary metadata + // fan-out, since those fan-outs are expensive (one PAPI round-trip per registered PDPF). + const { getNetworkEvent, projectLookupService } = await importMocks(); + let networkObjectCallback: ((details: { objectType: string }) => void) | undefined; + vi.mocked(getNetworkEvent).mockImplementation( + (eventName: string) => + vi.fn((cb: (details: { objectType: string }) => void) => { + if (eventName === 'object:onDidCreateNetworkObject') networkObjectCallback = cb; + return vi.fn(); + }) as never, + ); + vi.mocked(projectLookupService.getMetadataForAllProjects).mockResolvedValue( + metadataList([ + { id: 'p1', fullName: 'Full p1', name: 'Short p1', isEditable: true }, + ]) as never, + ); + + const { result } = renderHook(() => useProjectPickerData()); + await settle(result); + expect(projectLookupService.getMetadataForAllProjects).toHaveBeenCalledTimes(1); + + expect(networkObjectCallback).toBeDefined(); + // A non-PDPF network object registers (e.g. a data provider or a service). + act(() => networkObjectCallback!({ objectType: 'networkObject' })); + await settle(result); + + // Must NOT re-fetch: only PDPF registrations should invalidate the metadata cache. + expect(projectLookupService.getMetadataForAllProjects).toHaveBeenCalledTimes(1); + }); + + it('cancels the pending retry timer when a concurrent refresh heals the list (spurious Fetch C)', async () => { + // Reproduces the race where Fetch A fails (isRetryPending=true, 5-second timer scheduled), + // then an external PDPF registration fires while the timer is still running. Fetch B (triggered + // by the PDPF) succeeds and heals the list. The timer must be cancelled so it does not fire a + // spurious Fetch C after healing — the fix is setIsRetryPending(false) in the success path of + // getAllMetadata, which triggers the useEffect cleanup that calls clearTimeout. + vi.useFakeTimers(); + try { + const { projectLookupService, getNetworkEvent } = await importMocks(); + let pdpfCallback: ((d: { objectType: string }) => void) | undefined; + vi.mocked(getNetworkEvent).mockImplementation( + (eventName: string) => + vi.fn((cb: (d: { objectType: string }) => void) => { + if (eventName === 'object:onDidCreateNetworkObject') pdpfCallback = cb; + return vi.fn(); + }) as never, + ); + vi.mocked(projectLookupService.getMetadataForAllProjects) + .mockRejectedValueOnce(new Error('JSON-RPC timed out')) // Fetch A fails + .mockResolvedValue( + metadataList([ + { id: 'p1', fullName: 'Full p1', name: 'Short p1', isEditable: true }, + ]) as never, + ); // Fetch B+ succeeds + + const { result } = renderHook(() => useProjectPickerData()); + await settle(result); + // Fetch A failed; isRetryPending=true, 5-second timer scheduled. + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes(1); + expect(result.current.allProjects).toHaveLength(0); + + // PDPF registers → schedules debounced Fetch B. Advance past the debounce delay to fire it. + expect(pdpfCallback).toBeDefined(); + act(() => pdpfCallback!({ objectType: 'pdpFactory' })); + await act(async () => { + await vi.advanceTimersByTimeAsync(250); + }); + await settle(result); + // Fetch B healed the project list. + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes(2); + expect(result.current.allProjects).toHaveLength(1); + + // Advance remaining timers (retry timer from Fetch A should have been cancelled by Fetch B's + // success path setting isRetryPending=false). + await act(async () => { + await vi.runAllTimersAsync(); + }); + await settle(result); + + // No spurious Fetch C: the list healed in Fetch B; no unnecessary fan-out after. + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes(2); + } finally { + vi.useRealTimers(); + } + }); + + it('stale-generation success does not reset the retry budget for a newer failing generation (cap integrity)', async () => { + // Reproduces the race where a slow in-flight Gen A promise (up to 30 s in the service's + // startup retry loop) resolves after a newer Gen B+ has already exhausted part of its retry + // budget. Gen A's unguarded .then() must NOT reset fetchRetryCountRef.current, or subsequent + // Gen B+ failures get a fresh budget and can exceed MAX_METADATA_FETCH_RETRIES total retries. + vi.useFakeTimers(); + try { + const { projectLookupService, getNetworkEvent } = await importMocks(); + + // Gen A: manually controlled — we will resolve it late, after Gen B+ has been retrying. + let resolveGenA: (v: never) => void = () => {}; + const genAPromise = new Promise((resolve) => { + resolveGenA = resolve; + }); + + let pdpfCallback: ((d: { objectType: string }) => void) | undefined; + vi.mocked(getNetworkEvent).mockImplementation( + (eventName: string) => + vi.fn((cb: (d: { objectType: string }) => void) => { + if (eventName === 'object:onDidCreateNetworkObject') pdpfCallback = cb; + return vi.fn(); + }) as never, + ); + + vi.mocked(projectLookupService.getMetadataForAllProjects) + .mockReturnValueOnce(genAPromise as never) // Gen A: in-flight, will resolve late + .mockRejectedValue(new Error('Timeout')); // All subsequent generations fail + + const { result } = renderHook(() => useProjectPickerData()); + await settle(result); + // Gen A is in-flight. + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes(1); + + // PDPF registers → schedules debounced Gen B. Advance past the debounce delay to fire it. + expect(pdpfCallback).toBeDefined(); + act(() => pdpfCallback!({ objectType: 'pdpFactory' })); + await act(async () => { + await vi.advanceTimersByTimeAsync(250); + }); + await settle(result); + // Gen B started and failed; isRetryPending=true. + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes(2); + + // Advance through 2 retries (Gen C, Gen D) so the counter is partway through the budget. + for (let i = 0; i < 2; i += 1) { + // Sequential: advance timer then drain before the next retry cycle. + // eslint-disable-next-line no-await-in-loop + await act(async () => { + await vi.runAllTimersAsync(); + }); + // Same reason as above: sequential drain after each timer advance. + // eslint-disable-next-line no-await-in-loop + await settle(result); + } + // Calls so far: GenA(1) + GenB(1) + retry1(1) + retry2(1) = 4 + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes(4); + + // Gen A resolves late (stale). Without the generation guard, its .then() resets the counter + // to 0, allowing more than MAX_METADATA_FETCH_RETRIES total retries. With the fix, the guard + // sees metadataFetchRef.current !== entry-A and skips the reset. + await act(async () => { + resolveGenA([] as never); + }); + await settle(result); + + // Advance through what should be the LAST retry (retry 3 = Gen E). + await act(async () => { + await vi.runAllTimersAsync(); + }); + await settle(result); + // Calls: GenA + GenB + retry1 + retry2 + retry3(last) = 5 + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes(5); + + // Budget exhausted — no more retries regardless of timer advances. + await act(async () => { + await vi.runAllTimersAsync(); + }); + await settle(result); + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes(5); + } finally { + vi.useRealTimers(); + } + }); + + it('multiple rapid PDPF registrations trigger only one getMetadataForAllProjects fan-out (debounce)', async () => { + // When PDPFs re-register after extension reload they arrive as separate WebSocket messages, + // so React cannot batch the resulting refreshMetadata() calls. Each would normally fan out + // getMetadataForAllProjects to every registered PDPF; the fix debounces the PDPF-registration + // listener so a burst collapses to a single re-fetch. + vi.useFakeTimers(); + try { + const { projectLookupService, getNetworkEvent } = await importMocks(); + let pdpfCallback: ((d: { objectType: string }) => void) | undefined; + vi.mocked(getNetworkEvent).mockImplementation( + (eventName: string) => + vi.fn((cb: (d: { objectType: string }) => void) => { + if (eventName === 'object:onDidCreateNetworkObject') pdpfCallback = cb; + return vi.fn(); + }) as never, + ); + vi.mocked(projectLookupService.getMetadataForAllProjects).mockResolvedValue([] as never); + + const { result } = renderHook(() => useProjectPickerData()); + await settle(result); + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes(1); + + // Fire 3 PDPF registrations synchronously within one act. Each callback cancels the + // previous debounce timer and schedules a new one; only the last timer survives. + // Using a single act ensures no timer fires between callbacks (async act can advance + // fake timers between awaits, which would defeat the debounce). + expect(pdpfCallback).toBeDefined(); + act(() => { + pdpfCallback!({ objectType: 'pdpFactory' }); + pdpfCallback!({ objectType: 'pdpFactory' }); + pdpfCallback!({ objectType: 'pdpFactory' }); + }); + + // Advance timers to fire the single surviving debounced refresh. + await act(async () => { + await vi.runAllTimersAsync(); + }); + await settle(result); + + // With debouncing: initial(1) + debounced-refresh(1) = 2 total calls, not 4. + expect(vi.mocked(projectLookupService.getMetadataForAllProjects)).toHaveBeenCalledTimes(2); + } finally { + vi.useRealTimers(); + } + }); }); /* eslint-enable no-type-assertion/no-type-assertion */ diff --git a/src/renderer/hooks/use-project-picker-data.hook.ts b/src/renderer/hooks/use-project-picker-data.hook.ts index 32e838d5ec9..febdee731b4 100644 --- a/src/renderer/hooks/use-project-picker-data.hook.ts +++ b/src/renderer/hooks/use-project-picker-data.hook.ts @@ -1,12 +1,16 @@ import { useData } from '@renderer/hooks/papi-hooks'; import { useEvent, usePromise } from 'platform-bible-react'; -import { useCallback, useMemo, useRef, useState } from 'react'; +import { useCallback, useEffect, useMemo, useRef, useState } from 'react'; import { getNetworkEvent } from '@shared/services/network.service'; import { webViews } from '@renderer/services/papi-frontend.service'; import { projectLookupService } from '@shared/services/project-lookup.service'; import { normalizeProjectId } from '@shared/models/project-lookup.service-model'; import { type ProjectMetadata } from '@shared/models/project-metadata.model'; -import { type ProjectMetadataFilterOptions } from '@shared/models/project-data-provider-factory.interface'; +import { + PDP_FACTORY_OBJECT_TYPE, + type ProjectMetadataFilterOptions, +} from '@shared/models/project-data-provider-factory.interface'; +import { type NetworkObjectDetails } from '@shared/models/network-object.model'; import { EVENT_NAME_ON_DID_CLOSE_WEB_VIEW, EVENT_NAME_ON_DID_OPEN_WEB_VIEW, @@ -17,6 +21,17 @@ import { logger } from '@shared/services/logger.service'; import { findFirstEditorWebViewDefinition } from '@shared/models/web-view.model'; import { type ProjectItem } from '@renderer/components/projects/project-picker.component'; +/** How long to wait before retrying a failed metadata fetch. */ +const METADATA_FETCH_RETRY_DELAY_MS = 5 * 1000; +/** + * Maximum number of consecutive metadata fetch failures before the hook stops retrying. After this + * many failures the picker stays empty until the next external refresh signal (e.g. an extension + * reload or a PDPF registration). + */ +export const MAX_METADATA_FETCH_RETRIES = 3; +/** Debounce window that collapses rapid-fire PDPF registrations into a single metadata fan-out. */ +const PDPF_REGISTRATION_DEBOUNCE_MS = 200; + /** * `projectInterface` a project must support to belong in the picker: it can be opened in the * scripture editor. This filter is applied service-side so the service's retry-until-non-empty @@ -98,6 +113,13 @@ export function useProjectPickerData(): ProjectPickerData { const [currentProjectError, setCurrentProjectError] = useState(undefined); const refreshMetadata = useCallback(() => setMetadataRefreshCounter((n) => n + 1), []); const refreshActiveEditor = useCallback(() => setWebViewRefreshCounter((n) => n + 1), []); + // When getMetadataForAllProjects rejects (e.g. a PDPF's getAvailableProjects RPC times out + // during startup), isRetryPending becomes true and the effect below schedules a re-fetch after + // METADATA_FETCH_RETRY_DELAY_MS — by which time the extension host has typically drained its + // queue and responds quickly. fetchRetryCountRef caps consecutive retries so a permanently + // unavailable host does not loop forever. + const [isRetryPending, setIsRetryPending] = useState(false); + const fetchRetryCountRef = useRef(0); const onDidOpenWebView = useMemo(() => getNetworkEvent(EVENT_NAME_ON_DID_OPEN_WEB_VIEW), []); useEvent(onDidOpenWebView, refreshActiveEditor); @@ -116,6 +138,43 @@ export function useProjectPickerData(): ProjectPickerData { // three sections refetch. const onDidChangeProjects = useMemo(() => getNetworkEvent('platform.onDidChangeProjects'), []); useEvent(onDidChangeProjects, refreshMetadata); + // Heal the project list when a PDP factory registers after the startup grace window expires. + // internalGetMetadataWithRetries only retries within 30 s of process start; if the + // USJ-providing layering PDPF (Scripture Extender) arrives after that window AND neither + // onDidReloadExtensions nor onDidChangeProjects fires, the picker stays empty until the user + // triggers an unrelated refresh. Subscribing here ensures a late-arriving PDPF always heals + // the list independent of the 30-second bound. + const onDidCreateNetworkObject = useMemo( + () => getNetworkEvent('object:onDidCreateNetworkObject'), + [], + ); + // Debounce to collapse N rapid-fire PDPF registrations (e.g. after extension reload) into a + // single getMetadataForAllProjects fan-out. Without debouncing, each registration arrives as a + // separate WebSocket message that React 18 cannot batch, producing N wasted fan-outs. + const pdpfRefreshTimerRef = useRef | undefined>(undefined); + const onPdpFactoryRegistered = useCallback( + ({ objectType }: NetworkObjectDetails) => { + if (objectType !== PDP_FACTORY_OBJECT_TYPE) return; + clearTimeout(pdpfRefreshTimerRef.current); + pdpfRefreshTimerRef.current = setTimeout(refreshMetadata, PDPF_REGISTRATION_DEBOUNCE_MS); + }, + [refreshMetadata], + ); + useEvent(onDidCreateNetworkObject, onPdpFactoryRegistered); + // Cancel any pending debounced refresh on unmount to prevent state updates after teardown. + useEffect(() => () => clearTimeout(pdpfRefreshTimerRef.current), []); + // After a failed metadata fetch, wait METADATA_FETCH_RETRY_DELAY_MS before trying again. + // The timer is cancelled if the hook unmounts before it fires, preventing state updates on an + // unmounted component and avoiding spurious fan-outs when the user closes the picker quickly. + useEffect(() => { + if (!isRetryPending) return undefined; + const timeout = setTimeout(() => { + fetchRetryCountRef.current += 1; + setIsRetryPending(false); + refreshMetadata(); + }, METADATA_FETCH_RETRY_DELAY_MS); + return () => clearTimeout(timeout); + }, [isRetryPending, refreshMetadata]); // Recent project IDs from the service — reactive, updates when user opens projects const [rawRecentIds, , isRecentIdsLoading] = useData( @@ -144,11 +203,39 @@ export function useProjectPickerData(): ProjectPickerData { counter: metadataRefreshCounter, promise: projectLookupService.getMetadataForAllProjects(PICKER_METADATA_FILTER), }; - // Invalidate this generation if its fetch rejects, but only if it's still the current entry so - // a newer generation isn't clobbered. - entry.promise.catch(() => { - if (metadataFetchRef.current === entry) metadataFetchRef.current = undefined; - }); + // Attach success and failure handlers as the two arguments of .then() rather than as a + // .then().catch() chain. In the chained form, the .catch() sees both fetch rejections AND + // exceptions thrown by the success handler — silently mis-routing a future handler bug as a + // fetch failure. The two-argument form keeps the handlers independent: an exception in + // onFulfilled does not reach onRejected. The trailing .catch(() => undefined) satisfies the + // ESLint promise/catch-or-return rule (the plugin does not recognise the two-argument form + // as sufficient) and catches any exception from either handler; neither handler can throw in + // practice (ref reads + setState), so this is purely a safety net. + entry.promise + .then( + () => { + // Guard: only reset retry state for the current generation so a stale in-flight promise + // that resolves late cannot corrupt the retry budget or spuriously cancel the timer of + // the generation currently in the cache. + if (metadataFetchRef.current === entry) { + fetchRetryCountRef.current = 0; + // Cancels any pending retry timer: setIsRetryPending(false) triggers the useEffect + // cleanup (clearTimeout) so the timer does not fire a redundant fan-out after healing. + setIsRetryPending(false); + } + return undefined; + }, + () => { + if (metadataFetchRef.current === entry) { + metadataFetchRef.current = undefined; + if (fetchRetryCountRef.current < MAX_METADATA_FETCH_RETRIES) { + setIsRetryPending(true); + } + } + return undefined; + }, + ) + .catch(() => undefined); metadataFetchRef.current = entry; return entry.promise; }, [metadataRefreshCounter]);