From 6597dbff57bc5977c544080c3780f58e07a26968 Mon Sep 17 00:00:00 2001 From: Gert Hengeveld Date: Thu, 15 Feb 2024 14:58:10 +0100 Subject: [PATCH 01/10] Avoid build timeout when having to wait for upgrade builds --- node-src/lib/getEnv.ts | 3 ++ node-src/lib/setExitCode.ts | 1 + node-src/tasks/verify.test.ts | 82 ++++++++++++++++++++++++++++++++++- node-src/tasks/verify.ts | 30 ++++++++++--- node-src/ui/tasks/verify.ts | 16 +++++++ 5 files changed, 125 insertions(+), 7 deletions(-) diff --git a/node-src/lib/getEnv.ts b/node-src/lib/getEnv.ts index 860313129..dfe86f0d4 100644 --- a/node-src/lib/getEnv.ts +++ b/node-src/lib/getEnv.ts @@ -9,6 +9,7 @@ export interface Env { CHROMATIC_RETRIES: number; CHROMATIC_STORYBOOK_VERSION: string; CHROMATIC_TIMEOUT: number; + CHROMATIC_UPGRADE_TIMEOUT: number; ENVIRONMENT_WHITELIST: RegExp[]; HTTP_PROXY: string; HTTPS_PROXY: string; @@ -29,6 +30,7 @@ const { CHROMATIC_RETRIES = '5', CHROMATIC_STORYBOOK_VERSION, CHROMATIC_TIMEOUT = String(5 * 60 * 1000), + CHROMATIC_UPGRADE_TIMEOUT = String(60 * 60 * 1000), HTTP_PROXY = process.env.http_proxy, HTTPS_PROXY = process.env.https_proxy, LOGGLY_CUSTOMER_TOKEN = 'b5e26204-cdc5-4c78-a9cc-c69eb7fabad3', @@ -65,6 +67,7 @@ export default () => CHROMATIC_RETRIES: parseInt(CHROMATIC_RETRIES, 10), CHROMATIC_STORYBOOK_VERSION, CHROMATIC_TIMEOUT: parseInt(CHROMATIC_TIMEOUT, 10), + CHROMATIC_UPGRADE_TIMEOUT: parseInt(CHROMATIC_UPGRADE_TIMEOUT, 10), ENVIRONMENT_WHITELIST, HTTP_PROXY, HTTPS_PROXY, diff --git a/node-src/lib/setExitCode.ts b/node-src/lib/setExitCode.ts index 976387f2d..b30301be8 100644 --- a/node-src/lib/setExitCode.ts +++ b/node-src/lib/setExitCode.ts @@ -36,6 +36,7 @@ export const exitCodes = { FETCH_ERROR: 201, GRAPHQL_ERROR: 202, MISSING_DEPENDENCY: 210, + VERIFICATION_TIMEOUT: 220, INVALID_OPTIONS: 254, }; diff --git a/node-src/tasks/verify.test.ts b/node-src/tasks/verify.test.ts index fc0c34872..3cc74fa56 100644 --- a/node-src/tasks/verify.test.ts +++ b/node-src/tasks/verify.test.ts @@ -1,8 +1,13 @@ import { describe, expect, it, vi } from 'vitest'; +import { exitCodes } from '../lib/setExitCode'; import { publishBuild, verifyBuild } from './verify'; -const env = { STORYBOOK_VERIFY_TIMEOUT: 1000 }; +const env = { + CHROMATIC_POLL_INTERVAL: 10, + CHROMATIC_UPGRADE_TIMEOUT: 100, + STORYBOOK_VERIFY_TIMEOUT: 20, +}; const log = { info: vi.fn(), warn: vi.fn(), debug: vi.fn() }; const http = { fetch: vi.fn() }; @@ -55,9 +60,10 @@ describe('verifyBuild', () => { app: {}, startedAt: Date.now(), }; - const publishedBuild = { ...build, status: 'PUBLISHED', startedAt: null }; + const publishedBuild = { ...build, status: 'PUBLISHED', startedAt: null, upgradeBuilds: [] }; const client = { runQuery: vi.fn() }; client.runQuery + // We can safely poll three times without hitting the timeout .mockReturnValueOnce({ app: { build: publishedBuild } }) .mockReturnValueOnce({ app: { build: publishedBuild } }) .mockReturnValue({ app: { build } }); @@ -95,6 +101,78 @@ describe('verifyBuild', () => { expect(ctx.skipSnapshots).toBe(undefined); }); + it('times out if build takes too long to start', async () => { + const build = { + status: 'IN_PROGRESS', + features: { uiTests: true, uiReview: false }, + app: {}, + startedAt: Date.now(), + }; + const publishedBuild = { ...build, status: 'PUBLISHED', startedAt: null, upgradeBuilds: [] }; + const client = { runQuery: vi.fn() }; + client.runQuery + // Polling four times is going to hit the timeout + .mockReturnValueOnce({ app: { build: publishedBuild } }) + .mockReturnValueOnce({ app: { build: publishedBuild } }) + .mockReturnValueOnce({ app: { build: publishedBuild } }) + .mockReturnValue({ app: { build } }); + + const ctx = { client, ...defaultContext } as any; + await expect(verifyBuild(ctx, {} as any)).rejects.toThrow('Build verification timed out'); + + expect(client.runQuery).toHaveBeenCalledTimes(3); + expect(ctx.exitCode).toBe(exitCodes.VERIFICATION_TIMEOUT); + }); + + it('waits for upgrade builds before starting verification timeout', async () => { + const build = { + status: 'IN_PROGRESS', + features: { uiTests: true, uiReview: false }, + app: {}, + startedAt: Date.now(), + }; + const upgradeBuilds = [{ completedAt: null }]; + const completed = [{ completedAt: Date.now() }]; + const publishedBuild = { ...build, status: 'PUBLISHED', startedAt: null, upgradeBuilds }; + const client = { runQuery: vi.fn() }; + client.runQuery + // Polling while upgrade builds are in progress is irrelevant + .mockReturnValueOnce({ app: { build: publishedBuild } }) + .mockReturnValueOnce({ app: { build: publishedBuild } }) + .mockReturnValueOnce({ app: { build: publishedBuild } }) + .mockReturnValueOnce({ app: { build: publishedBuild } }) + .mockReturnValueOnce({ app: { build: publishedBuild } }) + .mockReturnValueOnce({ app: { build: publishedBuild } }) + // We can safely poll three times without hitting the timeout + .mockReturnValueOnce({ app: { build: { ...publishedBuild, upgradeBuilds: completed } } }) + .mockReturnValueOnce({ app: { build: { ...publishedBuild, upgradeBuilds: completed } } }) + .mockReturnValue({ app: { build } }); + + const ctx = { client, ...defaultContext } as any; + await verifyBuild(ctx, {} as any); + + expect(ctx.build).toMatchObject(build); + expect(ctx.exitCode).toBe(undefined); + }); + + it('times out if upgrade builds take too long to complete', async () => { + const build = { + status: 'IN_PROGRESS', + features: { uiTests: true, uiReview: false }, + app: {}, + startedAt: Date.now(), + }; + const upgradeBuilds = [{ completedAt: null }]; + const publishedBuild = { ...build, status: 'PUBLISHED', startedAt: null, upgradeBuilds }; + const client = { runQuery: vi.fn() }; + client.runQuery.mockReturnValue({ app: { build: publishedBuild } }); + + const ctx = { client, ...defaultContext } as any; + await expect(verifyBuild(ctx, {} as any)).rejects.toThrow( + 'Timed out waiting for upgrade builds to complete' + ); + }); + it('sets exitCode to 5 if build was limited', async () => { const client = { runQuery: vi.fn() }; client.runQuery.mockReturnValue({ diff --git a/node-src/tasks/verify.ts b/node-src/tasks/verify.ts index 4bc4f4111..3582ae7c4 100644 --- a/node-src/tasks/verify.ts +++ b/node-src/tasks/verify.ts @@ -12,6 +12,7 @@ import { pending, runOnlyFiles, runOnlyNames, + awaitingUpgrades, success, publishFailed, } from '../ui/tasks/verify'; @@ -85,6 +86,9 @@ const StartedBuildQuery = ` build(number: $number) { startedAt failureReason + upgradeBuilds { + completedAt + } } } } @@ -92,8 +96,11 @@ const StartedBuildQuery = ` interface StartedBuildQueryResult { app: { build: { - startedAt: number; - failureReason: string; + startedAt?: number; + failureReason?: string; + upgradeBuilds: { + completedAt?: number; + }[]; }; }; } @@ -178,6 +185,7 @@ export const verifyBuild = async (ctx: Context, task: Task) => { transitionTo(runOnlyNames)(ctx, task); } + let timeoutStart = Date.now(); const waitForBuildToStart = async () => { const { storybookUrl } = ctx; const { number, reportToken } = ctx.announcedBuild; @@ -187,12 +195,24 @@ export const verifyBuild = async (ctx: Context, task: Task) => { const { app: { build }, } = await client.runQuery(StartedBuildQuery, variables, options); + if (build.failureReason) { - ctx.log.warn(brokenStorybook({ ...build, storybookUrl })); + ctx.log.warn(brokenStorybook({ failureReason: build.failureReason, storybookUrl })); setExitCode(ctx, exitCodes.STORYBOOK_BROKEN, true); throw new Error(publishFailed().output); } + if (!build.startedAt) { + // Upgrade builds can take a long time to complete, so we can't apply a hard timeout yet, + // instead we only timeout on the actual build verification, after upgrades are complete. + if (build.upgradeBuilds.some((upgrade) => !upgrade.completedAt)) { + task.output = awaitingUpgrades(build).output; + timeoutStart = Date.now() + ctx.env.CHROMATIC_POLL_INTERVAL; + } else if (Date.now() - timeoutStart > ctx.env.STORYBOOK_VERIFY_TIMEOUT) { + setExitCode(ctx, exitCodes.VERIFICATION_TIMEOUT); + throw new Error('Build verification timed out'); + } + await delay(ctx.env.CHROMATIC_POLL_INTERVAL); await waitForBuildToStart(); return; @@ -209,8 +229,8 @@ export const verifyBuild = async (ctx: Context, task: Task) => { new Promise((_, reject) => setTimeout( reject, - ctx.env.STORYBOOK_VERIFY_TIMEOUT, - new Error('Build verification timed out') + ctx.env.CHROMATIC_UPGRADE_TIMEOUT, + new Error('Timed out waiting for upgrade builds to complete') ) ), ]); diff --git a/node-src/ui/tasks/verify.ts b/node-src/ui/tasks/verify.ts index 4402c407c..48e4e975f 100644 --- a/node-src/ui/tasks/verify.ts +++ b/node-src/ui/tasks/verify.ts @@ -1,3 +1,5 @@ +import pluralize from 'pluralize'; + import { Context } from '../../types'; export const initial = { @@ -41,6 +43,20 @@ export const runOnlyNames = (ctx: Context) => ({ .join(', ')}`, }); +export const awaitingUpgrades = ({ + upgradeBuilds, +}: { + upgradeBuilds: { completedAt?: number }[]; +}) => { + const pending = upgradeBuilds.filter((upgrade) => !upgrade.completedAt).length; + const upgrades = pluralize('upgrade build', upgradeBuilds.length, true); + return { + status: 'pending', + title: 'Verifying your Storybook', + output: `Waiting for ${pending}/${upgrades} to complete`, + }; +}; + export const success = (ctx: Context) => ({ status: 'success', title: ctx.isPublishOnly ? `Published your Storybook` : `Started build ${ctx.build.number}`, From 275406e1a0d1c65bd12c60e40228b3a0cef7ffee Mon Sep 17 00:00:00 2001 From: Gert Hengeveld Date: Fri, 16 Feb 2024 13:35:43 +0100 Subject: [PATCH 02/10] build.upgradeBuilds is nullable --- node-src/tasks/verify.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/node-src/tasks/verify.ts b/node-src/tasks/verify.ts index 93a90f155..6a5d01eca 100644 --- a/node-src/tasks/verify.ts +++ b/node-src/tasks/verify.ts @@ -96,7 +96,7 @@ interface StartedBuildQueryResult { build: { startedAt?: number; failureReason?: string; - upgradeBuilds: { + upgradeBuilds?: { completedAt?: number; }[]; }; @@ -203,7 +203,7 @@ export const verifyBuild = async (ctx: Context, task: Task) => { if (!build.startedAt) { // Upgrade builds can take a long time to complete, so we can't apply a hard timeout yet, // instead we only timeout on the actual build verification, after upgrades are complete. - if (build.upgradeBuilds.some((upgrade) => !upgrade.completedAt)) { + if (build.upgradeBuilds?.some((upgrade) => !upgrade.completedAt)) { task.output = awaitingUpgrades(build).output; timeoutStart = Date.now() + ctx.env.CHROMATIC_POLL_INTERVAL; } else if (Date.now() - timeoutStart > ctx.env.STORYBOOK_VERIFY_TIMEOUT) { From 7624db1a7267d7c94825e2b9e006646744716fe8 Mon Sep 17 00:00:00 2001 From: Gert Hengeveld Date: Fri, 16 Feb 2024 14:42:13 +0100 Subject: [PATCH 03/10] Add missing story --- node-src/tasks/verify.ts | 2 +- node-src/ui/tasks/verify.stories.ts | 4 ++++ node-src/ui/tasks/verify.ts | 8 ++------ 3 files changed, 7 insertions(+), 7 deletions(-) diff --git a/node-src/tasks/verify.ts b/node-src/tasks/verify.ts index 6a5d01eca..abaa9a158 100644 --- a/node-src/tasks/verify.ts +++ b/node-src/tasks/verify.ts @@ -204,7 +204,7 @@ export const verifyBuild = async (ctx: Context, task: Task) => { // Upgrade builds can take a long time to complete, so we can't apply a hard timeout yet, // instead we only timeout on the actual build verification, after upgrades are complete. if (build.upgradeBuilds?.some((upgrade) => !upgrade.completedAt)) { - task.output = awaitingUpgrades(build).output; + task.output = awaitingUpgrades(ctx, build.upgradeBuilds).output; timeoutStart = Date.now() + ctx.env.CHROMATIC_POLL_INTERVAL; } else if (Date.now() - timeoutStart > ctx.env.STORYBOOK_VERIFY_TIMEOUT) { setExitCode(ctx, exitCodes.VERIFICATION_TIMEOUT); diff --git a/node-src/ui/tasks/verify.stories.ts b/node-src/ui/tasks/verify.stories.ts index 4862e9c3e..edbe28c67 100644 --- a/node-src/ui/tasks/verify.stories.ts +++ b/node-src/ui/tasks/verify.stories.ts @@ -5,6 +5,7 @@ import { pending, runOnlyFiles, runOnlyNames, + awaitingUpgrades, success, failed, publishFailed, @@ -45,6 +46,9 @@ export const RunOnlyNames = () => options: { onlyStoryNames: ['MyComponent/**'] }, } as any); +export const AwaitingUpgrades = () => + awaitingUpgrades({} as any, [{ completedAt: 123 }, { completedAt: null }]); + export const Started = () => success({ build } as any); export const Published = () => success({ isPublishOnly: true, build } as any); diff --git a/node-src/ui/tasks/verify.ts b/node-src/ui/tasks/verify.ts index 48e4e975f..9774a6fa6 100644 --- a/node-src/ui/tasks/verify.ts +++ b/node-src/ui/tasks/verify.ts @@ -43,12 +43,8 @@ export const runOnlyNames = (ctx: Context) => ({ .join(', ')}`, }); -export const awaitingUpgrades = ({ - upgradeBuilds, -}: { - upgradeBuilds: { completedAt?: number }[]; -}) => { - const pending = upgradeBuilds.filter((upgrade) => !upgrade.completedAt).length; +export const awaitingUpgrades = (ctx: Context, upgradeBuilds: { completedAt?: number }[]) => { + const pending = upgradeBuilds!.filter((upgrade) => !upgrade.completedAt).length; const upgrades = pluralize('upgrade build', upgradeBuilds.length, true); return { status: 'pending', From 8da01c4699de80f24a902b69721923146598669b Mon Sep 17 00:00:00 2001 From: Gert Hengeveld Date: Fri, 16 Feb 2024 15:16:41 +0100 Subject: [PATCH 04/10] Silence the S3 polling errors --- node-src/lib/waitForSentinel.ts | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/node-src/lib/waitForSentinel.ts b/node-src/lib/waitForSentinel.ts index ad8b9431d..99d3b1205 100644 --- a/node-src/lib/waitForSentinel.ts +++ b/node-src/lib/waitForSentinel.ts @@ -18,7 +18,7 @@ export async function waitForSentinel(ctx: Context, { name, url }: { name: strin } try { - const res = await ctx.http.fetch(url, { signal }, { retries: 0 }); + const res = await ctx.http.fetch(url, { signal }, { retries: 0, noLogErrorBody: true }); const result = await res.text(); if (result !== SENTINEL_SUCCESS_VALUE) { ctx.log.debug(`Sentinel file '${name}' not OK, got '${result}'.`); @@ -26,9 +26,12 @@ export async function waitForSentinel(ctx: Context, { name, url }: { name: strin } ctx.log.debug(`Sentinel file '${name}' OK.`); } catch (e) { - const { response = {} } = e; + const { message, response = {} } = e; if (response.status === 403) { return bail(new Error('Provided signature expired.')); + } else if (response.status !== 404) { + if (this.log.getLevel() === 'debug') this.log.debug(await response.text()); + return bail(new Error(message)); } throw new Error(`Sentinel file '${name}' not present.`); } From 107d71125854f2faa0f7750097b4eb6b992ac2a0 Mon Sep 17 00:00:00 2001 From: Gert Hengeveld Date: Fri, 16 Feb 2024 15:17:29 +0100 Subject: [PATCH 05/10] Show a debug message when all tasks are done, to debug hanging CLI process --- node-src/index.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/node-src/index.ts b/node-src/index.ts index 0aa23c87b..ed62df0c4 100644 --- a/node-src/index.ts +++ b/node-src/index.ts @@ -203,6 +203,7 @@ async function runBuild(ctx: Context) { ctx.log.queue(); } await new Listr(getTasks(ctx.options), options).run(ctx); + ctx.log.debug('Tasks completed'); } catch (err) { endActivity(ctx); if (err.code === 'ECONNREFUSED' || err.name === 'StatusCodeError') { From f6f2c9a9e894e433ff1ae43413296b3b05f0eef6 Mon Sep 17 00:00:00 2001 From: Gert Hengeveld Date: Fri, 16 Feb 2024 15:20:08 +0100 Subject: [PATCH 06/10] Simplify logic --- node-src/lib/waitForSentinel.ts | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-) diff --git a/node-src/lib/waitForSentinel.ts b/node-src/lib/waitForSentinel.ts index 99d3b1205..01c9a4ae8 100644 --- a/node-src/lib/waitForSentinel.ts +++ b/node-src/lib/waitForSentinel.ts @@ -29,11 +29,14 @@ export async function waitForSentinel(ctx: Context, { name, url }: { name: strin const { message, response = {} } = e; if (response.status === 403) { return bail(new Error('Provided signature expired.')); - } else if (response.status !== 404) { - if (this.log.getLevel() === 'debug') this.log.debug(await response.text()); - return bail(new Error(message)); } - throw new Error(`Sentinel file '${name}' not present.`); + if (response.status === 404) { + throw new Error(`Sentinel file '${name}' not present.`); + } + if (this.log.getLevel() === 'debug') { + this.log.debug(await response.text()); + } + return bail(new Error(message)); } }, { From bb1e58492ca86513a4dfad341f66aa45b95112cd Mon Sep 17 00:00:00 2001 From: Gert Hengeveld Date: Fri, 16 Feb 2024 15:27:08 +0100 Subject: [PATCH 07/10] Make sure we exit with the right code when running via node --- scripts/run-via-node.mjs | 15 ++++++++++----- 1 file changed, 10 insertions(+), 5 deletions(-) diff --git a/scripts/run-via-node.mjs b/scripts/run-via-node.mjs index f5aa29cf0..335b62db4 100755 --- a/scripts/run-via-node.mjs +++ b/scripts/run-via-node.mjs @@ -7,8 +7,13 @@ run({ flags: { projectToken: process.env.CHROMATIC_PROJECT_TOKEN, }, -}).catch((err) => { - // eslint-disable-next-line no-console - console.log(err); - process.exit(1); -}); +}).then( + ({ code }) => { + process.exit(code); + }, + (err) => { + // eslint-disable-next-line no-console + console.log(err); + process.exit(1); + } +); From 67cfc06359f4db1040beae1dc3fa3ddbe2cad052 Mon Sep 17 00:00:00 2001 From: Gert Hengeveld Date: Fri, 16 Feb 2024 15:33:09 +0100 Subject: [PATCH 08/10] Exit zero on changes --- scripts/run-via-node.mjs | 1 + 1 file changed, 1 insertion(+) diff --git a/scripts/run-via-node.mjs b/scripts/run-via-node.mjs index 335b62db4..4d8043f83 100755 --- a/scripts/run-via-node.mjs +++ b/scripts/run-via-node.mjs @@ -6,6 +6,7 @@ import { run } from '../dist/node.js'; run({ flags: { projectToken: process.env.CHROMATIC_PROJECT_TOKEN, + exitZeroOnChanges: true, }, }).then( ({ code }) => { From 4d7c9c43dae17308cf00a893f71628700d9adac9 Mon Sep 17 00:00:00 2001 From: Gert Hengeveld Date: Fri, 16 Feb 2024 15:42:54 +0100 Subject: [PATCH 09/10] Drop irrelevant check --- node-src/tasks/verify.test.ts | 1 - 1 file changed, 1 deletion(-) diff --git a/node-src/tasks/verify.test.ts b/node-src/tasks/verify.test.ts index 3cc74fa56..fac337102 100644 --- a/node-src/tasks/verify.test.ts +++ b/node-src/tasks/verify.test.ts @@ -120,7 +120,6 @@ describe('verifyBuild', () => { const ctx = { client, ...defaultContext } as any; await expect(verifyBuild(ctx, {} as any)).rejects.toThrow('Build verification timed out'); - expect(client.runQuery).toHaveBeenCalledTimes(3); expect(ctx.exitCode).toBe(exitCodes.VERIFICATION_TIMEOUT); }); From e582c43c694463479550e10362aac84d9eed3d65 Mon Sep 17 00:00:00 2001 From: Gert Hengeveld Date: Fri, 16 Feb 2024 15:55:11 +0100 Subject: [PATCH 10/10] Make sure we don't hit the global timeout --- node-src/tasks/verify.test.ts | 1 - 1 file changed, 1 deletion(-) diff --git a/node-src/tasks/verify.test.ts b/node-src/tasks/verify.test.ts index fac337102..eaae14ac8 100644 --- a/node-src/tasks/verify.test.ts +++ b/node-src/tasks/verify.test.ts @@ -141,7 +141,6 @@ describe('verifyBuild', () => { .mockReturnValueOnce({ app: { build: publishedBuild } }) .mockReturnValueOnce({ app: { build: publishedBuild } }) .mockReturnValueOnce({ app: { build: publishedBuild } }) - .mockReturnValueOnce({ app: { build: publishedBuild } }) // We can safely poll three times without hitting the timeout .mockReturnValueOnce({ app: { build: { ...publishedBuild, upgradeBuilds: completed } } }) .mockReturnValueOnce({ app: { build: { ...publishedBuild, upgradeBuilds: completed } } })