diff --git a/packages/@tailwindcss-node/src/instrumentation.test.ts b/packages/@tailwindcss-node/src/instrumentation.test.ts index 1f06796fd..f6ae55741 100644 --- a/packages/@tailwindcss-node/src/instrumentation.test.ts +++ b/packages/@tailwindcss-node/src/instrumentation.test.ts @@ -1,8 +1,9 @@ import { stripVTControlCharacters } from 'util' import { expect, it } from 'vitest' +import { dimensions } from '../../tailwindcss/src/utils/dimensions' import { Instrumentation } from './instrumentation' -it('should add instrumentation', () => { +it('should add instrumentation using start/end markers', () => { let I = new Instrumentation() I.start('Foo') @@ -35,6 +36,80 @@ it('should add instrumentation', () => { }) }) +it('should measure callbacks via the `span` api', () => { + let I = new Instrumentation() + + I.span('Foo', () => { + let x = 1 + for (let i = 0; i < 100; i++) { + I.span('Bar', () => { + x **= 2 + }) + } + }) + + expect.assertions(1) + + I.report((output) => { + expect(stripVTControlCharacters(output).replace(/\[.*\]/g, '[0.xxms]')).toMatchInlineSnapshot(` + " + [0.xxms] Foo + [0.xxms] ↳ Bar × 100 + " + `) + }) +}) + +it('should measure async callbacks via the `span` api', async () => { + let I = new Instrumentation() + + await I.span('Foo', async () => { + let x = 1 + for (let i = 0; i < 100; i++) { + I.span('Bar', () => { + x **= 2 + }) + } + await new Promise((r) => setTimeout(r, 500)) + }) + + expect.assertions(1) + + I.report((output) => { + expect(stabilize(output)).toMatchInlineSnapshot(` + " + [510.00ms] Foo + [ 0.05ms] ↳ Bar × 100 + " + `) + }) +}) + +it('should measure blocks until they go out of scope via `using`', () => { + let I = new Instrumentation() + + { + using _ = I.track('Foo') + + let x = 1 + for (let i = 0; i < 100; i++) { + using _ = I.track('Bar') + x **= 2 + } + } + + expect.assertions(1) + + I.report((output) => { + expect(stripVTControlCharacters(output).replace(/\[.*\]/g, '[0.xxms]')).toMatchInlineSnapshot(` + " + [0.xxms] Foo + [0.xxms] ↳ Bar × 100 + " + `) + }) +}) + it('should auto end pending timers when reporting', () => { let I = new Instrumentation() @@ -59,3 +134,29 @@ it('should auto end pending timers when reporting', () => { `) }) }) + +let nf = new Intl.NumberFormat(undefined, { + style: 'decimal', + minimumFractionDigits: 2, +}) + +function stabilize(output: string) { + return stripVTControlCharacters(output).replace(/\[(\s*)(.*)\]/g, (_, whitespace, duration) => { + let [value, unit] = dimensions.get(duration.trim())! + return `[${whitespace}${nf.format(stableRound(value))}${unit}]` + }) +} + +function stableRound(value: number) { + if (value === 0) return 0 + + let sign = Math.sign(value) + let abs = Math.abs(value) + + let magnitude = 10 ** Math.floor(Math.log10(abs)) + + let step = magnitude / 10 + if (abs < 0.1) step = 0.05 + + return sign * Math.ceil(abs / step) * step +} diff --git a/packages/@tailwindcss-node/src/instrumentation.ts b/packages/@tailwindcss-node/src/instrumentation.ts index d27858d88..e454e6744 100644 --- a/packages/@tailwindcss-node/src/instrumentation.ts +++ b/packages/@tailwindcss-node/src/instrumentation.ts @@ -13,6 +13,7 @@ export class Instrumentation implements Disposable { #timerStack: { id: string; label: string; namespace: string; value: bigint }[] = [] constructor( + private shouldReport = env.DEBUG, private defaultFlush = (message: string) => void process.stderr.write(`${message}\n`), ) {} @@ -48,6 +49,41 @@ export class Instrumentation implements Disposable { this.#timers.get(parent.id).value += elapsed } + track(label: string) { + this.start(label) + let done = false + + return { + [Symbol.dispose]: () => { + if (!done) { + this.end(label) + done = true + } + }, + [Symbol.asyncDispose]: () => { + if (!done) { + this.end(label) + done = true + } + }, + } + } + + span(label: string, fn: () => T): T { + this.start(label) + let isPromise = false + try { + let result = fn() + + isPromise = result && typeof (result as any).then === 'function' + + // @ts-expect-error — TS can't infer that result is a Promise here + return isPromise ? result.finally(() => this.end(label)) : result + } finally { + if (!isPromise) this.end(label) + } + } + reset() { this.#hits.clear() this.#timers.clear() @@ -100,7 +136,7 @@ export class Instrumentation implements Disposable { } [Symbol.dispose]() { - env.DEBUG && this.report() + this.shouldReport && this.report() } }