Ability to report on `collect` time

[abrenneke]

Clear and concise description of the problem

In our large monorepo, the collect time is by far the largest. It would be nice if there were a reporter that would show how long was spent on collect in a more granular manner, such as every file Vitest has processed.

Suggested solution

vitest run --reporter=collect-time could report every imported file with the total time spent importing it.

Alternative

Vitest UI could show this as well?

Additional context

No response

Validations

• [x] Follow our Code of Conduct
• [x] Read the Contributing Guidelines.
• [x] Read the docs.
• [x] Check that there isn't already an issue that request the same feature to avoid creating a duplicate.

[AriPerkkio]

Collecting time of every file that was loaded sounds a bit extreme. Currently Vitest tracks only the time the whole test file took to load. Using custom reporter you can see test file specific times:

// vitest.config.ts
import { defineConfig } from "vitest/config";

export default defineConfig({
  test: {
    reporters: ["default", "./collection-reporter.ts"],
  },
});

// collection-reporter.ts
import { type Reporter } from "vitest/reporters";

export default class CollectionReporter implements Reporter {
  onTestRunEnd(testModules: Parameters<Reporter["onTestRunEnd"]>[0]) {
    for (const testModule of testModules) {
      console.log(
        `${testModule.moduleId} took ${
          testModule.diagnostic().collectDuration
        } ms to collect`
      );
    }
  }
}

[abrenneke]

Well, it's already transforming every file loaded, so tracking how long each import took is a very very small amount of time, proportionally @AriPerkkio. I'm not looking for test file times, but why collect is so large.

[FredrikAugust]

Hi, just wanted to add that, as another maintainer of a relatively large monorepo, this would be extremely useful. We're currently experiencing the same, where collect is order of magnitudes slower than the actual tests, mostly because barrel files were used earlier and they nuke performance 😅

[abrenneke]

Now that #8027 is merged 🎉 let's talk about how we'd like to integrate it with reporters @sheremet-va @hi-ogawa @AriPerkkio

Our options seem to be:

1. Separate reporter like I did initially (probably not great)
2. Additive reporter, so that you just add it to your reporters list and get extra information
3. Integrate with existing default reporter like https://github.com/vitest-dev/vitest/pull/8027#issuecomment-2909949959

Could also do both 2 and 3?

Open questions for 3 are:

• How do we know how many files to show?
• What should be the threshold for showing files? It feels like this highly depends on the project, so should be configurable. But a good default is really important. Spitballing... >500ms total time / >100ms self time perhaps?
• It should probably be self-time mostly, but should we also report slow total times?
• verbose mode - printing a list of every imported file after every test is extreme I think, there could be hundreds of files imported per test file. If not, what should verbose print? > slowThreshold files after each test?
• Is this data useful for all projects? It's not super useful for Vitest itself it seems since it doesn't have major slow dependencies. I'd be worried about unilaterally introducing it for the default reporter for all projects, but that's your maintainers' calls.

[sheremet-va]

• How do we know how many files to show?

I expected there to be an option like slowTestThreshold, and then show everything that is above that treashold.

I think maybe by default we can print a warning like "Vitest found <n> of files that took longer than <ms> during collection.". In watch mode we add "Press <button> to show the list of them" and in run mode we can say "To print the list of files, enable the <name> config option".

• verbose mode - printing a list of every imported file after every test is extreme I think, there could be hundreds of files imported per test file. If not, what should verbose print? > slowThreshold files after each test?

I don't think we should print every file, it should respect the config treashold.

Another thing that might be interesting is incorporating this in UI, but that's a big task.

[AriPerkkio]

I expected there to be an option like slowTestThreshold, and then show everything that is above that treashold.

Maybe slowCollectThreshold? This reporting feature is still about just collect phase, not about test running phase, right?

I think maybe by default we can print a warning like "Vitest found <n> of files that took longer than <ms> during collection.".

And it should be possible to disable the feature by providing value of 0 in the config.

In watch mode we add "Press <button> to show the list of them" and in run mode we can say "To print the list of files, enable the <name> config option".

Sounds perfect. This should also be mentioned on https://vitest.dev/guide/profiling-test-performance.html guides.

[kirillgroshkov]

Is there more progress on this? Can I help somehow? I'm very interested in debugging "collect time performance" for our projects, and currently writing a lot of my own debugging scripts. But sounds like this issue is ahead of me, and maybe needs some last pushes to be useful? 🙏

[hi-ogawa]

@kirillgroshkov The stats is available in reporter API. The primitive example is found here https://github.com/vitest-dev/vitest/pull/8027#discussion_r2110688260 https://stackblitz.com/edit/vitest-dev-vitest-335d17yc?file=vite.config.ts

[sheremet-va]

You can also use OpenTelemetry traces to see how long it takes to load modules. They are called vitest.module.inline and vitest.module.external.