From 0e315ffb50be7aab8bfb81a5c7896bc978a8a3ad Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ari=20Perkki=C3=B6?= Date: Tue, 12 Nov 2024 09:57:43 +0200 Subject: [PATCH] feat: `verbose` reporter to show slow in-progress tests --- docs/guide/reporters.md | 20 ++++- packages/vitest/src/node/reporters/default.ts | 2 +- packages/vitest/src/node/reporters/summary.ts | 84 +++++++++++++++++-- 3 files changed, 97 insertions(+), 9 deletions(-) diff --git a/docs/guide/reporters.md b/docs/guide/reporters.md index e960e2363dea9..0fef317566407 100644 --- a/docs/guide/reporters.md +++ b/docs/guide/reporters.md @@ -172,7 +172,7 @@ Example output using basic reporter: ### Verbose Reporter -Verbose reporter is same as `default` reporter, but it also displays each individual test after the suite has finished. Similar to `default` reporter, you can disable the summary by configuring the reporter. +Verbose reporter is same as `default` reporter, but it also displays each individual test after the suite has finished. It also displays currently running tests that are taking longer than [`slowTestThreshold`](/config/#slowtestthreshold). Similar to `default` reporter, you can disable the summary by configuring the reporter. :::code-group ```bash [CLI] @@ -190,6 +190,24 @@ export default defineConfig({ ``` ::: +Example output for tests in progress with default `slowTestThreshold: 300`: + +```bash + ✓ __tests__/example-1.test.ts (2) 725ms + ✓ first test file (2) 725ms + ✓ 2 + 2 should equal 4 + ✓ 4 - 2 should equal 2 + + ❯ test/example-2.test.ts 3/5 + ↳ should run longer than three seconds 1.57s + ❯ test/example-3.test.ts 1/5 + + Test Files 2 passed (4) + Tests 10 passed | 3 skipped (65) + Start at 11:01:36 + Duration 2.00s +``` + Example of final terminal output for a passing test suite: ```bash diff --git a/packages/vitest/src/node/reporters/default.ts b/packages/vitest/src/node/reporters/default.ts index f147bdeafcf83..5ac02191fcab1 100644 --- a/packages/vitest/src/node/reporters/default.ts +++ b/packages/vitest/src/node/reporters/default.ts @@ -30,7 +30,7 @@ export class DefaultReporter extends BaseReporter { onInit(ctx: Vitest) { super.onInit(ctx) - this.summary?.onInit(ctx) + this.summary?.onInit(ctx, { verbose: this.verbose }) } onPathsCollected(paths: string[] = []) { diff --git a/packages/vitest/src/node/reporters/summary.ts b/packages/vitest/src/node/reporters/summary.ts index a2f7d5968c157..66efa75687621 100644 --- a/packages/vitest/src/node/reporters/summary.ts +++ b/packages/vitest/src/node/reporters/summary.ts @@ -3,13 +3,17 @@ import type { Vitest } from '../core' import type { Reporter } from '../types/reporter' import { getTests } from '@vitest/runner/utils' import c from 'tinyrainbow' -import { F_POINTER } from './renderers/figures' +import { F_DOWN_RIGHT, F_POINTER } from './renderers/figures' import { formatProjectName, formatTime, formatTimeString, padSummaryTitle } from './renderers/utils' import { WindowRenderer } from './renderers/windowedRenderer' -const DURATION_UPDATE_INTERVAL_MS = 500 +const DURATION_UPDATE_INTERVAL_MS = 100 const FINISHED_TEST_CLEANUP_TIME_MS = 1_000 +interface Options { + verbose?: boolean +} + interface Counter { total: number completed: number @@ -22,6 +26,11 @@ interface Counter { interface RunningTest extends Pick { filename: File['name'] projectName: File['projectName'] + slowTest?: { + name?: string + startTime: number + timeout: NodeJS.Timeout + } } /** @@ -30,6 +39,7 @@ interface RunningTest extends Pick { */ export class SummaryReporter implements Reporter { private ctx!: Vitest + private options!: Options private renderer!: WindowRenderer private suites = emptyCounters() @@ -46,12 +56,18 @@ export class SummaryReporter implements Reporter { private allFinishedTests = new Set() private startTime = '' + private currentTime = 0 private duration = 0 private durationInterval: NodeJS.Timeout | undefined = undefined - onInit(ctx: Vitest) { + onInit(ctx: Vitest, options: Options = {}) { this.ctx = ctx + this.options = { + verbose: false, + ...options, + } + this.renderer = new WindowRenderer({ logger: ctx.logger, getWindow: () => this.createSummary(), @@ -88,7 +104,10 @@ export class SummaryReporter implements Reporter { } if (task?.type === 'test' || task?.type === 'custom') { - if (task.result?.state !== 'run') { + if (task.result?.state === 'run') { + this.onTestStart(task) + } + else { this.onTestFinished(task) } } @@ -129,6 +148,9 @@ export class SummaryReporter implements Reporter { if (finished) { clearTimeout(finished[1]) this.finishedTests.delete(finished[0]) + + const slowTest = this.runningTests.get(finished[0])?.slowTest + clearTimeout(slowTest?.timeout) this.runningTests.delete(finished[0]) } } @@ -143,7 +165,7 @@ export class SummaryReporter implements Reporter { this.maxParallelTests = Math.max(this.maxParallelTests, this.runningTests.size) } - private onTestFinished(test: Test | Custom) { + private getTestStats(test: Test | Custom) { const file = test.file let stats = this.runningTests.get(file.id) @@ -158,6 +180,43 @@ export class SummaryReporter implements Reporter { } } + return stats + } + + private onTestStart(test: Test | Custom) { + // Track slow running tests only on verbose mode + if (!this.options.verbose) { + return + } + + const stats = this.getTestStats(test) + + if (!stats) { + return + } + + const slowTest: NonNullable = { + name: undefined, + startTime: performance.now(), + timeout: setTimeout(() => { + slowTest.name = test.name + }, this.ctx.config.slowTestThreshold).unref(), + } + + clearTimeout(stats.slowTest?.timeout) + stats.slowTest = slowTest + } + + private onTestFinished(test: Test | Custom) { + const file = test.file + const stats = this.getTestStats(test) + + if (!stats) { + return + } + + clearTimeout(stats.slowTest?.timeout) + stats.slowTest = undefined stats.completed++ const result = test.result @@ -225,6 +284,16 @@ export class SummaryReporter implements Reporter { + test.filename + c.dim(` ${test.completed}/${test.total}`), ) + + if (test.slowTest?.name) { + const elapsed = this.currentTime - test.slowTest.startTime + + summary.push( + c.bold(c.yellow(` ${F_DOWN_RIGHT} `)) + + test.slowTest.name + + c.bold(c.yellow(` ${formatTime(Math.max(0, elapsed))}`)), + ) + } } if (this.runningTests.size > 0) { @@ -246,8 +315,9 @@ export class SummaryReporter implements Reporter { this.startTime = formatTimeString(new Date()) this.durationInterval = setInterval(() => { - this.duration = performance.now() - start - }, DURATION_UPDATE_INTERVAL_MS) + this.currentTime = performance.now() + this.duration = this.currentTime - start + }, DURATION_UPDATE_INTERVAL_MS).unref() } }