Repository: vercel/next.js
Pull request: Build: Add time to logline of every step

## What?

Add timing to every step of the `next build` process for both Turbopack and webpack.

Besides the existing `compiled successfully in` time for Turbopack/webpack these now also have timings:

```
 ✓ Linting and checking validity of types in 954ms    
 ✓ Collecting page data in 205ms    
 ✓ Generating static pages (4/4) in 307ms
 ✓ Collecting build traces in 3.3s    
 ✓ Finalizing page optimization in 3.3s 
```

Closes PACK-5638

Changed files:
filename: packages/next/src/build/duration-to-string.ts
patch: @@ -11,3 +11,12 @@ export function durationToString(compilerDuration: number) {
   }
   return durationString
 }
+
+export function hrtimeToSeconds(hrtime: [number, number]): number {
+  // hrtime is a tuple of [seconds, nanoseconds]
+  return hrtime[0] + hrtime[1] / 1e9
+}
+
+export function hrtimeDurationToString(hrtime: [number, number]): string {
+  return durationToString(hrtimeToSeconds(hrtime))
+}

filename: packages/next/src/build/index.ts
patch: @@ -209,7 +209,7 @@ import { turbopackBuild } from './turbopack-build'
 import { isPersistentCachingEnabledForBuild } from '../shared/lib/turbopack/utils'
 import { inlineStaticEnv } from '../lib/inline-static-env'
 import { populateStaticEnv } from '../lib/static-env'
-import { durationToString } from './duration-to-string'
+import { durationToString, hrtimeDurationToString } from './duration-to-string'
 import { traceGlobals } from '../trace/shared'
 import { extractNextErrorCode } from '../lib/error-telemetry-utils'
 import { runAfterProductionCompile } from './after-production-compile'
@@ -1846,6 +1846,7 @@ export default async function build(
         traceMemoryUsage('Finished type checking', nextBuildSpan)
       }
 
+      const collectingPageDataStart = process.hrtime()
       const postCompileSpinner = createSpinner('Collecting page data')
 
       const buildManifestPath = path.join(distDir, BUILD_MANIFEST)
@@ -2413,7 +2414,13 @@ export default async function build(
         return returnValue
       })
 
-      if (postCompileSpinner) postCompileSpinner.stopAndPersist()
+      if (postCompileSpinner) {
+        const collectingPageDataEnd = process.hrtime(collectingPageDataStart)
+        postCompileSpinner.setText(
+          `Collecting page data in ${hrtimeDurationToString(collectingPageDataEnd)}`
+        )
+        postCompileSpinner.stopAndPersist()
+      }
       traceMemoryUsage('Finished collecting page data', nextBuildSpan)
 
       if (customAppGetInitialProps) {
@@ -3890,9 +3897,12 @@ export default async function build(
           .traceAsyncFn(() => writeManifest(routesManifestPath, routesManifest))
       }
 
+      const finalizingPageOptimizationStart = process.hrtime()
       const postBuildSpinner = createSpinner('Finalizing page optimization')
       let buildTracesSpinner
+      let buildTracesStart
       if (buildTracesPromise) {
+        buildTracesStart = process.hrtime()
         buildTracesSpinner = createSpinner('Collecting build traces')
       }
 
@@ -4044,6 +4054,12 @@ export default async function build(
       await buildTracesPromise
 
       if (buildTracesSpinner) {
+        if (buildTracesStart) {
+          const buildTracesEnd = process.hrtime(buildTracesStart)
+          buildTracesSpinner.setText(
+            `Collecting build traces in ${hrtimeDurationToString(buildTracesEnd)}`
+          )
+        }
         buildTracesSpinner.stopAndPersist()
         buildTracesSpinner = undefined
       }
@@ -4117,7 +4133,15 @@ export default async function build(
           })
       }
 
-      if (postBuildSpinner) postBuildSpinner.stopAndPersist()
+      if (postBuildSpinner) {
+        const finalizingPageOptimizationEnd = process.hrtime(
+          finalizingPageOptimizationStart
+        )
+        postBuildSpinner.setText(
+          `Finalizing page optimization in ${hrtimeDurationToString(finalizingPageOptimizationEnd)}`
+        )
+        postBuildSpinner.stopAndPersist()
+      }
       console.log()
 
       if (debugOutput) {

filename: packages/next/src/build/progress.ts
patch: @@ -1,4 +1,5 @@
 import * as Log from '../build/output/log'
+import { hrtimeDurationToString } from './duration-to-string'
 import createSpinner from './spinner'
 
 function divideSegments(number: number, segments: number): number[] {
@@ -15,6 +16,8 @@ function divideSegments(number: number, segments: number): number[] {
 }
 
 export const createProgress = (total: number, label: string) => {
+  const progressStart = process.hrtime()
+
   const segments = divideSegments(total, 4)
 
   if (total === 0) {
@@ -74,7 +77,8 @@ export const createProgress = (total: number, label: string) => {
     } else {
       progressSpinner?.stop()
       if (isFinished) {
-        Log.event(message)
+        const progressEnd = process.hrtime(progressStart)
+        Log.event(`${message} in ${hrtimeDurationToString(progressEnd)}`)
       } else {
         Log.info(`${message} ${process.stdout.isTTY ? '\n' : '\r'}`)
       }

filename: packages/next/src/build/type-check.ts
patch: @@ -9,6 +9,7 @@ import { verifyAndLint } from '../lib/verifyAndLint'
 import createSpinner from './spinner'
 import { eventTypeCheckCompleted } from '../telemetry/events'
 import isError from '../lib/is-error'
+import { hrtimeDurationToString } from './duration-to-string'
 
 /**
  * typescript will be loaded in "next/lib/verify-typescript-setup" and
@@ -156,7 +157,13 @@ export async function startTypeChecking({
           )
         }),
     ])
-    typeCheckingAndLintingSpinner?.stopAndPersist()
+
+    if (typeCheckingAndLintingSpinner) {
+      typeCheckingAndLintingSpinner.setText(
+        `${typeCheckingAndLintingSpinnerPrefixText} in ${hrtimeDurationToString(typeCheckEnd)}`
+      )
+      typeCheckingAndLintingSpinner.stopAndPersist()
+    }
 
     if (!ignoreTypeScriptErrors && verifyResult) {
       telemetry.record(

filename: packages/next/src/build/webpack-build/impl.ts
patch: @@ -40,15 +40,10 @@ import type { UnwrapPromise } from '../../lib/coalesced-function'
 
 import origDebug from 'next/dist/compiled/debug'
 import { Telemetry } from '../../telemetry/storage'
-import { durationToString } from '../duration-to-string'
+import { durationToString, hrtimeToSeconds } from '../duration-to-string'
 
 const debug = origDebug('next:build:webpack-build')
 
-function hrtimeToSeconds(hrtime: [number, number]): number {
-  // hrtime is a tuple of [seconds, nanoseconds]
-  return hrtime[0] + hrtime[1] / 1e9
-}
-
 type CompilerResult = {
   errors: webpack.StatsError[]
   warnings: webpack.StatsError[]