Repository: vercel/next.js
Pull request: Fix devlow job timeouts

Attempting to fix the devlow job timeouts that have been happening on canary for a bit

x-ref: https://github.com/vercel/next.js/actions/runs/21889767463/job/63192963474

Changed files:
filename: scripts/devlow-bench.mjs
patch: @@ -10,6 +10,7 @@ import { waitForFile } from '@vercel/devlow-bench/file'
 const REPO_ROOT = fileURLToPath(new URL('..', import.meta.url))
 const START_SERVER_REGEXP = /Ready in \d+/
 const URL_REGEXP = /Local:\s+(?<url>.+)\n/
+const STARTUP_WAIT_TIMEOUT_MS = 5 * 60 * 1000
 
 const GIT_SHA =
   process.env.GITHUB_SHA ??
@@ -105,10 +106,14 @@ const nextBuildWorkflow =
       // wait for server to be ready
       const {
         groups: { url },
-      } = await shell.waitForOutput(URL_REGEXP)
+      } = await shell.waitForOutput(URL_REGEXP, {
+        timeoutMs: STARTUP_WAIT_TIMEOUT_MS,
+      })
 
       // wait for server to be ready
-      await shell.waitForOutput(START_SERVER_REGEXP)
+      await shell.waitForOutput(START_SERVER_REGEXP, {
+        timeoutMs: STARTUP_WAIT_TIMEOUT_MS,
+      })
       await measureTime('server startup', { props: { turbopack, page } })
       await shell.reportMemUsage('mem usage after startup', {
         props: { turbopack, page },
@@ -192,7 +197,9 @@ const nextBuildWorkflow =
       // wait for server to be ready
       const {
         groups: { url: url2 },
-      } = await shell.waitForOutput(URL_REGEXP)
+      } = await shell.waitForOutput(URL_REGEXP, {
+        timeoutMs: STARTUP_WAIT_TIMEOUT_MS,
+      })
       await shell.reportMemUsage('mem usage after startup with cache')
 
       // open page
@@ -284,10 +291,14 @@ const nextDevWorkflow =
       // wait for server to be ready
       const {
         groups: { url },
-      } = await shell.waitForOutput(URL_REGEXP)
+      } = await shell.waitForOutput(URL_REGEXP, {
+        timeoutMs: STARTUP_WAIT_TIMEOUT_MS,
+      })
 
       // wait for server to be ready
-      await shell.waitForOutput(START_SERVER_REGEXP)
+      await shell.waitForOutput(START_SERVER_REGEXP, {
+        timeoutMs: STARTUP_WAIT_TIMEOUT_MS,
+      })
       await measureTime('server startup', { props: { turbopack, page } })
       await shell.reportMemUsage('mem usage after startup', {
         props: { turbopack, page },
@@ -512,7 +523,9 @@ const nextDevWorkflow =
       // wait for server to be ready
       const {
         groups: { url: url2 },
-      } = await shell.waitForOutput(URL_REGEXP)
+      } = await shell.waitForOutput(URL_REGEXP, {
+        timeoutMs: STARTUP_WAIT_TIMEOUT_MS,
+      })
       await shell.reportMemUsage('mem usage after startup with cache')
 
       // open page

filename: turbopack/packages/devlow-bench/src/interfaces/shell-test.ts
patch: @@ -0,0 +1,72 @@
+import assert from 'assert'
+import { mkdtemp, rm, writeFile } from 'node:fs/promises'
+import { tmpdir } from 'node:os'
+import { join } from 'node:path'
+import { test } from 'node:test'
+import { command } from '../shell.js'
+
+async function withTempScript(
+  scriptContents: string,
+  fn: (scriptPath: string) => Promise<void>
+) {
+  const dir = await mkdtemp(join(tmpdir(), 'devlow-shell-test-'))
+  const scriptPath = join(dir, 'script.js')
+
+  try {
+    await writeFile(scriptPath, scriptContents, 'utf8')
+    await fn(scriptPath)
+  } finally {
+    await rm(dir, { recursive: true, force: true })
+  }
+}
+
+test('waitForOutput handles sequential waits after buffered output', async () => {
+  await withTempScript(
+    `
+console.log('FIRST_MARKER')
+console.log('SECOND_MARKER')
+setTimeout(() => {}, 1000)
+`,
+    async (scriptPath) => {
+      const shell = command('node', [scriptPath])
+
+      try {
+        const first = await shell.waitForOutput(/FIRST_MARKER\n/, {
+          timeoutMs: 2_000,
+        })
+        assert.equal(first[0], 'FIRST_MARKER\n')
+        const second = await shell.waitForOutput(/SECOND_MARKER\n/, {
+          timeoutMs: 2_000,
+        })
+        assert.equal(second[0], 'SECOND_MARKER\n')
+      } finally {
+        await shell.kill()
+      }
+    }
+  )
+})
+
+test('waitForOutput times out when output never appears', async () => {
+  await withTempScript(
+    `
+console.log('FIRST_MARKER')
+setTimeout(() => {}, 1000)
+`,
+    async (scriptPath) => {
+      const shell = command('node', [scriptPath])
+
+      try {
+        await shell.waitForOutput(/FIRST_MARKER\n/, {
+          timeoutMs: 2_000,
+        })
+
+        await assert.rejects(
+          shell.waitForOutput(/NEVER_SEEN\n/, { timeoutMs: 100 }),
+          /Timed out waiting for output matching/
+        )
+      } finally {
+        await shell.kill()
+      }
+    }
+  )
+})

filename: turbopack/packages/devlow-bench/src/shell.ts
patch: @@ -8,7 +8,12 @@ export interface Command {
   ok(): Promise<void>
   kill(): Promise<void>
   end(): Promise<number>
-  waitForOutput(regex: RegExp): Promise<RegExpMatchArray>
+  waitForOutput(
+    regex: RegExp,
+    options?: {
+      timeoutMs?: number
+    }
+  ): Promise<RegExpMatchArray>
   reportMemUsage(
     metricName: string,
     options: {
@@ -28,6 +33,7 @@ class CommandImpl {
   stdout: string = ''
   stderr: string = ''
   output: string = ''
+  outputCursor: number = 0
   exitPromise: Promise<number>
   waitingForOutput: (() => void)[] = []
   constructor(private process: ChildProcess) {
@@ -91,20 +97,62 @@ class CommandImpl {
     await this.exitPromise
   }
 
-  async waitForOutput(regex: RegExp) {
-    let start = this.output.length
+  async waitForOutput(
+    regex: RegExp,
+    options: {
+      timeoutMs?: number
+    } = {}
+  ) {
+    let start = this.outputCursor
+    const deadline =
+      options.timeoutMs === undefined
+        ? undefined
+        : Date.now() + options.timeoutMs
+
     while (true) {
-      const match = this.output.slice(start).match(regex)
+      const outputToSearch = this.output.slice(start)
+      const match = outputToSearch.match(regex)
       if (match) {
+        const matchIndex = match.index ?? outputToSearch.search(regex)
+        if (matchIndex >= 0) {
+          this.outputCursor = start + matchIndex + match[0].length
+        } else {
+          this.outputCursor = this.output.length
+        }
         return match
       }
-      const waitResult = await Promise.race([
+
+      const promises: Promise<number | 'output' | 'timeout'>[] = [
         this.exitPromise,
         new Promise<void>((resolve) => {
           this.waitingForOutput.push(resolve)
         }).then(() => 'output'),
-      ])
+      ]
+
+      let timeoutId: ReturnType<typeof setTimeout> | undefined
+      if (deadline !== undefined) {
+        const timeoutMs = deadline - Date.now()
+        if (timeoutMs <= 0) {
+          throw new Error(
+            `Timed out waiting for output matching ${regex}\n\nOutput:\n${this.output}`
+          )
+        }
+        promises.push(
+          new Promise<'timeout'>((resolve) => {
+            timeoutId = setTimeout(() => resolve('timeout'), timeoutMs)
+          })
+        )
+      }
+
+      const waitResult = await Promise.race(promises)
+      if (timeoutId) clearTimeout(timeoutId)
+
       if (waitResult !== 'output') {
+        if (waitResult === 'timeout') {
+          throw new Error(
+            `Timed out waiting for output matching ${regex}\n\nOutput:\n${this.output}`
+          )
+        }
         throw new Error(
           `Command exited with code ${waitResult}\n\nOutput:\n${this.output}`
         )