Move request logging code out of NextNodeServer

packages/next/src/server/config-shared.ts

@@ -199,6 +199,12 @@ export interface ReactCompilerOptions {
   panicThreshold?: 'ALL_ERRORS' | 'CRITICAL_ERRORS' | 'NONE'
 }
 
+export interface LoggingConfig {
+  fetches?: {
+    fullUrl?: boolean
+  }
+}
+
 export interface ExperimentalConfig {
   appNavFailHandling?: boolean
   flyingShuttle?: boolean
@@ -853,13 +859,7 @@ export interface NextConfig extends Record<string, any> {
     }
   >
 
-  logging?:
-    | {
-        fetches?: {
-          fullUrl?: boolean
-        }
-      }
-    | false
+  logging?: LoggingConfig | false
 
   /**
    * period (in seconds) where the server allow to serve stale cache

packages/next/src/server/dev/log-requests.ts

@@ -0,0 +1,145 @@
+import {
+  blue,
+  bold,
+  gray,
+  green,
+  red,
+  white,
+  yellow,
+} from '../../lib/picocolors'
+import { stripNextRscUnionQuery } from '../../lib/url'
+import type { FetchMetric } from '../base-http'
+import type { NodeNextRequest, NodeNextResponse } from '../base-http/node'
+import type { LoggingConfig } from '../config-shared'
+import { getRequestMeta } from '../request-meta'
+
+export interface RequestLoggingOptions {
+  readonly request: NodeNextRequest
+  readonly response: NodeNextResponse
+  readonly loggingConfig: LoggingConfig | undefined
+  readonly requestDurationInMs: number
+}
+
+export function logRequests(options: RequestLoggingOptions): void {
+  const { request, response, loggingConfig, requestDurationInMs } = options
+
+  logIncomingRequest({
+    request,
+    requestDurationInMs,
+    statusCode: response.statusCode,
+  })
+
+  if (request.fetchMetrics) {
+    for (const fetchMetric of request.fetchMetrics) {
+      logFetchMetric(fetchMetric, loggingConfig)
+    }
+  }
+}
+
+interface IncomingRequestOptions {
+  readonly request: NodeNextRequest
+  readonly requestDurationInMs: number
+  readonly statusCode: number
+}
+
+function logIncomingRequest(options: IncomingRequestOptions): void {
+  const { request, requestDurationInMs, statusCode } = options
+  const isRSC = getRequestMeta(request, 'isRSCRequest')
+  const url = isRSC ? stripNextRscUnionQuery(request.url) : request.url
+
+  const statusCodeColor =
+    statusCode < 200
+      ? white
+      : statusCode < 300
+        ? green
+        : statusCode < 400
+          ? blue
+          : statusCode < 500
+            ? yellow
+            : red
+
+  const coloredStatus = statusCodeColor(statusCode.toString())
+
+  return writeLine(
+    `${request.method} ${url} ${coloredStatus} in ${requestDurationInMs}ms`
+  )
+}
+
+function logFetchMetric(
+  fetchMetric: FetchMetric,
+  loggingConfig: LoggingConfig | undefined
+): void {
+  let {
+    cacheReason,
+    cacheStatus,
+    cacheWarning,
+    end,
+    method,
+    start,
+    status,
+    url,
+  } = fetchMetric
+
+  if (cacheStatus === 'hmr') {
+    // Cache hits during HMR refreshes are intentionally not logged.
+    return
+  }
+
+  if (loggingConfig?.fetches) {
+    if (url.length > 48 && !loggingConfig.fetches.fullUrl) {
+      url = truncateUrl(url)
+    }
+
+    writeLine(
+      white(
+        `${method} ${url} ${status} in ${end - start}ms ${formatCacheStatus(cacheStatus)}`
+      ),
+      1
+    )
+
+    if (cacheStatus === 'skip' || cacheStatus === 'miss') {
+      writeLine(
+        gray(
+          `Cache ${cacheStatus === 'skip' ? 'skipped' : 'missed'} reason: (${white(cacheReason)})`
+        ),
+        2
+      )
+    }
+  } else if (cacheWarning) {
+    // When logging for fetches is not enabled, we still want to print any
+    // associated warnings, so we print the request first to provide context.
+    writeLine(white(`${method} ${url}`), 1)
+  }
+
+  if (cacheWarning) {
+    writeLine(`${yellow(bold('⚠'))} ${white(cacheWarning)}`, 2)
+  }
+}
+
+function writeLine(text: string, indentationLevel = 0): void {
+  process.stdout.write(` ${'│ '.repeat(indentationLevel)}${text}\n`)
+}
+
+function truncate(text: string, maxLength: number): string {
+  return maxLength !== undefined && text.length > maxLength
+    ? text.substring(0, maxLength) + '..'
+    : text
+}
+
+function truncateUrl(url: string): string {
+  const { protocol, host, pathname, search } = new URL(url)
+
+  return (
+    protocol +
+    '//' +
+    truncate(host, 16) +
+    truncate(pathname, 24) +
+    truncate(search, 16)
+  )
+}
+
+function formatCacheStatus(cacheStatus: 'hit' | 'miss' | 'skip'): string {
+  const color = cacheStatus === 'hit' ? green : yellow
+
+  return color(`(cache ${cacheStatus})`)
+}

packages/next/src/server/dev/next-dev-server.ts

@@ -1,4 +1,4 @@
-import type { FindComponentsResult } from '../next-server'
+import type { FindComponentsResult, NodeRequestHandler } from '../next-server'
 import type { LoadComponentsReturnType } from '../load-components'
 import type { Options as ServerOptions } from '../next-server'
 import type { Params } from '../../client/components/params'
@@ -9,9 +9,10 @@ import type { FallbackMode, MiddlewareRoutingItem } from '../base-server'
 import type { FunctionComponent } from 'react'
 import type { RouteDefinition } from '../route-definitions/route-definition'
 import type { RouteMatcherManager } from '../route-matcher-managers/route-matcher-manager'
-import type {
-  NextParsedUrlQuery,
-  NextUrlWithParsedQuery,
+import {
+  getRequestMeta,
+  type NextParsedUrlQuery,
+  type NextUrlWithParsedQuery,
 } from '../request-meta'
 import type { DevBundlerService } from '../lib/dev-bundler-service'
 import type { IncrementalCache } from '../lib/incremental-cache'
@@ -67,6 +68,7 @@ import { buildCustomRoute } from '../../lib/build-custom-route'
 import { decorateServerError } from '../../shared/lib/error-source'
 import type { ServerOnInstrumentationRequestError } from '../app-render/types'
 import type { ServerComponentsHmrCache } from '../response-cache'
+import { logRequests } from './log-requests'
 
 // Load ReactDevOverlay only when needed
 let ReactDevOverlayImpl: FunctionComponent
@@ -461,6 +463,43 @@ export default class DevServer extends Server {
     }
   }
 
+  public getRequestHandler(): NodeRequestHandler {
+    const handler = super.getRequestHandler()
+
+    return (req, res, parsedUrl) => {
+      const request = this.normalizeReq(req)
+      const response = this.normalizeRes(res)
+      const loggingConfig = this.nextConfig.logging
+
+      if (loggingConfig !== false) {
+        const start = Date.now()
+        const isMiddlewareRequest = getRequestMeta(req, 'middlewareInvoke')
+
+        if (!isMiddlewareRequest) {
+          response.originalResponse.once('close', () => {
+            // NOTE: The route match is only attached to the request's meta data
+            // after the request handler is created, so we need to check it in the
+            // close handler and not before.
+            const routeMatch = getRequestMeta(req).match
+
+            if (!routeMatch) {
+              return
+            }
+
+            logRequests({
+              request,
+              response,
+              loggingConfig,
+              requestDurationInMs: Date.now() - start,
+            })
+          })
+        }
+      }
+
+      return handler(request, response, parsedUrl)
+    }
+  }
+
   public async handleRequest(
     req: NodeNextRequest,
     res: NodeNextResponse,