Processing timeout

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;

src/utils.js

@@ -114,23 +114,55 @@ 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(<message>) if <promise> doesn't settle within <ms> 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 <debug> 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)) {
 				yield message;
 			}
 		}
 		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)) {

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();
 	}
 };

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', () => {