Merge pull request #4536 from Shopify/improve-user-logs

[Themes] Dev Server - Improve user logging for render requests

.changeset/big-hairs-carry.md

@@ -0,0 +1,5 @@
+---
+'@shopify/cli': minor
+---
+
+Improve user logging for render requests

packages/theme/src/cli/utilities/theme-environment/html.ts

@@ -2,18 +2,19 @@ import {getProxyStorefrontHeaders, patchRenderingResponse} from './proxy.js'
 import {getInMemoryTemplates, injectHotReloadScript} from './hot-reload/server.js'
 import {render} from './storefront-renderer.js'
 import {getExtensionInMemoryTemplates} from '../theme-ext-environment/theme-ext-server.js'
-import {defineEventHandler, getCookie, setResponseHeader, setResponseStatus, type H3Error} from 'h3'
+import {timestampDateFormat} from '../../constants.js'
+import {defineEventHandler, getCookie, H3Event, setResponseHeader, setResponseStatus, type H3Error} from 'h3'
 import {renderError, renderFatalError} from '@shopify/cli-kit/node/ui'
-import {outputInfo} from '@shopify/cli-kit/node/output'
+import {outputContent, outputInfo, outputToken} from '@shopify/cli-kit/node/output'
 import {AbortError} from '@shopify/cli-kit/node/error'
 import type {Response} from '@shopify/cli-kit/node/http'
 import type {Theme} from '@shopify/cli-kit/node/themes/types'
 import type {DevServerContext} from './types.js'
 
+const CHARACTER_TRUNCATION_LIMIT = 80
+
 export function getHtmlHandler(theme: Theme, ctx: DevServerContext) {
  return defineEventHandler((event) => {
- outputInfo(`${event.method} ${event.path}`)
-
  const [browserPathname = '/', browserSearch = ''] = event.path.split('?')
 
  return render(ctx.session, {
@@ -27,6 +28,8 @@ export function getHtmlHandler(theme: Theme, ctx: DevServerContext) {
  replaceTemplates: getInMemoryTemplates(ctx, browserPathname, getCookie(event, 'localization')?.toLowerCase()),
  })
  .then(async (response) => {
+ logRequestLine(event, response)
+
  let html = await patchRenderingResponse(ctx, event, response)
 
  html = prettifySyntaxErrors(html)
@@ -67,6 +70,22 @@ export function getHtmlHandler(theme: Theme, ctx: DevServerContext) {
  })
 }
 
+function logRequestLine(event: H3Event, response: Response) {
+ const truncatedPath =
+ event.path.length > CHARACTER_TRUNCATION_LIMIT
+ ? `${event.path.substring(0, CHARACTER_TRUNCATION_LIMIT)}...`
+ : event.path
+ const serverTiming = response.headers.get('server-timing')
+ const requestDuration = serverTiming?.match(/cfRequestDuration;dur=([\d.]+)/)?.[1]
+ const durationString = requestDuration ? `${Math.round(Number(requestDuration))}ms` : ''
+
+ outputInfo(
+ outputContent`• ${timestampDateFormat.format(new Date())} Request ${outputToken.raw('»')} ${outputToken.gray(
+ `${event.method} ${truncatedPath} ${durationString}`,
+ )}`,
+ )
+}
+
 export function prettifySyntaxErrors(html: string) {
  return html.replace(/Liquid(?: syntax)? error \([^\n]+(?:\n|<)/g, getErrorSection)
 }