Time out lint and test integrations (#835)

.changeset/cuddly-seahorses-help.md

@@ -0,0 +1,7 @@
+---
+'skuba': patch
+---
+
+lint, test: Set timeout for Buildkite and GitHub integrations
+
+Transient network failures can impact annotations and autofixes. We now specify a 30 second timeout for these integration features to prevent them from hanging and indefinitely preoccupying your build agents.

src/cli/lint/annotate/buildkite/index.ts

@@ -17,7 +17,7 @@ export const createBuildkiteAnnotations = async (
     return;
   }
 
-  const buildkiteOutput: string = [
+  const buildkiteOutput = [
     '`skuba lint` found issues that require triage:',
     ...createEslintAnnotations(eslint),
     ...createPrettierAnnotations(prettier),

src/cli/lint/autofix.ts

@@ -7,6 +7,7 @@ import { runESLint } from '../../cli/adapter/eslint';
 import { runPrettier } from '../../cli/adapter/prettier';
 import { isCiEnv } from '../../utils/env';
 import { createLogger, log } from '../../utils/logging';
+import { throwOnTimeout } from '../../utils/wait';
 
 import type { Input } from './types';
 
@@ -86,16 +87,19 @@ export const autofix = async (input: Pick<Input, 'debug'>): Promise<void> => {
       return log.warn('No autofixes detected.');
     }
 
-    await (process.env.GITHUB_ACTIONS
-      ? // GitHub's checkout action should preconfigure the Git CLI.
-        simpleGit().push()
-      : // In other CI environments (Buildkite) we fall back to GitHub App auth.
-        Git.push({
-          auth: { type: 'gitHubApp' },
-          dir: process.cwd(),
-          ref,
-          remoteRef: currentBranch,
-        }));
+    await throwOnTimeout<unknown>(
+      process.env.GITHUB_ACTIONS
+        ? // GitHub's checkout action should preconfigure the Git CLI.
+          simpleGit().push()
+        : // In other CI environments (Buildkite) we fall back to GitHub App auth.
+          Git.push({
+            auth: { type: 'gitHubApp' },
+            dir: process.cwd(),
+            ref,
+            remoteRef: currentBranch,
+          }),
+      { s: 30 },
+    );
 
     log.warn(`Pushed fix commit ${ref}.`);
   } catch (err) {

src/cli/lint/external.ts

@@ -2,6 +2,7 @@ import stream from 'stream';
 import { inspect } from 'util';
 
 import { log } from '../../utils/logging';
+import { throwOnTimeout } from '../../utils/wait';
 
 import { createAnnotations } from './annotate';
 import { autofix } from './autofix';
@@ -86,7 +87,10 @@ export const externalLint = async (input: Input) => {
   const { eslint, prettier, tscOk } = await lint({ ...input, tscOutputStream });
 
   try {
-    await createAnnotations(eslint, prettier, tscOk, tscOutputStream);
+    await throwOnTimeout(
+      createAnnotations(eslint, prettier, tscOk, tscOutputStream),
+      { s: 30 },
+    );
   } catch (err) {
     log.warn('Failed to annotate lint results.');
     log.subtle(inspect(err));

src/cli/test/reporters/github/index.ts

@@ -9,6 +9,7 @@ import {
   enabledFromEnvironment,
 } from '../../../../api/github/environment';
 import { log } from '../../../../utils/logging';
+import { throwOnTimeout } from '../../../../utils/wait';
 
 import { generateAnnotationEntries } from './annotations';
 
@@ -37,13 +38,16 @@ export default class GitHubReporter implements Pick<Reporter, 'onRunComplete'> {
           ? '`skuba test` passed.'
           : '`skuba test` found issues that require triage.';
 
-        await GitHub.createCheckRun({
-          name,
-          annotations,
-          conclusion: isOk ? 'success' : 'failure',
-          summary,
-          title: `${build} ${isOk ? 'passed' : 'failed'}`,
-        });
+        await throwOnTimeout(
+          GitHub.createCheckRun({
+            name,
+            annotations,
+            conclusion: isOk ? 'success' : 'failure',
+            summary,
+            title: `${build} ${isOk ? 'passed' : 'failed'}`,
+          }),
+          { s: 30 },
+        );
       }
     } catch (err) {
       log.warn('Failed to report test results to GitHub.');

src/utils/error.test.ts

@@ -0,0 +1,19 @@
+import { inspect } from 'util';
+
+import { createTerseError } from './error';
+
+describe('createTerseError', () => {
+  it('creates a terse error for `util.inspect`', () => {
+    const message = 'Badness!';
+
+    const err = createTerseError(message);
+
+    // Retains standard message and stack behaviour
+    expect(err.message).toBe(message);
+    expect(err.stack).not.toBe(message);
+    expect(err.stack).toContain(message);
+
+    // Declares custom inspect function
+    expect(inspect(err)).toBe(message);
+  });
+});

src/utils/error.ts

@@ -21,6 +21,20 @@ export const ConcurrentlyErrors = t.Array(
   }),
 );
 
+/**
+ * Creates an error that returns its plain `message` rather than a full stack
+ * trace when `util.inspect`ed.
+ *
+ * This can be useful for terser handling and logging of known error scenarios
+ * that have descriptive messages.
+ *
+ * https://nodejs.org/api/util.html#custom-inspection-functions-on-objects
+ */
+export const createTerseError = (message?: string) =>
+  Object.assign(new Error(message), {
+    [inspect.custom]: () => message,
+  });
+
 const isExecaError = (err: unknown): err is ExecaError =>
   hasNumberProp(err, 'exitCode');
 

src/utils/version.ts

@@ -1,16 +1,13 @@
 import latestVersion from 'latest-version';
 
 import { getSkubaManifest } from './manifest';
-
-const sleep = (ms: number) =>
-  new Promise<void>((resolve) => setTimeout(resolve, ms));
+import { withTimeout } from './wait';
 
 const latestSkubaVersion = async (): Promise<string | null> => {
   try {
-    // Don't pull an Apple; bail out before holding up the command for too long
-    const result = await Promise.race([latestVersion('skuba'), sleep(2_000)]);
+    const result = await withTimeout(latestVersion('skuba'), { s: 2 });
 
-    return typeof result === 'string' ? result : null;
+    return result.ok ? result.value : null;
   } catch {
     return null;
   }

src/utils/wait.test.ts

@@ -0,0 +1,107 @@
+import * as wait from './wait';
+
+const delayMicrotask = () =>
+  Promise.resolve()
+    .then(() => undefined)
+    .then(() => undefined);
+
+const sleep = jest.spyOn(wait, 'sleep');
+
+beforeEach(jest.resetAllMocks);
+
+describe('throwOnTimeout', () => {
+  it('propagates a fulfilled promise within the timeout', async () => {
+    sleep.mockImplementation(delayMicrotask);
+
+    const value = 123;
+    const promise = jest.fn().mockResolvedValue(value);
+
+    await expect(wait.throwOnTimeout(promise(), { s: 3 })).resolves.toBe(value);
+
+    expect(sleep).toHaveBeenCalledTimes(1);
+    expect(sleep).toHaveBeenNthCalledWith(1, 3_000);
+  });
+
+  it('propagates a rejected promise within the timeout', async () => {
+    sleep.mockImplementation(delayMicrotask);
+
+    const err = new Error('Badness!');
+
+    const promise = jest.fn().mockRejectedValue(err);
+
+    await expect(wait.throwOnTimeout(promise(), { s: 2 })).rejects.toThrow(err);
+
+    expect(sleep).toHaveBeenCalledTimes(1);
+    expect(sleep).toHaveBeenNthCalledWith(1, 2_000);
+  });
+
+  it('enforces the timeout', async () => {
+    sleep.mockResolvedValue();
+
+    const promise = jest.fn().mockImplementation(delayMicrotask);
+
+    await expect(
+      wait.throwOnTimeout(promise(), { s: 1 }),
+    ).rejects.toThrowErrorMatchingInlineSnapshot(`"Timed out after 1 second"`);
+
+    expect(sleep).toHaveBeenCalledTimes(1);
+    expect(sleep).toHaveBeenNthCalledWith(1, 1_000);
+  });
+});
+
+describe('withTimeout', () => {
+  it('propagates a static value for easier `jest.mock`ing', async () => {
+    sleep.mockImplementation(delayMicrotask);
+
+    const value = 123;
+
+    await expect(wait.withTimeout(value, { s: 1 })).resolves.toStrictEqual({
+      ok: true,
+      value,
+    });
+
+    expect(sleep).toHaveBeenCalledTimes(1);
+    expect(sleep).toHaveBeenNthCalledWith(1, 1_000);
+  });
+
+  it('propagates a fulfilled promise within the timeout', async () => {
+    sleep.mockImplementation(delayMicrotask);
+
+    const value = 123;
+    const promise = jest.fn().mockResolvedValue(value);
+
+    await expect(wait.withTimeout(promise(), { s: 1 })).resolves.toStrictEqual({
+      ok: true,
+      value,
+    });
+
+    expect(sleep).toHaveBeenCalledTimes(1);
+    expect(sleep).toHaveBeenNthCalledWith(1, 1_000);
+  });
+
+  it('propagates a rejected promise within the timeout', async () => {
+    sleep.mockImplementation(delayMicrotask);
+
+    const err = new Error('Badness!');
+
+    const promise = jest.fn().mockRejectedValue(err);
+
+    await expect(wait.withTimeout(promise(), { s: 2 })).rejects.toThrow(err);
+
+    expect(sleep).toHaveBeenCalledTimes(1);
+    expect(sleep).toHaveBeenNthCalledWith(1, 2_000);
+  });
+
+  it('enforces the timeout', async () => {
+    sleep.mockResolvedValue();
+
+    const promise = jest.fn().mockImplementation(delayMicrotask);
+
+    await expect(wait.withTimeout(promise(), { s: 3 })).resolves.toStrictEqual({
+      ok: false,
+    });
+
+    expect(sleep).toHaveBeenCalledTimes(1);
+    expect(sleep).toHaveBeenNthCalledWith(1, 3_000);
+  });
+});

src/utils/wait.ts

@@ -0,0 +1,29 @@
+import { createTerseError } from './error';
+import { pluralise } from './logging';
+
+export const sleep = (ms: number) =>
+  new Promise<void>((resolve) => setTimeout(resolve, ms));
+
+export const throwOnTimeout = async <T>(
+  promise: PromiseLike<T>,
+  { s }: { s: number },
+): Promise<T> => {
+  const result = await withTimeout(promise, { s });
+
+  if (!result.ok) {
+    throw createTerseError(`Timed out after ${pluralise(s, 'second')}`);
+  }
+
+  return result.value;
+};
+
+type TimeoutResult<T> = { ok: true; value: T } | { ok: false };
+
+export const withTimeout = <T>(
+  promise: T | PromiseLike<T>,
+  { s }: { s: number },
+): Promise<TimeoutResult<T>> =>
+  Promise.race<TimeoutResult<T>>([
+    Promise.resolve(promise).then((value) => ({ ok: true, value })),
+    sleep(s * 1_000).then(() => ({ ok: false })),
+  ]);