Repository: vercel/next.js
Pull request: [Instant] speed up test instant-validation suite

This PR speeds up the `instant-validation` test suite from 450s down to ~100s. We were wasting a lot of time in `waitForNoErrorToast()`, which ends up waiting almost 15s by default.

The trick is to add some debug logs inside app-render to track when instant validation started/ended. If we know that the validation is finished, we can just wait for a short time, because if there were errors, a toast would be displayed very quickly.

Note that is a stopgap -- when we add a "Validating..." indicator, we won't have to emit the log and can just wait for the indicator instead. But in the meantime, waiting for the tests is pretty painful, so this is worth doing.

Changed files:
filename: packages/next/src/server/app-render/app-render.tsx
patch: @@ -3615,13 +3615,39 @@ async function logMessagesAndSendErrorsToBrowser(
   }
 }
 
+async function spawnStaticShellValidationInDev(
+  ...args: Parameters<typeof spawnStaticShellValidationInDevImpl>
+) {
+  if (process.env.__NEXT_TEST_MODE && process.env.NEXT_TEST_LOG_VALIDATION) {
+    const ctx: AppRenderContext = args[5]
+    const requestId = ctx.requestId
+    const url = ctx.url.href
+    console.log(
+      '<VALIDATION_MESSAGE>' +
+        JSON.stringify({ type: 'validation_start', requestId, url }) +
+        '</VALIDATION_MESSAGE>'
+    )
+    try {
+      return await spawnStaticShellValidationInDevImpl(...args)
+    } finally {
+      console.log(
+        '<VALIDATION_MESSAGE>' +
+          JSON.stringify({ type: 'validation_end', requestId, url }) +
+          '</VALIDATION_MESSAGE>'
+      )
+    }
+  } else {
+    return await spawnStaticShellValidationInDevImpl(...args)
+  }
+}
+
 /**
  * This function is a fork of prerenderToStream cacheComponents branch.
  * While it doesn't return a stream we want it to have identical
  * prerender semantics to prerenderToStream and should update it
  * in conjunction with any changes to that function.
  */
-async function spawnStaticShellValidationInDev(
+async function spawnStaticShellValidationInDevImpl(
   accumulatedChunksPromise: Promise<AccumulatedStreamChunks>,
   syncInterruptReason: Error | null,
   startTime: number,

filename: test/e2e/app-dir/instant-validation/app/suspense-in-root/static/invalid-only-loading-around-dynamic/page.tsx
patch: @@ -28,7 +28,6 @@ async function Runtime() {
 }
 
 async function Dynamic() {
-  await new Promise((resolve) => setTimeout(resolve, 1000))
   await connection()
   return <div id="dynamic-content">Dynamic content from page</div>
 }

filename: test/e2e/app-dir/instant-validation/instant-validation.test.ts
patch: @@ -15,13 +15,112 @@ describe('instant validation', () => {
   const { next, skipped, isNextDev } = nextTestSetup({
     files: __dirname,
     skipDeployment: true,
+    env: {
+      NEXT_TEST_LOG_VALIDATION: '1',
+    },
   })
   if (skipped) return
   if (!isNextDev) {
     it.skip('Only implemented in dev', () => {})
     return
   }
 
+  let currentCliOutputIndex = 0
+  beforeEach(() => {
+    currentCliOutputIndex = next.cliOutput.length
+  })
+
+  function getCliOutputSinceMark(): string {
+    if (next.cliOutput.length < currentCliOutputIndex) {
+      // cliOutput shrank since we started the test, so something (like a `sandbox`) reset the logs
+      currentCliOutputIndex = 0
+    }
+    return next.cliOutput.slice(currentCliOutputIndex)
+  }
+
+  type ValidationEvent =
+    | { type: 'validation_start'; requestId: string; url: string }
+    | { type: 'validation_end'; requestId: string; url: string }
+
+  async function waitForValidationStart(targetUrl: string): Promise<string> {
+    const parsedTargetUrl = new URL(targetUrl)
+    const relativeTargetUrl =
+      parsedTargetUrl.pathname + parsedTargetUrl.search + parsedTargetUrl.hash
+
+    const requestId = await retry(
+      async () => {
+        const events = parseValidationMessages(getCliOutputSinceMark())
+        const start = events.find(
+          (e) =>
+            e.type === 'validation_start' &&
+            normalizeValidationUrl(e.url) === relativeTargetUrl
+        )
+        expect(start).toBeDefined()
+        return start!.requestId
+      },
+      undefined,
+      undefined,
+      `wait for validation of '${relativeTargetUrl}' to start`
+    )
+    return requestId
+  }
+
+  async function waitForValidationEnd(requestId: string): Promise<void> {
+    await retry(
+      async () => {
+        const events = parseValidationMessages(getCliOutputSinceMark())
+        const end = events.find(
+          (e) => e.type === 'validation_end' && e.requestId === requestId
+        )
+        expect(end).toBeDefined()
+      },
+      undefined,
+      undefined,
+      'wait for validation to end'
+    )
+  }
+
+  async function waitForValidation(url: string) {
+    const requestId = await waitForValidationStart(url)
+    await waitForValidationEnd(requestId)
+  }
+
+  const NO_VALIDATION_ERRORS_WAIT: Parameters<typeof waitForNoErrorToast>[1] = {
+    waitInMs: 500,
+  }
+
+  async function expectNoValidationErrors(
+    browser: Awaited<ReturnType<typeof next.browser>>,
+    url: string
+  ): Promise<void> {
+    await waitForValidation(url)
+    await waitForNoErrorToast(browser, NO_VALIDATION_ERRORS_WAIT)
+  }
+
+  function parseValidationMessages(output: string): ValidationEvent[] {
+    const messageRe = /<VALIDATION_MESSAGE>(.*?)<\/VALIDATION_MESSAGE>/g
+    const events: ValidationEvent[] = []
+    let match: RegExpExecArray | null
+    while ((match = messageRe.exec(output)) !== null) {
+      try {
+        events.push(JSON.parse(match[1]))
+      } catch (err) {
+        throw new Error(`Failed to parse message '${match[1]}'`, {
+          cause: err,
+        })
+      }
+    }
+    return events
+  }
+
+  function normalizeValidationUrl(url: string): string {
+    // RSC requests include ?_rsc=... in the URL. Strip it so the event URL
+    // matches what browser.url() returns (which has no _rsc param).
+    const parsed = new URL(url, 'http://n')
+    parsed.searchParams.delete('_rsc')
+    return parsed.pathname + parsed.search + parsed.hash
+  }
+
   describe.each([
     { isClientNav: false, description: 'initial load' },
     { isClientNav: true, description: 'client navigation' },
@@ -56,7 +155,7 @@ describe('instant validation', () => {
           expect(await browser.url()).toContain(href)
         },
         undefined,
-        undefined,
+        100,
         'wait for url to change'
       )
 
@@ -72,13 +171,13 @@ describe('instant validation', () => {
       const browser = await navigateTo(
         '/suspense-in-root/static/suspense-around-dynamic'
       )
-      await waitForNoErrorToast(browser)
+      await expectNoValidationErrors(browser, await browser.url())
     })
     it('valid - runtime prefetch - suspense only around dynamic', async () => {
       const browser = await navigateTo(
         '/suspense-in-root/runtime/suspense-around-dynamic'
       )
-      await waitForNoErrorToast(browser)
+      await expectNoValidationErrors(browser, await browser.url())
     })
 
     it('invalid - static prefetch - missing suspense around runtime', async () => {
@@ -276,7 +375,7 @@ describe('instant validation', () => {
       const browser = await navigateTo(
         '/suspense-in-root/runtime/valid-no-suspense-around-params/123'
       )
-      await waitForNoErrorToast(browser)
+      await expectNoValidationErrors(browser, await browser.url())
     })
 
     it('invalid - static prefetch - missing suspense around search params', async () => {
@@ -316,7 +415,7 @@ describe('instant validation', () => {
       const browser = await navigateTo(
         '/suspense-in-root/runtime/valid-no-suspense-around-search-params?foo=bar'
       )
-      await waitForNoErrorToast(browser)
+      await expectNoValidationErrors(browser, await browser.url())
     })
 
     it('valid - target segment not visible in all navigations', async () => {
@@ -330,7 +429,7 @@ describe('instant validation', () => {
       // in all navigations (which would require that its parent layouts must never
       // block the children slots)
       const browser = await navigateTo('/default/static/valid-blocked-children')
-      await waitForNoErrorToast(browser)
+      await expectNoValidationErrors(browser, await browser.url())
     })
 
     it('invalid - static prefetch - suspense too high', async () => {
@@ -479,7 +578,7 @@ describe('instant validation', () => {
       const browser = await navigateTo(
         '/suspense-in-root/runtime/valid-sync-io-in-static-parent'
       )
-      await waitForNoErrorToast(browser)
+      await expectNoValidationErrors(browser, await browser.url())
     })
 
     it('invalid - missing suspense around dynamic (with loading.js)', async () => {
@@ -503,11 +602,11 @@ describe('instant validation', () => {
        Learn more: https://nextjs.org/docs/messages/blocking-route",
          "environmentLabel": "Server",
          "label": "Blocking Route",
-         "source": "app/suspense-in-root/static/invalid-only-loading-around-dynamic/page.tsx (32:19) @ Dynamic
-       > 32 |   await connection()
+         "source": "app/suspense-in-root/static/invalid-only-loading-around-dynamic/page.tsx (31:19) @ Dynamic
+       > 31 |   await connection()
             |                   ^",
          "stack": [
-           "Dynamic app/suspense-in-root/static/invalid-only-loading-around-dynamic/page.tsx (32:19)",
+           "Dynamic app/suspense-in-root/static/invalid-only-loading-around-dynamic/page.tsx (31:19)",
            "Page app/suspense-in-root/static/invalid-only-loading-around-dynamic/page.tsx (19:9)",
          ],
        }
@@ -519,7 +618,7 @@ describe('instant validation', () => {
         const browser = await navigateTo(
           '/suspense-in-root/static/blocking-layout'
         )
-        await waitForNoErrorToast(browser)
+        await expectNoValidationErrors(browser, await browser.url())
       })
       it('invalid - missing suspense inside blocking layout', async () => {
         const browser = await navigateTo(
@@ -558,13 +657,13 @@ describe('instant validation', () => {
         const browser = await navigateTo(
           '/default/static/valid-blocking-inside-static'
         )
-        await waitForNoErrorToast(browser)
+        await expectNoValidationErrors(browser, await browser.url())
       })
       it('valid - blocking page inside a runtime layout is allowed if the layout has suspense', async () => {
         const browser = await navigateTo(
           '/suspense-in-root/runtime/valid-blocking-inside-runtime'
         )
-        await waitForNoErrorToast(browser)
+        await expectNoValidationErrors(browser, await browser.url())
       })
 
       it('invalid - blocking page inside a static layout is not allowed if the layout has no suspense', async () => {
@@ -757,26 +856,26 @@ describe('instant validation', () => {
         const browser = await navigateTo(
           '/suspense-in-root/static/valid-client-data-does-not-block-validation'
         )
-        await waitForNoErrorToast(browser)
+        await expectNoValidationErrors(browser, await browser.url())
       })
 
       it('valid - parent uses sync IO in a client component', async () => {
         const browser = await navigateTo(
           '/suspense-in-root/static/valid-client-api-in-parent/sync-io'
         )
-        await waitForNoErrorToast(browser)
+        await expectNoValidationErrors(browser, await browser.url())
       })
       it('valid - parent uses dynamic usePathname() in a client component', async () => {
         const browser = await navigateTo(
           '/suspense-in-root/static/valid-client-api-in-parent/dynamic-params/123'
         )
-        await waitForNoErrorToast(browser)
+        await expectNoValidationErrors(browser, await browser.url())
       })
       it('valid - parent uses useSearchPatams() in a client component', async () => {
         const browser = await navigateTo(
           '/suspense-in-root/static/valid-client-api-in-parent/search-params'
         )
-        await waitForNoErrorToast(browser)
+        await expectNoValidationErrors(browser, await browser.url())
       })
     })
 
@@ -910,9 +1009,10 @@ describe('instant validation', () => {
         const browser = await navigateTo(
           '/suspense-in-root/static/valid-client-error-in-parent-does-not-block-validation'
         )
+        await waitForValidation(await browser.url())
         if (isClientNav) {
           // In a client nav, no errors should be reported.
-          await waitForNoErrorToast(browser)
+          await waitForNoErrorToast(browser, NO_VALIDATION_ERRORS_WAIT)
         } else {
           // In SSR, we expect to only see the error coming from react.
           await expect(browser).toDisplayCollapsedRedbox(`
@@ -935,23 +1035,26 @@ describe('instant validation', () => {
     })
 
     describe('disabling validation', () => {
+      // We don't log any messages if validation is skipped, so the best we can do is wait.
+      const VALIDATION_SKIPPED_WAIT: Parameters<typeof waitForNoErrorToast>[1] =
+        { waitInMs: 3000 }
       it('in a layout', async () => {
         const browser = await navigateTo(
           '/suspense-in-root/disable-validation/in-layout'
         )
-        await waitForNoErrorToast(browser)
+        await waitForNoErrorToast(browser, VALIDATION_SKIPPED_WAIT)
       })
       it('in a page', async () => {
         const browser = await navigateTo(
           '/suspense-in-root/disable-validation/in-page'
         )
-        await waitForNoErrorToast(browser)
+        await waitForNoErrorToast(browser, VALIDATION_SKIPPED_WAIT)
       })
       it('in a page with a parent that has a config', async () => {
         const browser = await navigateTo(
           '/suspense-in-root/disable-validation/in-page-with-outer'
         )
-        await waitForNoErrorToast(browser)
+        await waitForNoErrorToast(browser, VALIDATION_SKIPPED_WAIT)
       })
     })
   })

filename: test/lib/next-test-utils.ts
patch: @@ -896,11 +896,14 @@ export async function waitForNoRedbox(
   }
 }
 
-export async function waitForNoErrorToast(browser: Playwright): Promise<void> {
+export async function waitForNoErrorToast(
+  browser: Playwright,
+  { waitInMs }: { waitInMs?: number } = {}
+): Promise<void> {
   let didOpenRedbox = false
 
   try {
-    await browser.waitForElementByCss('[data-issues]').click()
+    await browser.waitForElementByCss('[data-issues]', waitInMs).click()
     didOpenRedbox = true
   } catch {
     // We expect this to fail.