Enhance structured logger for script usage (#60860)

Author: Ebonsignori

src/assets/scripts/list-image-sizes.ts

@@ -8,24 +8,41 @@ import { fileURLToPath } from 'url'
 import path from 'path'
 import walk from 'walk-sync'
 import sharp from 'sharp'
+import { createLogger } from '@/observability/logger'
+import { toError } from '@/observability/lib/to-error'
+
+const logger = createLogger(import.meta.url)
+
 const __dirname = path.dirname(fileURLToPath(import.meta.url))
 
-const imagesPath = path.join(__dirname, '../assets/images')
+const imagesPath = path.join(__dirname, '../../../assets/images')
 const imagesExtensions = ['.jpg', '.jpeg', '.png', '.gif']
 
 const files = walk(imagesPath, { directories: false }).filter((relativePath) => {
   return imagesExtensions.includes(path.extname(relativePath.toLowerCase()))
 })
+
+logger.info('Starting image scan', { path: imagesPath, totalFiles: files.length })
+
 const images = await Promise.all(
   files.map(async (relativePath) => {
     const fullPath = path.join(imagesPath, relativePath)
-    const image = sharp(fullPath)
-    const { width, height } = await image.metadata()
-    const size = (width || 0) * (height || 0)
-    return { relativePath, width, height, size }
+    try {
+      const image = sharp(fullPath)
+      const { width, height } = await image.metadata()
+      const size = (width || 0) * (height || 0)
+      return { relativePath, width, height, size }
+    } catch (error) {
+      logger.warn('Failed to read image metadata', toError(error), { relativePath })
+      return { relativePath, width: 0, height: 0, size: 0 }
+    }
   }),
 )
-for (const image of images.sort((a, b) => b.size - a.size)) {
+
+const sorted = images.sort((a, b) => b.size - a.size)
+for (const image of sorted) {
   const { relativePath, width, height } = image
-  console.log(`${width} x ${height} - ${relativePath}`)
+  logger.info(`${width} x ${height} - ${relativePath}`)
 }
+
+logger.info('Image scan complete', { totalImages: sorted.length })

src/observability/logger/index.ts

@@ -1,4 +1,5 @@
 import path from 'path'
+import chalk from 'chalk'
 import { getLoggerContext } from '@/observability/logger/lib/logger-context'
 import {
   getLogLevelNumber,
@@ -8,6 +9,54 @@ import {
 import { toLogfmt } from '@/observability/logger/lib/to-logfmt'
 import { POD_IDENTITY } from '@/observability/logger/lib/pod-identity'
 
+const LEVEL_COLORS: Record<keyof typeof LOG_LEVELS, (s: string) => string> = {
+  error: chalk.red,
+  warn: chalk.yellow,
+  info: chalk.cyan,
+  debug: chalk.gray,
+}
+
+function formatTimestamp(): string {
+  const now = new Date()
+  const h = String(now.getHours()).padStart(2, '0')
+  const m = String(now.getMinutes()).padStart(2, '0')
+  const s = String(now.getSeconds()).padStart(2, '0')
+  const ms = String(now.getMilliseconds()).padStart(3, '0')
+  return `${h}:${m}:${s}.${ms}`
+}
+
+// Format non-error included context as compact key=value pairs
+function formatContext(ctx: Record<string, unknown>): string {
+  const parts: string[] = []
+  for (const [key, value] of Object.entries(ctx)) {
+    if (value instanceof Error) continue // errors handled separately
+    if (value === undefined || value === null || value === '') continue
+    let v: string
+    if (typeof value === 'object') {
+      try {
+        v = JSON.stringify(value)
+      } catch {
+        v = String(value)
+      }
+    } else {
+      v = String(value)
+    }
+    parts.push(`${chalk.dim(`${key}=`)}${v}`)
+  }
+  return parts.length > 0 ? `  ${parts.join(' ')}` : ''
+}
+
+// Safely resolve filePath to a relative path.
+// Handles file:// URLs (from import.meta.url) and plain string labels.
+function resolveFilePath(filePath: string): string {
+  try {
+    const parsed = new URL(filePath)
+    return path.relative(process.cwd(), parsed.pathname)
+  } catch {
+    return filePath
+  }
+}
+
 type IncludeContext = { [key: string]: unknown }
 
 // Read once at module startup so every log line carries the deployed version.
@@ -141,7 +190,7 @@ export function createLogger(filePath: string) {
         timestamp,
         level,
         ...(BUILD_SHA !== undefined ? { build_sha: BUILD_SHA } : {}),
-        file: path.relative(process.cwd(), new URL(filePath).pathname),
+        file: resolveFilePath(filePath),
         message: finalMessage,
       }
 
@@ -164,17 +213,25 @@ export function createLogger(filePath: string) {
 
       console.log(toLogfmt(logObject))
     } else {
-      // If the log includes an error, log to console.error in local dev
+      // Human-readable dev/script logging
+      const relFile = resolveFilePath(filePath)
+      const ts = formatTimestamp()
+      const colorFn = LEVEL_COLORS[level]
+      const lvl = colorFn(level.toUpperCase().padEnd(5))
+      const fileTag = chalk.dim(`(${relFile})`)
+      const contextStr = formatContext(includeContext)
+
+      // If the log includes an error, print the Error object to console.error in local dev
       let wasErrorLog = false
       for (const [, value] of Object.entries(includeContext)) {
         if (typeof value === 'object' && value instanceof Error) {
           wasErrorLog = true
-          console.log(`[${level.toUpperCase()}] ${finalMessage}`)
+          console.log(`${chalk.dim(ts)} ${lvl} ${fileTag} ${finalMessage}${contextStr}`)
           console.error(value)
         }
       }
       if (!wasErrorLog) {
-        console.log(`[${level.toUpperCase()}] ${finalMessage}`)
+        console.log(`${chalk.dim(ts)} ${lvl} ${fileTag} ${finalMessage}${contextStr}`)
       }
     }
   }

src/observability/tests/logger-integration.ts

@@ -3,6 +3,21 @@ import type { Request, Response } from 'express'
 import { createLogger } from '@/observability/logger'
 import { initLoggerContext, updateLoggerContext } from '@/observability/logger/lib/logger-context'
 
+// Strip ANSI escape codes for easier assertion matching
+function stripAnsi(s: string): string {
+  // eslint-disable-next-line no-control-regex
+  return s.replace(/\[\d+m/g, '')
+}
+
+// Check that a dev-mode log line contains the expected level and message
+function expectDevLog(logs: string[], level: string, message: string): void {
+  const match = logs.find((log) => {
+    const clean = stripAnsi(log)
+    return clean.includes(level) && clean.includes(message)
+  })
+  expect(match, `Expected a log containing "${level}" and "${message}"`).toBeDefined()
+}
+
 // Integration tests that use real dependencies without mocks
 describe('logger integration tests', () => {
   let originalConsoleLog: typeof console.log
@@ -147,10 +162,11 @@ describe('logger integration tests', () => {
       logger.error('Error message')
 
       // With 'info' level, debug should be filtered out (debug=3, info=2, so debug > info)
-      expect(consoleLogs).not.toContain('[DEBUG] Debug message')
-      expect(consoleLogs).toContain('[INFO] Info message')
-      expect(consoleLogs).toContain('[WARN] Warn message')
-      expect(consoleLogs).toContain('[ERROR] Error message')
+      const allClean = consoleLogs.map(stripAnsi).join('\n')
+      expect(allClean).not.toContain('Debug message')
+      expectDevLog(consoleLogs, 'INFO', 'Info message')
+      expectDevLog(consoleLogs, 'WARN', 'Warn message')
+      expectDevLog(consoleLogs, 'ERROR', 'Error message')
     })
 
     it('should use real log level filtering with explicit LOG_LEVEL=error', () => {
@@ -171,10 +187,11 @@ describe('logger integration tests', () => {
       logger.error('Error message')
 
       // With 'error' level (0), only error should be logged
-      expect(consoleLogs).not.toContain('[DEBUG] Debug message')
-      expect(consoleLogs).not.toContain('[INFO] Info message')
-      expect(consoleLogs).not.toContain('[WARN] Warn message')
-      expect(consoleLogs).toContain('[ERROR] Error message')
+      const allClean = consoleLogs.map(stripAnsi).join('\n')
+      expect(allClean).not.toContain('Debug message')
+      expect(allClean).not.toContain('Info message')
+      expect(allClean).not.toContain('Warn message')
+      expectDevLog(consoleLogs, 'ERROR', 'Error message')
     })
 
     it('should use real production logging detection with LOG_LIKE_PRODUCTION=true', () => {
@@ -234,10 +251,10 @@ describe('logger integration tests', () => {
       logger.info('Development logging test')
 
       expect(consoleLogs).toHaveLength(1)
-      const logOutput = consoleLogs[0]
 
       // Should be in development format (not logfmt)
-      expect(logOutput).toBe('[INFO] Development logging test')
+      expectDevLog(consoleLogs, 'INFO', 'Development logging test')
+      const logOutput = stripAnsi(consoleLogs[0])
       expect(logOutput).not.toContain('level=info')
       expect(logOutput).not.toContain('timestamp=')
     })