From 57b584075ccd6d4775c9cb6f915c127979648136 Mon Sep 17 00:00:00 2001 From: Vladimir Razuvaev Date: Thu, 19 Nov 2020 19:08:52 +0700 Subject: [PATCH] fix(gatsby): get-page-data should timeout gracefully (#28131) (#28180) * fix(gatsby): get-page-data should timeout gracefully * lower timeout interval, add retries, make timeout configurable, add more tests * Update packages/gatsby/src/utils/__tests__/get-page-data.ts Co-authored-by: Vladimir Razuvaev Co-authored-by: Michal Piechowiak (cherry picked from commit c517b605b7572171607be140175be279748de7fa) --- .../src/utils/__tests__/get-page-data.ts | 334 ++++++++++++++++++ packages/gatsby/src/utils/get-page-data.ts | 71 +++- 2 files changed, 392 insertions(+), 13 deletions(-) create mode 100644 packages/gatsby/src/utils/__tests__/get-page-data.ts diff --git a/packages/gatsby/src/utils/__tests__/get-page-data.ts b/packages/gatsby/src/utils/__tests__/get-page-data.ts new file mode 100644 index 0000000000000..232208188708b --- /dev/null +++ b/packages/gatsby/src/utils/__tests__/get-page-data.ts @@ -0,0 +1,334 @@ +import { store } from "../../redux" +import { getPageData, RETRY_INTERVAL } from "../get-page-data" +import { fixedPagePath } from "../page-data" +import { + IGatsbyPage, + IGatsbyPlugin, + IQueryStartAction, +} from "../../redux/types" +import { pageQueryRun, queryStart } from "../../redux/actions/internal" +import { join as pathJoin } from "path" + +let MOCK_FILE_INFO = {} + +jest.mock(`fs-extra`, () => { + return { + readFile: jest.fn(path => { + if (MOCK_FILE_INFO[path]) { + return MOCK_FILE_INFO[path] + } + throw new Error(`Cannot read file "${path}"`) + }), + } +}) + +describe(`get-page-data-util`, () => { + const pageDataContent = { + result: { + foo: `bar`, + }, + } + + const pageDataStaleContent = { + result: { + foo: `I'm stale`, + }, + } + + let Pages + beforeAll(() => { + Pages = { + foo: { + path: `/foo`, + componentPath: `/foo.js`, + component: `/foo.js`, + }, + } + + store.dispatch({ + type: `SET_PROGRAM`, + payload: { + directory: __dirname, + }, + }) + }) + + beforeEach(() => { + store.dispatch({ + type: `DELETE_CACHE`, + }) + deletePageDataFilesFromFs() + }) + + it(`Resolves immediately if query result is up to date`, async () => { + // query did already run before + createPage(Pages.foo) + startPageQuery(Pages.foo) + finishQuery(Pages.foo) + writePageDataFileToFs(Pages.foo, pageDataContent) + + const resultPromise = getPageData(Pages.foo.path) + expect(await resultPromise).toEqual(pageDataContent) + }) + + it(`Waits for query to run and resolve properly`, async () => { + createPage(Pages.foo) + const resultPromise = getPageData(Pages.foo.path) + + startPageQuery(Pages.foo) + finishQuery(Pages.foo) + writePageDataFileToFs(Pages.foo, pageDataContent) + + expect(await resultPromise).toEqual(pageDataContent) + }) + + describe(`timeouts and retries`, () => { + it(`it times out eventually (default timeout)`, async () => { + jest.useFakeTimers() + + createPage(Pages.foo) + const resultPromise = getPageData(Pages.foo.path) + + jest.runAllTimers() + + expect(setTimeout).toHaveBeenCalledTimes(3) + expect(setTimeout).toHaveBeenNthCalledWith( + 1, + expect.any(Function), + RETRY_INTERVAL + ) + expect(setTimeout).toHaveBeenNthCalledWith( + 2, + expect.any(Function), + RETRY_INTERVAL + ) + expect(setTimeout).toHaveBeenNthCalledWith( + 3, + expect.any(Function), + RETRY_INTERVAL + ) + + await expect(resultPromise).rejects.toMatchInlineSnapshot( + `[Error: Couldn't get query results for "/foo" in 15.000s.]` + ) + }) + + it(`it times out eventually (7 second timeout - 5s + 2s)`, async () => { + jest.useFakeTimers() + + createPage(Pages.foo) + const resultPromise = getPageData(Pages.foo.path, 7000) + + jest.runAllTimers() + + expect(setTimeout).toHaveBeenCalledTimes(2) + expect(setTimeout).toHaveBeenNthCalledWith( + 1, + expect.any(Function), + RETRY_INTERVAL + ) + expect(setTimeout).toHaveBeenNthCalledWith(2, expect.any(Function), 2000) + + await expect(resultPromise).rejects.toMatchInlineSnapshot( + `[Error: Couldn't get query results for "/foo" in 7.000s.]` + ) + }) + + it(`Can resolve after retry`, async () => { + jest.useFakeTimers() + + expect(clearTimeout).toHaveBeenCalledTimes(0) + + createPage(Pages.foo) + const resultPromise = getPageData(Pages.foo.path) + startPageQuery(Pages.foo) + + jest.runOnlyPendingTimers() + + // we don't resolve in first timeout and we set timeout for second one + expect(setTimeout).toHaveBeenCalledTimes(2) + expect(setTimeout).toHaveBeenNthCalledWith( + 1, + expect.any(Function), + RETRY_INTERVAL + ) + expect(setTimeout).toHaveBeenNthCalledWith( + 1, + expect.any(Function), + RETRY_INTERVAL + ) + + finishQuery(Pages.foo) + writePageDataFileToFs(Pages.foo, pageDataContent) + + // we cancel second timeout + expect(clearTimeout).toHaveBeenCalledTimes(1) + + // and result are correct + expect(await resultPromise).toEqual(pageDataContent) + }) + + it(`Can fallback to stale page-data if it exists (better to potentially unblock user to start doing some work than fail completely)`, async () => { + jest.useFakeTimers() + + writePageDataFileToFs(Pages.foo, pageDataStaleContent) + + createPage(Pages.foo) + const resultPromise = getPageData(Pages.foo.path) + + jest.runAllTimers() + + expect(setTimeout).toHaveBeenCalledTimes(3) + expect(setTimeout).toHaveBeenNthCalledWith( + 1, + expect.any(Function), + RETRY_INTERVAL + ) + expect(setTimeout).toHaveBeenNthCalledWith( + 2, + expect.any(Function), + RETRY_INTERVAL + ) + expect(setTimeout).toHaveBeenNthCalledWith( + 3, + expect.any(Function), + RETRY_INTERVAL + ) + + // we didn't get fresh results, but we resolved to stale ones + expect(await resultPromise).toEqual(pageDataStaleContent) + }) + }) + + describe(`handles page deletion in the middle of execution gracefully`, () => { + describe.each([ + // both variants should report that page was deleted + [ + `Doesn't have stale page-data file for a page`, + { hasPreviousResults: false }, + ], + [`Has stale page-data file for a page`, { hasPreviousResults: true }], + ])(`%s`, (_title, { hasPreviousResults }) => { + beforeEach(() => { + if (hasPreviousResults) { + writePageDataFileToFs(Pages.foo, pageDataStaleContent) + } + }) + + it(`page is deleted before we start query running`, async () => { + jest.useFakeTimers() + + createPage(Pages.foo) + const resultPromise = getPageData(Pages.foo.path) + + deletePage(Pages.foo) + + jest.runAllTimers() + + await expect(resultPromise).rejects.toMatchInlineSnapshot( + `[Error: Page "/foo" doesn't exist. It might have been deleted recently.]` + ) + }) + + it(`page is deleted after we start query running`, async () => { + jest.useFakeTimers() + + createPage(Pages.foo) + const resultPromise = getPageData(Pages.foo.path) + startPageQuery(Pages.foo) + deletePage(Pages.foo) + finishQuery(Pages.foo) + + jest.runAllTimers() + + await expect(resultPromise).rejects.toMatchInlineSnapshot( + `[Error: Page "/foo" doesn't exist. It might have been deleted recently.]` + ) + }) + + it(`page is deleted before we flush page data`, async () => { + jest.useFakeTimers() + + createPage(Pages.foo) + const resultPromise = getPageData(Pages.foo.path) + startPageQuery(Pages.foo) + finishQuery(Pages.foo) + deletePage(Pages.foo) + + jest.runAllTimers() + + await expect(resultPromise).rejects.toMatchInlineSnapshot( + `[Error: Page "/foo" doesn't exist. It might have been deleted recently.]` + ) + }) + }) + }) +}) + +function createPage(page: Partial): void { + store.dispatch({ + type: `CREATE_PAGE`, + payload: { ...page, context: {} }, + plugin: { name: `get-page-data-test` }, + }) +} + +function deletePage(page: Partial): void { + store.dispatch({ + type: `DELETE_PAGE`, + payload: page, + plugin: { name: `get-page-data-test` }, + }) +} + +function startPageQuery(page: Partial): void { + const payload: IQueryStartAction["payload"] = { + path: page.path!, + componentPath: page.componentPath!, + isPage: true, + } + store.dispatch( + queryStart(payload, { name: `page-data-test` } as IGatsbyPlugin) + ) +} + +function finishQuery(page: Partial): void { + const payload: IQueryStartAction["payload"] = { + path: page.path!, + componentPath: page.componentPath!, + isPage: true, + } + store.dispatch( + pageQueryRun(payload, { name: `page-data-test` } as IGatsbyPlugin) + ) + + store.dispatch({ + type: `ADD_PENDING_PAGE_DATA_WRITE`, + payload: { + path: page.path, + }, + }) +} + +function deletePageDataFilesFromFs(): void { + MOCK_FILE_INFO = {} +} + +function writePageDataFileToFs( + page: Partial, + jsonObject: object +): void { + MOCK_FILE_INFO[ + pathJoin( + __dirname, + `public`, + `page-data`, + fixedPagePath(page.path!), + `page-data.json` + ) + ] = JSON.stringify(jsonObject) + store.dispatch({ + type: `CLEAR_PENDING_PAGE_DATA_WRITE`, + payload: { page: page.path }, + }) +} diff --git a/packages/gatsby/src/utils/get-page-data.ts b/packages/gatsby/src/utils/get-page-data.ts index de5e675dac177..d58f58c60cbc2 100644 --- a/packages/gatsby/src/utils/get-page-data.ts +++ b/packages/gatsby/src/utils/get-page-data.ts @@ -6,10 +6,28 @@ import { readPageData as readPageDataUtil, } from "./page-data" +const DEFAULT_WAIT_TIMEOUT = 15 * 1000 +export const RETRY_INTERVAL = 5 * 1000 + export async function getPageData( - pagePath: string + pagePath: string, + waitForMS: number = DEFAULT_WAIT_TIMEOUT +): Promise { + return doGetPageData(pagePath, waitForMS, waitForMS) +} + +async function doGetPageData( + pagePath: string, + waitForMS: number, + initialWaitForMs: number ): Promise { - const { queries, pendingPageDataWrites } = store.getState() + const { queries, pendingPageDataWrites, pages } = store.getState() + + if (!pages.has(pagePath)) { + throw new Error( + `Page "${pagePath}" doesn't exist. It might have been deleted recently.` + ) + } const query = queries.trackedQueries.get(pagePath) @@ -17,31 +35,58 @@ export async function getPageData( throw new Error(`Could not find query ${pagePath}`) } if (query.running !== 0) { - return waitNextPageData(pagePath) + return waitNextPageData(pagePath, waitForMS, initialWaitForMs) } if (query.dirty !== 0) { emitter.emit(`QUERY_RUN_REQUESTED`, { pagePath }) - return waitNextPageData(pagePath) + return waitNextPageData(pagePath, waitForMS, initialWaitForMs) } if (pendingPageDataWrites.pagePaths.has(pagePath)) { - return waitNextPageData(pagePath) + return waitNextPageData(pagePath, waitForMS, initialWaitForMs) } // Results are up-to-date return readPageData(pagePath) } async function waitNextPageData( - pagePath: string + pagePath: string, + remainingTime: number, + initialWaitForMs: number ): Promise { - return new Promise(resolve => { - const listener = (data: IClearPendingPageDataWriteAction): void => { - if (data.payload.page === pagePath) { + if (remainingTime > 0) { + return new Promise(resolve => { + emitter.on(`CLEAR_PENDING_PAGE_DATA_WRITE`, listener) + + const timeout = setTimeout((): void => { emitter.off(`CLEAR_PENDING_PAGE_DATA_WRITE`, listener) - resolve(readPageData(pagePath)) + resolve( + doGetPageData( + pagePath, + Math.max(remainingTime - RETRY_INTERVAL, 0), + initialWaitForMs + ) + ) + }, Math.min(RETRY_INTERVAL, remainingTime)) + + function listener(data: IClearPendingPageDataWriteAction): void { + if (data.payload.page === pagePath) { + clearTimeout(timeout) + emitter.off(`CLEAR_PENDING_PAGE_DATA_WRITE`, listener) + resolve(readPageData(pagePath)) + } } - } - emitter.on(`CLEAR_PENDING_PAGE_DATA_WRITE`, listener) - }) + }) + } else { + // not ideal ... but try to push results we might have (stale) + // or fail/reject + return readPageData(pagePath).catch(() => { + throw new Error( + `Couldn't get query results for "${pagePath}" in ${( + initialWaitForMs / 1000 + ).toFixed(3)}s.` + ) + }) + } } async function readPageData(pagePath): Promise {