diff --git a/src/composables/useStatsData.js b/src/composables/useStatsData.js index cd5dd08..54944ed 100644 --- a/src/composables/useStatsData.js +++ b/src/composables/useStatsData.js @@ -231,7 +231,13 @@ export function useStatsData() { let n = 0, s = 0, r = 0; - for await (let m of queryMessages(folder.id, active.period.start, active.period.end)) { + for await (let m of queryMessages( + folder.id, + active.period.start, + active.period.end, + options.debug, + folder.path + )) { const type = analyzeMessage(data, m, identityList, context); // live update numbers section if corresponding option is enabled if (options.liveCountUp) display.value.numbers = data.numbers; diff --git a/src/utils.js b/src/utils.js index a3ce3c6..0a0b268 100644 --- a/src/utils.js +++ b/src/utils.js @@ -114,15 +114,47 @@ const isSelfMessage = (message, identities) => { return true; }; +// milliseconds a single messenger.messages.list/continueList call may take before +// it's considered hung (see https://github.com/devmount/third-stats/issues/445) +const PAGE_FETCH_TIMEOUT_MS = 30000; + +// reject with an Error() if doesn't settle within milliseconds +const withTimeout = (promise, ms, message) => { + let timer; + const timeout = new Promise((_, reject) => { + timer = setTimeout(() => reject(new Error(message)), ms); + }); + return Promise.race([promise, timeout]).finally(() => clearTimeout(timer)); +}; + // generator to query messages of given folder -const queryMessages = async function* (folderId, fromDate, toDate) { +// if is true, logs timing of each list/continueList page fetch and aborts +// a single fetch that takes longer than PAGE_FETCH_TIMEOUT_MS, instead of hanging forever +const queryMessages = async function* (folderId, fromDate, toDate, debug = false, folderPath = folderId) { // handle date filter const dateFilterActive = fromDate && toDate; const from = new Date(fromDate).setUTCHours(0, 0, 0, 0); const to = new Date(toDate).setUTCHours(23, 59, 59, 999); + let pageNum = 0; + const fetchPage = (call) => { + pageNum++; + if (debug) console.debug(`⏳ ${folderPath}: fetching page ${pageNum}...`); + const start = Date.now(); + return withTimeout( + call, + PAGE_FETCH_TIMEOUT_MS, + `Timed out fetching page ${pageNum} of folder "${folderPath}" after ${PAGE_FETCH_TIMEOUT_MS}ms` + ).then((page) => { + if (debug) + console.debug( + `✅ ${folderPath}: page ${pageNum} (${page.messages.length} messages) in ${Date.now() - start}ms` + ); + return page; + }); + }; try { // paginate messages - let page = await messenger.messages.list(folderId); + let page = await fetchPage(messenger.messages.list(folderId)); for (let message of page.messages) { const messagesOutsideDateFilter = message.date < from || message.date > to; if (!(dateFilterActive && messagesOutsideDateFilter)) { @@ -130,7 +162,7 @@ const queryMessages = async function* (folderId, fromDate, toDate) { } } while (page.id) { - page = await messenger.messages.continueList(page.id); + page = await fetchPage(messenger.messages.continueList(page.id)); for (let message of page.messages) { const messagesOutsideDateFilter = message.date < from || message.date > to; if (!(dateFilterActive && messagesOutsideDateFilter)) { diff --git a/test/composables/useStatsData.spec.js b/test/composables/useStatsData.spec.js index ed29545..91ca4ee 100644 --- a/test/composables/useStatsData.spec.js +++ b/test/composables/useStatsData.spec.js @@ -81,7 +81,7 @@ const makeMessage = (overrides) => ({ // its result (or that must not leak an in-flight messenger call past their own teardown) // need many microtask turns, not just one. const flushPending = async () => { - for (let i = 0; i < 20; i++) { + for (let i = 0; i < 40; i++) { await nextTick(); } }; diff --git a/test/utils.spec.js b/test/utils.spec.js index 8de43f1..db27970 100644 --- a/test/utils.spec.js +++ b/test/utils.spec.js @@ -550,6 +550,49 @@ describe('queryMessages', () => { expect(result).toEqual([]); expect(set).toHaveBeenCalledWith({ error: true }); }); + + it('records an error and stops iterating when a page fetch hangs past the timeout (issue #445)', async () => { + vi.useFakeTimers(); + const list = vi.fn(() => new Promise(() => {})); // never resolves, simulating a hung API call + const set = vi.fn().mockResolvedValue(); + vi.stubGlobal('messenger', createMockMessenger({ messages: { list }, storage: { local: { set } } })); + vi.spyOn(console, 'error').mockImplementation(() => {}); + const result = []; + const done = (async () => { + for await (const m of queryMessages('folder-1', null, null)) result.push(m); + })(); + await vi.advanceTimersByTimeAsync(30000); + await done; + expect(result).toEqual([]); + expect(set).toHaveBeenCalledWith({ error: true }); + vi.useRealTimers(); + }); + + it('logs timing of each page fetch when debug is enabled', async () => { + const list = vi.fn().mockResolvedValue(page([{ id: 1 }], 'page-2')); + const continueList = vi.fn().mockResolvedValue(page([{ id: 2 }], null)); + vi.stubGlobal('messenger', createMockMessenger({ messages: { list, continueList } })); + const debugSpy = vi.spyOn(console, 'debug').mockImplementation(() => {}); + debugSpy.mockClear(); + const result = []; + for await (const m of queryMessages('folder-1', null, null, true, '/Inbox')) result.push(m); + expect(result).toEqual([{ id: 1 }, { id: 2 }]); + expect(debugSpy).toHaveBeenCalledWith(expect.stringContaining('/Inbox: fetching page 1')); + expect(debugSpy).toHaveBeenCalledWith(expect.stringContaining('/Inbox: page 1 (1 messages)')); + expect(debugSpy).toHaveBeenCalledWith(expect.stringContaining('/Inbox: fetching page 2')); + expect(debugSpy).toHaveBeenCalledWith(expect.stringContaining('/Inbox: page 2 (1 messages)')); + debugSpy.mockRestore(); + }); + + it('does not log anything when debug is disabled', async () => { + const list = vi.fn().mockResolvedValue(page([{ id: 1 }], null)); + vi.stubGlobal('messenger', createMockMessenger({ messages: { list } })); + const debugSpy = vi.spyOn(console, 'debug').mockImplementation(() => {}); + debugSpy.mockClear(); + for await (const m of queryMessages('folder-1', null, null)) void m; + expect(debugSpy).not.toHaveBeenCalled(); + debugSpy.mockRestore(); + }); }); describe('traverseAccount', () => {