diff --git a/packages/payload/src/utilities/profiling.ts b/packages/payload/src/utilities/profiling.ts new file mode 100644 index 00000000000..3b0b33ea8a2 --- /dev/null +++ b/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(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(name: string, fn: () => Promise): Promise { + 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() + + 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() +} diff --git a/test/profiling/collections/index.ts b/test/profiling/collections/index.ts new file mode 100644 index 00000000000..dcda2254746 --- /dev/null +++ b/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'] }, + }, + ], + })) +} diff --git a/test/profiling/config.ts b/test/profiling/config.ts new file mode 100644 index 00000000000..a05dbd055fa --- /dev/null +++ b/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' }], + })), +}) diff --git a/test/profiling/int.spec.ts b/test/profiling/int.spec.ts new file mode 100644 index 00000000000..78ff1b4676a --- /dev/null +++ b/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() + }) +}) diff --git a/test/profiling/payload-types.ts b/test/profiling/payload-types.ts new file mode 100644 index 00000000000..2e169443167 --- /dev/null +++ b/test/profiling/payload-types.ts @@ -0,0 +1,2 @@ +// Generated types placeholder +export {}