feat: add profiling utilities for performance measurement

packages/payload/src/utilities/profiling.ts

@@ -0,0 +1,96 @@
+import { performance } from 'perf_hooks'
+
+const isEnabled = (): boolean => process.env.PAYLOAD_DEBUG_TIMING === 'true'
+
+// Track nested calls to build hierarchy
+const callStack: string[] = []
+
+/**
+ * Wrap a synchronous function with timing instrumentation.
+ * Only active when PAYLOAD_DEBUG_TIMING=true.
+ */
+export function timeSync<T>(name: string, fn: () => T): T {
+  if (!isEnabled()) {
+    return fn()
+  }
+
+  const fullName = callStack.length ? `${callStack.at(-1)} > ${name}` : name
+  callStack.push(name)
+
+  performance.mark(`${fullName}:start`)
+  try {
+    const result = fn()
+    performance.mark(`${fullName}:end`)
+    performance.measure(fullName, `${fullName}:start`, `${fullName}:end`)
+    return result
+  } finally {
+    callStack.pop()
+  }
+}
+
+/**
+ * Wrap an async function with timing instrumentation.
+ * Only active when PAYLOAD_DEBUG_TIMING=true.
+ */
+export async function timeAsync<T>(name: string, fn: () => Promise<T>): Promise<T> {
+  if (!isEnabled()) {
+    return fn()
+  }
+
+  const fullName = callStack.length ? `${callStack.at(-1)} > ${name}` : name
+  callStack.push(name)
+
+  performance.mark(`${fullName}:start`)
+  try {
+    const result = await fn()
+    performance.mark(`${fullName}:end`)
+    performance.measure(fullName, `${fullName}:start`, `${fullName}:end`)
+    return result
+  } finally {
+    callStack.pop()
+  }
+}
+
+/**
+ * Print aggregated timing results to console.
+ * Shows operation name, total time, percentage, count, and average.
+ */
+export function printProfileResults(): void {
+  if (!isEnabled()) {
+    return
+  }
+
+  const entries = performance.getEntriesByType('measure')
+  const grouped = new Map<string, { count: number; total: number }>()
+
+  for (const entry of entries) {
+    const existing = grouped.get(entry.name) ?? { count: 0, total: 0 }
+    grouped.set(entry.name, {
+      count: existing.count + 1,
+      total: existing.total + entry.duration,
+    })
+  }
+
+  // Calculate total time from top-level operations only (no " > " in name)
+  const topLevelTime = Array.from(grouped.entries())
+    .filter(([name]) => !name.includes(' > '))
+    .reduce((sum, [, v]) => sum + v.total, 0)
+
+  const sorted = Array.from(grouped.entries())
+    .sort((a, b) => b[1].total - a[1].total)
+    .map(([name, { count, total }]) => ({
+      name,
+      avg: `${(total / count).toFixed(2)}ms`,
+      count,
+      pct: `${((total / topLevelTime) * 100).toFixed(1)}%`,
+      total: `${total.toFixed(2)}ms`,
+    }))
+
+  // eslint-disable-next-line no-console
+  console.log('\n=== sanitizeConfig Profile ===')
+  // eslint-disable-next-line no-console
+  console.table(sorted)
+
+  performance.clearMeasures()
+  performance.clearMarks()
+}

test/profiling/collections/index.ts

@@ -0,0 +1,43 @@
+import type { CollectionConfig, Field } from 'payload'
+
+function createNestedFields(depth: number, prefix: string): Field[] {
+  if (depth === 0) {
+    return [{ name: `${prefix}_text`, type: 'text' }]
+  }
+
+  return [
+    {
+      name: `${prefix}_group`,
+      type: 'group',
+      fields: createNestedFields(depth - 1, `${prefix}_g`),
+    },
+    {
+      name: `${prefix}_array`,
+      type: 'array',
+      fields: createNestedFields(depth - 1, `${prefix}_a`),
+    },
+    {
+      type: 'tabs',
+      tabs: [
+        { label: 'Tab1', fields: createNestedFields(depth - 1, `${prefix}_t1`) },
+        { label: 'Tab2', fields: createNestedFields(depth - 1, `${prefix}_t2`) },
+      ],
+    },
+  ]
+}
+
+export function generateCollections(count: number): CollectionConfig[] {
+  return Array.from({ length: count }, (_, i) => ({
+    slug: `collection-${i}`,
+    fields: [
+      ...createNestedFields(4, `c${i}`),
+      { name: 'richText', type: 'richText' },
+      {
+        name: 'virtual',
+        type: 'text',
+        virtual: true,
+        hooks: { beforeRead: [() => 'computed'] },
+      },
+    ],
+  }))
+}

test/profiling/config.ts

@@ -0,0 +1,17 @@
+import { buildConfigWithDefaults } from '../buildConfigWithDefaults.js'
+import { generateCollections } from './collections/index.js'
+
+export default buildConfigWithDefaults({
+  collections: [
+    ...generateCollections(30),
+    {
+      slug: 'users',
+      auth: true,
+      fields: [{ name: 'name', type: 'text' }],
+    },
+  ],
+  globals: Array.from({ length: 5 }, (_, i) => ({
+    slug: `global-${i}`,
+    fields: [{ name: 'title', type: 'text' }],
+  })),
+})

test/profiling/int.spec.ts

@@ -0,0 +1,41 @@
+import type { Payload } from 'payload'
+
+import path from 'path'
+import { performance } from 'perf_hooks'
+import { fileURLToPath } from 'url'
+import { afterAll, beforeAll, describe, expect } from 'vitest'
+
+import { it } from '../__helpers/int/vitest.js'
+import { initPayloadInt } from '../__helpers/shared/initPayloadInt.js'
+
+const filename = fileURLToPath(import.meta.url)
+const dirname = path.dirname(filename)
+
+let payload: Payload
+
+describe('sanitizeConfig profiling', () => {
+  beforeAll(() => {
+    process.env.PAYLOAD_DEBUG_TIMING = 'true'
+  })
+
+  afterAll(async () => {
+    if (payload) {
+      await payload.db.destroy()
+    }
+    delete process.env.PAYLOAD_DEBUG_TIMING
+  })
+
+  it('should profile sanitizeConfig and output timing breakdown', async () => {
+    const startTime = performance.now()
+
+    ;({ payload } = await initPayloadInt(dirname))
+
+    const totalTime = performance.now() - startTime
+
+    console.log(`\nTotal init time: ${totalTime.toFixed(2)}ms`)
+
+    // Verify payload initialized
+    expect(payload).toBeDefined()
+    expect(payload.collections['collection-0']).toBeDefined()
+  })
+})

test/profiling/payload-types.ts

@@ -0,0 +1,2 @@
+// Generated types placeholder
+export {}