Skip to content

Commit 5652bf9

Browse files
authored
fix(coverage): expose profiling timers (#7820)
1 parent b194263 commit 5652bf9

File tree

5 files changed

+92
-2
lines changed

5 files changed

+92
-2
lines changed

docs/guide/coverage.md

+4
Original file line numberDiff line numberDiff line change
@@ -215,6 +215,10 @@ if (condition) {
215215
216216
To see all configurable options for coverage, see the [coverage Config Reference](https://vitest.dev/config/#coverage).
217217
218+
## Coverage performance
219+
220+
If code coverage generation is slow on your project, see [Profiling Test Performance | Code coverage](/guide/profiling-test-performance.html#code-coverage).
221+
218222
## Vitest UI
219223
220224
You can check your coverage report in [Vitest UI](/guide/ui).

docs/guide/profiling-test-performance.md

+26
Original file line numberDiff line numberDiff line change
@@ -178,6 +178,32 @@ _x_examples_profiling_test_prime-number_test_ts-1413378098.js
178178
_src_prime-number_ts-525172412.js
179179
```
180180
181+
## Code coverage
182+
183+
If code coverage generation is slow on your project you can use `DEBUG=vitest:coverage` environment variable to enable performance logging.
184+
185+
```bash
186+
$ DEBUG=vitest:coverage vitest --run --coverage
187+
188+
RUN v3.1.1 /x/vitest-example
189+
190+
vitest:coverage Reading coverage results 2/2
191+
vitest:coverage Converting 1/2
192+
vitest:coverage 4 ms /x/src/multiply.ts
193+
vitest:coverage Converting 2/2
194+
vitest:coverage 552 ms /x/src/add.ts
195+
vitest:coverage Uncovered files 1/2
196+
vitest:coverage File "/x/src/large-file.ts" is taking longer than 3s # [!code error]
197+
vitest:coverage 3027 ms /x/src/large-file.ts
198+
vitest:coverage Uncovered files 2/2
199+
vitest:coverage 4 ms /x/src/untested-file.ts
200+
vitest:coverage Generate coverage total time 3521 ms
201+
```
202+
203+
This profiling approach is great for detecting large files that are accidentally picked by coverage providers.
204+
For example if your configuration is accidentally including large built minified Javascript files in code coverage, they should appear in logs.
205+
In these cases you might want to adjust your [`coverage.include`](/config/#coverage-include) and [`coverage.exclude`](/config/#coverage-exclude) options.
206+
181207
## Inspecting profiling records
182208
183209
You can inspect the contents of `*.cpuprofile` and `*.heapprofile` with various tools. See list below for examples.

packages/coverage-istanbul/src/provider.ts

+23-1
Original file line numberDiff line numberDiff line change
@@ -89,6 +89,8 @@ export class IstanbulCoverageProvider extends BaseCoverageProvider<ResolvedCover
8989
}
9090

9191
async generateCoverage({ allTestsRun }: ReportContext): Promise<CoverageMap> {
92+
const start = debug.enabled ? performance.now() : 0
93+
9294
const coverageMap = this.createCoverageMap()
9395
let coverageMapByTransformMode = this.createCoverageMap()
9496

@@ -120,6 +122,10 @@ export class IstanbulCoverageProvider extends BaseCoverageProvider<ResolvedCover
120122
coverageMap.filter(filename => this.testExclude.shouldInstrument(filename))
121123
}
122124

125+
if (debug.enabled) {
126+
debug('Generate coverage total time %d ms', (performance.now() - start!).toFixed())
127+
}
128+
123129
return coverageMap
124130
}
125131

@@ -182,12 +188,28 @@ export class IstanbulCoverageProvider extends BaseCoverageProvider<ResolvedCover
182188
// Note that these cannot be run parallel as synchronous instrumenter.lastFileCoverage
183189
// returns the coverage of the last transformed file
184190
for (const [index, filename] of uncoveredFiles.entries()) {
185-
debug('Uncovered file %s %d/%d', filename, index, uncoveredFiles.length)
191+
let timeout: ReturnType<typeof setTimeout> | undefined
192+
let start: number | undefined
193+
194+
if (debug.enabled) {
195+
start = performance.now()
196+
timeout = setTimeout(() => debug(c.bgRed(`File "${filename}" is taking longer than 3s`)), 3_000)
197+
198+
debug('Uncovered file %d/%d', index, uncoveredFiles.length)
199+
}
186200

187201
// Make sure file is not served from cache so that instrumenter loads up requested file coverage
188202
await transform(`${filename}?v=${cacheKey}`)
189203
const lastCoverage = this.instrumenter.lastFileCoverage()
190204
coverageMap.addFileCoverage(lastCoverage)
205+
206+
if (debug.enabled) {
207+
clearTimeout(timeout)
208+
209+
const diff = performance.now() - start!
210+
const color = diff > 500 ? c.bgRed : c.bgGreen
211+
debug(`${color(` ${diff.toFixed()} ms `)} ${filename}`)
212+
}
191213
}
192214

193215
return coverageMap

packages/coverage-v8/src/provider.ts

+38
Original file line numberDiff line numberDiff line change
@@ -65,6 +65,8 @@ export class V8CoverageProvider extends BaseCoverageProvider<ResolvedCoverageOpt
6565
}
6666

6767
async generateCoverage({ allTestsRun }: ReportContext): Promise<CoverageMap> {
68+
const start = debug.enabled ? performance.now() : 0
69+
6870
const coverageMap = this.createCoverageMap()
6971
let merged: RawCoverage = { result: [] }
7072

@@ -110,6 +112,10 @@ export class V8CoverageProvider extends BaseCoverageProvider<ResolvedCoverageOpt
110112
coverageMap.filter(filename => this.testExclude.shouldInstrument(filename))
111113
}
112114

115+
if (debug.enabled) {
116+
debug(`Generate coverage total time ${(performance.now() - start!).toFixed()} ms`)
117+
}
118+
113119
return coverageMap
114120
}
115121

@@ -189,6 +195,14 @@ export class V8CoverageProvider extends BaseCoverageProvider<ResolvedCoverageOpt
189195
}
190196

191197
await Promise.all(chunk.map(async (filename) => {
198+
let timeout: ReturnType<typeof setTimeout> | undefined
199+
let start: number | undefined
200+
201+
if (debug.enabled) {
202+
start = performance.now()
203+
timeout = setTimeout(() => debug(c.bgRed(`File "${filename.pathname}" is taking longer than 3s`)), 3_000)
204+
}
205+
192206
const sources = await this.getSources(
193207
filename.href,
194208
transformResults,
@@ -225,6 +239,14 @@ export class V8CoverageProvider extends BaseCoverageProvider<ResolvedCoverageOpt
225239
}
226240

227241
coverageMap.merge(converter.toIstanbul())
242+
243+
if (debug.enabled) {
244+
clearTimeout(timeout)
245+
246+
const diff = performance.now() - start!
247+
const color = diff > 500 ? c.bgRed : c.bgGreen
248+
debug(`${color(` ${diff.toFixed()} ms `)} ${filename.pathname}`)
249+
}
228250
}))
229251
}
230252

@@ -344,6 +366,14 @@ export class V8CoverageProvider extends BaseCoverageProvider<ResolvedCoverageOpt
344366

345367
await Promise.all(
346368
chunk.map(async ({ url, functions, startOffset }) => {
369+
let timeout: ReturnType<typeof setTimeout> | undefined
370+
let start: number | undefined
371+
372+
if (debug.enabled) {
373+
start = performance.now()
374+
timeout = setTimeout(() => debug(c.bgRed(`File "${fileURLToPath(url)}" is taking longer than 3s`)), 3_000)
375+
}
376+
347377
const sources = await this.getSources(
348378
url,
349379
transformResults,
@@ -368,6 +398,14 @@ export class V8CoverageProvider extends BaseCoverageProvider<ResolvedCoverageOpt
368398
}
369399

370400
coverageMap.merge(converter.toIstanbul())
401+
402+
if (debug.enabled) {
403+
clearTimeout(timeout)
404+
405+
const diff = performance.now() - start!
406+
const color = diff > 500 ? c.bgRed : c.bgGreen
407+
debug(`${color(` ${diff.toFixed()} ms `)} ${fileURLToPath(url)}`)
408+
}
371409
}),
372410
)
373411
}

packages/vitest/src/node/coverage.ts

+1-1
Original file line numberDiff line numberDiff line change
@@ -217,7 +217,7 @@ export class BaseCoverageProvider<Options extends ResolvedCoverageOptions<'istan
217217
for (const chunk of this.toSlices(filenames, this.options.processingConcurrency)) {
218218
if (onDebug.enabled) {
219219
index += chunk.length
220-
onDebug('Covered files %d/%d', index, total)
220+
onDebug(`Reading coverage results ${index}/${total}`)
221221
}
222222

223223
await Promise.all(chunk.map(async (filename) => {

0 commit comments

Comments
 (0)