diff --git a/CHANGELOG.md b/CHANGELOG.md index dd9b356fb..0af18ba2a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -31,6 +31,8 @@ Versioning](https://semver.org/spec/v2.0.0.html). proxies used by some third-party runners. - `WIREIT_PARALLEL`, `WIREIT_WATCH_POLL_MS`, and `WIREIT_MAX_OPEN_FILES` now reject any value that is not a positive integer, such as `2abc` or `1.5`. +- The message explaining that GitHub Actions caching was disabled after an HTTP + error from the cache service is now logged. It was always skipped before. ### Changed diff --git a/src/caching/github-actions-cache.ts b/src/caching/github-actions-cache.ts index 41b697a14..c5a5169e5 100644 --- a/src/caching/github-actions-cache.ts +++ b/src/caching/github-actions-cache.ts @@ -225,10 +225,10 @@ export class GitHubActionsCache implements Cache { const {req, resPromise} = requestResult; req.end(bodyBuffer); const result = await resPromise; - if (!this.#maybeHandleServiceDown(result, script)) { + const response = await this.#maybeHandleServiceDown(result, script); + if (response === undefined) { return undefined; } - const response = result.value; if (isOk(response)) { const {signed_download_url: archiveLocation} = JSON.parse( @@ -391,10 +391,10 @@ export class GitHubActionsCache implements Cache { }); const result = await resPromise; - if (!this.#maybeHandleServiceDown(result, script)) { + const response = await this.#maybeHandleServiceDown(result, script); + if (response === undefined) { return false; } - const response = result.value; if (!isOk(response)) { throw new Error( @@ -426,14 +426,15 @@ ${blockIds.map((blockId) => ` ${blockId}`).join('\n' }); requestResult.req.end(doneXmlBody); const r = await requestResult.resPromise; - if (!this.#maybeHandleServiceDown(r, script)) { + const response = await this.#maybeHandleServiceDown(r, script); + if (response === undefined) { return false; } - if (!isOk(r.value)) { + if (!isOk(response)) { throw new Error( `GitHub Cache finalize HTTP ${String( - r.value.statusCode, - )} error: ${await readBody(r.value)}`, + response.statusCode, + )} error: ${await readBody(response)}`, ); } return true; @@ -479,10 +480,10 @@ ${blockIds.map((blockId) => ` ${blockId}`).join('\n' req.end(bodyBuffer); const result = await resPromise; - if (!this.#maybeHandleServiceDown(result, script)) { + const response = await this.#maybeHandleServiceDown(result, script); + if (response === undefined) { return false; } - const response = result.value; if (!isOk(response)) { throw new Error( @@ -518,17 +519,16 @@ ${blockIds.map((blockId) => ` ${blockId}`).join('\n' /** * If we received a network or HTTP error from the given HTTP request, set the * global flag to indicate that GitHub Actions Caching is down (it's a class - * property, but this class should be a global singleton), log an error - * (possibly asynchronously), and return false. If the request was OK, just - * return true. + * property, but this class should be a global singleton), log an error, and + * return undefined. If the request was OK, just return the response. */ - #maybeHandleServiceDown( + async #maybeHandleServiceDown( res: Result, script: ScriptReference, - ): res is {ok: true; value: http.IncomingMessage} { + ): Promise { const status = res.ok ? res.value.statusCode : null; if (res.ok && status != null && status >= 200 && status <= 299) { - return true; + return res.value; } if (this.#serviceIsDown) { @@ -538,7 +538,7 @@ ${blockIds.map((blockId) => ` ${blockId}`).join('\n' // stop making HTTP requests after setting this flag, there could be >1 // pending requests out at the same time before the first error is // detected. - return false; + return undefined; } this.#serviceIsDown = true; @@ -553,30 +553,27 @@ ${blockIds.map((blockId) => ` ${blockId}`).join('\n' ` Detail:\n\n${res.error}`, }); } else { - void (async () => { - const body = await readBody(res.value).catch(() => ''); - if (this.#serviceIsDown) { - return; - } - const message = - status === 429 - ? `Hit GitHub Actions cache service rate limit` - : status === 503 - ? `GitHub Actions cache service is temporarily unavailable` - : `Unexpected HTTP ${status} error from GitHub Actions cache service`; - this.#logger.log({ - script, - type: 'info', - detail: 'cache-info', - message: - `${message}.` + - ` GitHub Actions caching has been temporarily disabled.` + - ` Detail:\n\nHTTP ${status}: ${body}`, - }); - })(); + // Read the body before returning. The caller destroys the request as soon + // as we return, which would cut the body off. + const body = await readBody(res.value).catch(() => ''); + const message = + status === 429 + ? `Hit GitHub Actions cache service rate limit` + : status === 503 + ? `GitHub Actions cache service is temporarily unavailable` + : `Unexpected HTTP ${status} error from GitHub Actions cache service`; + this.#logger.log({ + script, + type: 'info', + detail: 'cache-info', + message: + `${message}.` + + ` GitHub Actions caching has been temporarily disabled.` + + ` Detail:\n\nHTTP ${status}: ${body}`, + }); } - return false; + return undefined; } #computeCacheKey(script: ScriptReference): string { @@ -702,10 +699,10 @@ ${blockIds.map((blockId) => ` ${blockId}`).join('\n' // same script. return undefined; } - if (!this.#maybeHandleServiceDown(result, script)) { + const response = await this.#maybeHandleServiceDown(result, script); + if (response === undefined) { return undefined; } - const response = result.value; if (isOk(response)) { const resData = JSON.parse(await readBody(response)) as { diff --git a/src/test/cache-github-fake.test.ts b/src/test/cache-github-fake.test.ts index 6e4ba1362..e69372166 100644 --- a/src/test/cache-github-fake.test.ts +++ b/src/test/cache-github-fake.test.ts @@ -287,6 +287,36 @@ void test(`gracefully handles 409 conflict on set()`, async () => { assert.equal(cmdA.numInvocations, 1); }); +void test('logs that caching was disabled after an HTTP error', async () => { + const cmdA = await rig.newCommand(); + await rig.write({ + 'package.json': { + scripts: { + a: 'wireit', + }, + wireit: { + a: { + command: cmdA.command, + files: ['input'], + output: [], + }, + }, + }, + input: 'foo', + }); + + server.forceErrorOnNextRequest('getCacheEntry', 503); + const exec = rig.exec('npm run a', {env: {WIREIT_LOGGER: 'simple'}}); + (await cmdA.nextInvocation()).exit(0); + const res = await exec.exit; + assertSuccess(res); + assert.match( + res.stdout, + /GitHub Actions cache service is temporarily unavailable/, + ); + assert.match(res.stdout, /HTTP 503: Forcing 503 error for getCacheEntry/); +}); + const randomInt = (minIncl: number, maxExcl: number) => minIncl + Math.floor(Math.random() * (maxExcl - minIncl));