Improve debug logs #15303
+301
−77
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,61 @@ | ||
| import { stripVTControlCharacters } from 'util' | ||
| import { expect, it } from 'vitest' | ||
| import { Instrumentation } from './instrumentation' | ||
|
|
||
| it('should add instrumentation', () => { | ||
| let I = new Instrumentation() | ||
|
|
||
| I.start('Foo') | ||
| let x = 1 | ||
| for (let i = 0; i < 100; i++) { | ||
| I.start('Bar') | ||
| x **= 2 | ||
| I.end('Bar') | ||
| } | ||
| I.end('Foo') | ||
|
|
||
| I.hit('Potato') | ||
| I.hit('Potato') | ||
| I.hit('Potato') | ||
| I.hit('Potato') | ||
|
|
||
| expect.assertions(1) | ||
|
|
||
| I.report((output) => { | ||
| expect(stripVTControlCharacters(output).replace(/\[.*\]/g, '[0.xxms]')).toMatchInlineSnapshot(` | ||
| " | ||
| Hits: | ||
| Potato × 4 | ||
|
|
||
| Timers: | ||
| [0.xxms] Foo | ||
| [0.xxms] ↳ Bar × 100 | ||
| " | ||
| `) | ||
| }) | ||
| }) | ||
|
|
||
| it('should auto end pending timers when reporting', () => { | ||
| let I = new Instrumentation() | ||
|
|
||
| I.start('Foo') | ||
| let x = 1 | ||
| for (let i = 0; i < 100; i++) { | ||
| I.start('Bar') | ||
| x **= 2 | ||
| I.end('Bar') | ||
| } | ||
| I.start('Baz') | ||
|
|
||
| expect.assertions(1) | ||
|
|
||
| I.report((output) => { | ||
| expect(stripVTControlCharacters(output).replace(/\[.*\]/g, '[0.xxms]')).toMatchInlineSnapshot(` | ||
| " | ||
| [0.xxms] Foo | ||
| [0.xxms] ↳ Bar × 100 | ||
| [0.xxms] ↳ Baz | ||
| " | ||
| `) | ||
| }) | ||
| }) |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,105 @@ | ||
| import { DefaultMap } from '../../tailwindcss/src/utils/default-map' | ||
| import * as env from './env' | ||
|
|
||
| export class Instrumentation implements Disposable { | ||
| #hits = new DefaultMap(() => ({ value: 0 })) | ||
| #timers = new DefaultMap(() => ({ value: 0n })) | ||
| #timerStack: { id: string; label: string; namespace: string; value: bigint }[] = [] | ||
|
|
||
| constructor(private defaultFlush = (message: string) => process.stderr.write(`${message}\n`)) {} | ||
|
|
||
| hit(label: string) { | ||
| this.#hits.get(label).value++ | ||
| } | ||
|
|
||
| start(label: string) { | ||
| let namespace = this.#timerStack.map((t) => t.label).join('//') | ||
| let id = `${namespace}${namespace.length === 0 ? '' : '//'}${label}` | ||
|
|
||
| this.#hits.get(id).value++ | ||
|
|
||
| // Create the timer if it doesn't exist yet | ||
| this.#timers.get(id) | ||
|
|
||
| this.#timerStack.push({ id, label, namespace, value: process.hrtime.bigint() }) | ||
| } | ||
|
|
||
| end(label: string) { | ||
| let end = process.hrtime.bigint() | ||
|
|
||
| if (this.#timerStack[this.#timerStack.length - 1].label !== label) { | ||
| throw new Error( | ||
| `Mismatched timer label: \`${label}\`, expected \`${ | ||
| this.#timerStack[this.#timerStack.length - 1].label | ||
| }\``, | ||
| ) | ||
| } | ||
|
|
||
| let parent = this.#timerStack.pop()! | ||
| let elapsed = end - parent.value | ||
| this.#timers.get(parent.id).value += elapsed | ||
| } | ||
|
|
||
| reset() { | ||
| this.#hits.clear() | ||
| this.#timers.clear() | ||
| this.#timerStack.splice(0) | ||
| } | ||
|
|
||
| report(flush = this.defaultFlush) { | ||
| let output: string[] = [] | ||
| let hasHits = false | ||
|
|
||
| // Auto end any pending timers | ||
| for (let i = this.#timerStack.length - 1; i >= 0; i--) { | ||
| this.end(this.#timerStack[i].label) | ||
| } | ||
|
|
||
| for (let [label, { value: count }] of this.#hits.entries()) { | ||
| if (this.#timers.has(label)) continue | ||
| if (output.length === 0) { | ||
| hasHits = true | ||
| output.push('Hits:') | ||
| } | ||
|
|
||
| let depth = label.split('//').length | ||
| output.push(`${' '.repeat(depth)}${label} ${dim(blue(`× ${count}`))}`) | ||
| } | ||
|
|
||
| if (this.#timers.size > 0 && hasHits) { | ||
| output.push('\nTimers:') | ||
| } | ||
|
|
||
| let max = -Infinity | ||
| let computed = new Map<string, string>() | ||
| for (let [label, { value }] of this.#timers) { | ||
| let x = `${(Number(value) / 1e6).toFixed(2)}ms` | ||
| computed.set(label, x) | ||
| max = Math.max(max, x.length) | ||
| } | ||
|
|
||
| for (let label of this.#timers.keys()) { | ||
| let depth = label.split('//').length | ||
| output.push( | ||
| `${dim(`[${computed.get(label)!.padStart(max, ' ')}]`)}${' '.repeat(depth - 1)}${depth === 1 ? ' ' : dim(' ↳ ')}${label.split('//').pop()} ${ | ||
| this.#hits.get(label).value === 1 ? '' : dim(blue(`× ${this.#hits.get(label).value}`)) | ||
| }`.trimEnd(), | ||
| ) | ||
| } | ||
|
|
||
| flush(`\n${output.join('\n')}\n`) | ||
| this.reset() | ||
| } | ||
|
|
||
| [Symbol.dispose]() { | ||
| env.DEBUG && this.report() | ||
| } | ||
| } | ||
|
|
||
| function dim(input: string) { | ||
| return `\u001b[2m${input}\u001b[22m` | ||
| } | ||
|
|
||
| function blue(input: string) { | ||
| return `\u001b[34m${input}\u001b[39m` | ||
| } |
Oops, something went wrong.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
When using
DEBUG=1it also shows a lot of oxide related tracing logs. This change only shows them if you are usingDEBUG=*orDEBUG=tailwindcss:oxideby following theDEBUGconventions.