Improve internal instrumentation module (#20119)
This PR improves some of the internal instrumentation tooling we have.
While working on another branch, I updated the instrumentation tooling
to have a few different ways of measuring what's going on.
Until now, we had an `I.start(label)` and corresponding `I.end(label)`.
While this works, it also means that you have to make sure that you call
`I.end(label)` before every `return` to track things properly.
With this PR, I added a `I.span(label, () => /* some callback*/{})` API
that essentially does that in one go. It also handles promises and
resturns the value that was returned from the callback. This can be
useful in situations where you have a one-liner:
```ts
let css = I.span('toCss(…)', () => toCss(ast))
```
If your callback is longer, then you end up in a situation where you
have to indent your code, and if you want to stop measuring you have to
drop code in 2 places and re-indent:
```diff
- I.span('label', () => {
…
- })
```
For this situation, I also added a `using _ = I.track(label)` API
instead. This can also be used in any block and automatically inserts
the `I.end(label)` on every exit point. This relies on the new `using`
keyword, but we already relied on that for the instrumentation module.
Last but not least, the constructor accepts a `shouldReport` which
defaults to the `env.DEBUG`. The reason for this change is so that it's
easier to report / not report during development instead of swapping out
an environment variable. Again, this is internal so there is no public
API change happening here.
## Test plan
All tests should still pass.
This commit is contained in:
parent
cdfae994ed
commit
2666194d5c
2 changed files with 139 additions and 2 deletions
|
|
@ -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
|
||||
}
|
||||
|
|
|
|||
|
|
@ -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<T>(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()
|
||||
}
|
||||
}
|
||||
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue