Repository: vercel/next.js
Pull request: [test] Improve debug logs for Playwright tests

This PR enhances the debug logging for Playwright tests by prefixing the messages with a timestamp, which helps debugging timing related issues. It also sends debug messages directly to Node's stdout, bypassing Jest's verbose logging, yielding a more compact output.

In addition, we're not running the tests in silent mode anymore in CI. This is a relic from the past, and we do already set `TRACE_PLAYWRIGHT=true`, which indicates that we want to see all the debug output.

**Before:**

<img width="1487" height="856" alt="playwright logs before" src="https://github.com/user-attachments/assets/dee7455e-25df-46d6-b873-685b0a03be11" />

**After:**

<img width="1487" height="631" alt="playwright logs after" src="https://github.com/user-attachments/assets/5d8eba72-c385-421c-8139-44f48ee3060c" />




Changed files:
filename: run-tests.js
patch: @@ -463,7 +463,6 @@ ${ENDGROUP}`)
         '--runInBand',
         '--forceExit',
         '--verbose',
-        '--silent',
         ...(isTestJob
           ? ['--json', `--outputFile=${test.file}${RESULTS_EXT}`]
           : []),

filename: test/lib/browsers/playwright.ts
patch: @@ -1,4 +1,5 @@
 import fs from 'fs-extra'
+import { debugPrint } from 'next-test-utils'
 import {
   chromium,
   webkit,
@@ -269,7 +270,7 @@ export class Playwright<TCurrent = undefined> {
     websocketFrames = []
 
     page.on('console', (msg) => {
-      console.log('browser log:', msg)
+      debugPrint('Browser Log:', msg)
 
       pageLogs.push(
         Promise.all(

filename: test/lib/next-test-utils.ts
patch: @@ -6,7 +6,7 @@ import {
   writeFileSync,
   createReadStream,
 } from 'fs'
-import { promisify } from 'util'
+import { inspect, promisify } from 'util'
 import http from 'http'
 import path from 'path'
 
@@ -41,6 +41,21 @@ export { shouldUseTurbopack }
 export const nextServer = server
 export const pkg = _pkg
 
+// This goes straight to Node’s stdout, avoiding Jest's verbose output:
+export const debugPrint = (...args: unknown[]) => {
+  const prettyArgs = args
+    .map((arg) =>
+      typeof arg === 'string'
+        ? arg
+        : inspect(arg, { colors: process.stdout.isTTY })
+    )
+    .join(' ')
+
+  const timestamp = new Date().toISOString().split('T')[1]
+
+  return process.stdout.write(`[${timestamp}] ${prettyArgs}\n`)
+}
+
 export function initNextServerScript(
   scriptPath: string,
   successRegexp: RegExp,
@@ -249,7 +264,7 @@ export function runNextCommand(
   }
 
   return new Promise((resolve, reject) => {
-    console.log(`Running command "next ${argv.join(' ')}"`)
+    debugPrint(`Running command "next ${argv.join(' ')}"`)
     const instance = spawn(
       'node',
       [...(options.nodeArgs || []), '--no-deprecation', nextBin, ...argv],
@@ -274,7 +289,7 @@ export function runNextCommand(
         stderrOutput += chunk
 
         if (options.stderr === 'log') {
-          console.log(chunk.toString())
+          debugPrint(chunk.toString())
         }
         if (typeof options.onStderr === 'function') {
           options.onStderr(chunk.toString())
@@ -293,7 +308,7 @@ export function runNextCommand(
         stdoutOutput += chunk
 
         if (options.stdout === 'log') {
-          console.log(chunk.toString())
+          debugPrint(chunk.toString())
         }
         if (typeof options.onStdout === 'function') {
           options.onStdout(chunk.toString())
@@ -820,7 +835,7 @@ export async function retry<T>(
         )
         throw err
       }
-      console.log(
+      debugPrint(
         `Retrying${description ? ` ${description}` : ''} in ${interval}ms`
       )
       await waitFor(interval)

filename: test/lib/next-webdriver.ts
patch: @@ -1,4 +1,4 @@
-import { getFullUrl, waitFor } from 'next-test-utils'
+import { debugPrint, getFullUrl, waitFor } from 'next-test-utils'
 import os from 'os'
 import {
   Playwright,
@@ -146,7 +146,7 @@ export default async function webdriver(
     isBrowserStack ? deviceIP : 'localhost'
   )
 
-  console.log(`\n> Loading browser with ${fullUrl}\n`)
+  debugPrint(`Loading browser with ${fullUrl}`)
 
   await browser.loadPage(fullUrl, {
     disableCache,
@@ -155,13 +155,13 @@ export default async function webdriver(
     pushErrorAsConsoleLog,
     waitUntil,
   })
-  console.log(`\n> Loaded browser with ${fullUrl}\n`)
+  debugPrint(`Loaded browser with ${fullUrl}`)
 
   browserTeardown.push(browser.close.bind(browser))
 
   // Wait for application to hydrate
   if (!disableJavaScript && waitHydration) {
-    console.log(`\n> Waiting hydration for ${fullUrl}\n`)
+    debugPrint(`Waiting hydration for ${fullUrl}`)
 
     const checkHydrated = async () => {
       await browser.eval(() => {
@@ -207,15 +207,15 @@ export default async function webdriver(
       }
     }
 
-    console.log(`\n> Hydration complete for ${fullUrl}\n`)
+    debugPrint(`Hydration complete for ${fullUrl}`)
   }
 
   // This is a temporary workaround for turbopack starting watching too late.
   // So we delay file changes to give it some time
   // to connect the WebSocket and start watching.
   // TODO: Is this still needed? Can we wait in a more useful way, like a socket connection event?
   if (process.env.IS_TURBOPACK_TEST && process.env.TURBOPACK_DEV) {
-    console.log(`\n> Waiting for for turbopack watcher to start`)
+    debugPrint(`Waiting for for turbopack watcher to start`)
     await waitFor(1000)
   }
   return browser