fix(coverage): expose profiling timers

docs/guide/coverage.md

@@ -215,6 +215,10 @@ if (condition) {
 
 To see all configurable options for coverage, see the [coverage Config Reference](https://vitest.dev/config/#coverage).
 
+## Coverage performance
+
+If code coverage generation is slow on your project, see [Profiling Test Performance | Code coverage](/guide/profiling-test-performance.html#code-coverage).
+
 ## Vitest UI
 
 You can check your coverage report in [Vitest UI](/guide/ui).

docs/guide/profiling-test-performance.md

@@ -178,6 +178,32 @@ _x_examples_profiling_test_prime-number_test_ts-1413378098.js
 _src_prime-number_ts-525172412.js
 ```
 
+## Code coverage
+
+If code coverage generation is slow on your project you can use `DEBUG=vitest:coverage` environment variable to enable performance logging.
+
+```bash
+$ DEBUG=vitest:coverage vitest --run --coverage
+
+ RUN  v3.1.1 /x/vitest-example
+
+  vitest:coverage Reading coverage results 2/2
+  vitest:coverage Converting 1/2
+  vitest:coverage 4 ms /x/src/multiply.ts
+  vitest:coverage Converting 2/2
+  vitest:coverage 552 ms /x/src/add.ts
+  vitest:coverage Uncovered files 1/2
+  vitest:coverage File "/x/src/large-file.ts" is taking longer than 3s # [!code error]
+  vitest:coverage 3027 ms /x/src/large-file.ts
+  vitest:coverage Uncovered files 2/2
+  vitest:coverage 4 ms /x/src/untested-file.ts
+  vitest:coverage Generate coverage total time 3521 ms
+```
+
+This profiling approach is great for detecting large files that are accidentally picked by coverage providers.
+For example if your configuration is accidentally including large built minified Javascript files in code coverage, they should appear in logs.
+In these cases you might want to adjust your [`coverage.include`](/config/#coverage-include) and [`coverage.exclude`](/config/#coverage-exclude) options.
+
 ## Inspecting profiling records
 
 You can inspect the contents of `*.cpuprofile` and `*.heapprofile` with various tools. See list below for examples.

packages/coverage-istanbul/src/provider.ts

@@ -89,6 +89,8 @@ export class IstanbulCoverageProvider extends BaseCoverageProvider<ResolvedCover
   }
 
   async generateCoverage({ allTestsRun }: ReportContext): Promise<CoverageMap> {
+    const start = debug.enabled ? performance.now() : 0
+
     const coverageMap = this.createCoverageMap()
     let coverageMapByTransformMode = this.createCoverageMap()
 
@@ -120,6 +122,10 @@ export class IstanbulCoverageProvider extends BaseCoverageProvider<ResolvedCover
       coverageMap.filter(filename => this.testExclude.shouldInstrument(filename))
     }
 
+    if (debug.enabled) {
+      debug('Generate coverage total time %d ms', (performance.now() - start!).toFixed())
+    }
+
     return coverageMap
   }
 
@@ -182,12 +188,28 @@ export class IstanbulCoverageProvider extends BaseCoverageProvider<ResolvedCover
     // Note that these cannot be run parallel as synchronous instrumenter.lastFileCoverage
     // returns the coverage of the last transformed file
     for (const [index, filename] of uncoveredFiles.entries()) {
-      debug('Uncovered file %s %d/%d', filename, index, uncoveredFiles.length)
+      let timeout: ReturnType<typeof setTimeout> | undefined
+      let start: number | undefined
+
+      if (debug.enabled) {
+        start = performance.now()
+        timeout = setTimeout(() => debug(c.bgRed(`File "${filename}" is taking longer than 3s`)), 3_000)
+
+        debug('Uncovered file %d/%d', index, uncoveredFiles.length)
+      }
 
       // Make sure file is not served from cache so that instrumenter loads up requested file coverage
       await transform(`${filename}?v=${cacheKey}`)
       const lastCoverage = this.instrumenter.lastFileCoverage()
       coverageMap.addFileCoverage(lastCoverage)
+
+      if (debug.enabled) {
+        clearTimeout(timeout)
+
+        const diff = performance.now() - start!
+        const color = diff > 500 ? c.bgRed : c.bgGreen
+        debug(`${color(` ${diff.toFixed()} ms `)} ${filename}`)
+      }
     }
 
     return coverageMap

packages/coverage-v8/src/provider.ts

@@ -65,6 +65,8 @@ export class V8CoverageProvider extends BaseCoverageProvider<ResolvedCoverageOpt
   }
 
   async generateCoverage({ allTestsRun }: ReportContext): Promise<CoverageMap> {
+    const start = debug.enabled ? performance.now() : 0
+
     const coverageMap = this.createCoverageMap()
     let merged: RawCoverage = { result: [] }
 
@@ -110,6 +112,10 @@ export class V8CoverageProvider extends BaseCoverageProvider<ResolvedCoverageOpt
       coverageMap.filter(filename => this.testExclude.shouldInstrument(filename))
     }
 
+    if (debug.enabled) {
+      debug(`Generate coverage total time ${(performance.now() - start!).toFixed()} ms`)
+    }
+
     return coverageMap
   }
 
@@ -189,6 +195,14 @@ export class V8CoverageProvider extends BaseCoverageProvider<ResolvedCoverageOpt
       }
 
       await Promise.all(chunk.map(async (filename) => {
+        let timeout: ReturnType<typeof setTimeout> | undefined
+        let start: number | undefined
+
+        if (debug.enabled) {
+          start = performance.now()
+          timeout = setTimeout(() => debug(c.bgRed(`File "${filename.pathname}" is taking longer than 3s`)), 3_000)
+        }
+
         const sources = await this.getSources(
           filename.href,
           transformResults,
@@ -225,6 +239,14 @@ export class V8CoverageProvider extends BaseCoverageProvider<ResolvedCoverageOpt
         }
 
         coverageMap.merge(converter.toIstanbul())
+
+        if (debug.enabled) {
+          clearTimeout(timeout)
+
+          const diff = performance.now() - start!
+          const color = diff > 500 ? c.bgRed : c.bgGreen
+          debug(`${color(` ${diff.toFixed()} ms `)} ${filename.pathname}`)
+        }
       }))
     }
 
@@ -344,6 +366,14 @@ export class V8CoverageProvider extends BaseCoverageProvider<ResolvedCoverageOpt
 
       await Promise.all(
         chunk.map(async ({ url, functions, startOffset }) => {
+          let timeout: ReturnType<typeof setTimeout> | undefined
+          let start: number | undefined
+
+          if (debug.enabled) {
+            start = performance.now()
+            timeout = setTimeout(() => debug(c.bgRed(`File "${fileURLToPath(url)}" is taking longer than 3s`)), 3_000)
+          }
+
           const sources = await this.getSources(
             url,
             transformResults,
@@ -368,6 +398,14 @@ export class V8CoverageProvider extends BaseCoverageProvider<ResolvedCoverageOpt
           }
 
           coverageMap.merge(converter.toIstanbul())
+
+          if (debug.enabled) {
+            clearTimeout(timeout)
+
+            const diff = performance.now() - start!
+            const color = diff > 500 ? c.bgRed : c.bgGreen
+            debug(`${color(` ${diff.toFixed()} ms `)} ${fileURLToPath(url)}`)
+          }
         }),
       )
     }

packages/vitest/src/node/coverage.ts

@@ -217,7 +217,7 @@ export class BaseCoverageProvider<Options extends ResolvedCoverageOptions<'istan
         for (const chunk of this.toSlices(filenames, this.options.processingConcurrency)) {
           if (onDebug.enabled) {
             index += chunk.length
-            onDebug('Covered files %d/%d', index, total)
+            onDebug(`Reading coverage results ${index}/${total}`)
           }
 
           await Promise.all(chunk.map(async (filename) => {