feat: hide optimized deps found during scan phase logs

[patak-dev]

Description

As part of #7379, we modified the logs to make them more concise now that the user will generally not notice the extra time to scan and pre-bundle during cold start.

It now looks like this:

The logs can still be a bit noisy for projects like StoryBook, Cypress, Ladle, etc where there are a lot of newly discovered deps as the use explores the app:

IMO the only important log here is the last one. Since there is a page reload, we need to communicate to the user why we are doing so. But the rest of the logs feel more like implementation details to me. It isn't that useful for the user to know when a dependency has been pre-bundled if there is not a big noticeable delay in server start or during a rerun.

This PR hides these logs, and only shows them when debugging or when using --force. I think that having them when using force is a good idea since the user is focused on re-bundling the dependencies so it is good feedback in that case.

---

What is the purpose of this pull request?

• Bug fix
• New Feature
• Documentation update
• Other

[benmccann]

I agree with moving the logging behind debug flag. My one question about adding logging with --force is then if logs show up will people think something is happening only when they use --force since they don't see the logs without it?

[bluwy]

I feel like we should still keep the logs, so that the user knows which imports triggered the on-the-fly bundling. And I think frameworks or end-users should try to keep on-the-fly bundling to the lowest too (ideally bundles once on startup), so having these kind of verbose logs could signal them to improve their setup, though I'm not sure why Ladle is behaving that way currently that causes the multi bundling.

[patak-dev]

I agree with moving the logging behind debug flag. My one question about adding logging with --force is then if logs show up will people think something is happening only when they use --force since they don't see the logs without it?

This is a good point. We should give some feedback when using force though. So maybe we should only log the first optimized deps batch with a message like:

12:18:24 AM [vite] ✨ forced drop of optimized dependencies cache
12:18:24 AM [vite] ✨ dependencies optimized: vue, pinia, luxon

But the rest of on-the-fly messages should probably also appear... because they also are there because you used --force. So my vote would go to add the new message and then show all of them. Or only show the new "forced drop" message and nothing more.

I feel like we should still keep the logs, so that the user knows which imports triggered the on-the-fly bundling. And I think frameworks or end-users should try to keep on-the-fly bundling to the lowest too (ideally bundles once on startup), so having these kind of verbose logs could signal them to improve their setup, though I'm not sure why Ladle is behaving that way currently that causes the multi bundling.

Ladle and similar projects have so many on-the-fly bundling because they don't scan the whole app upfront IIUC. Each time you click on a story, new dependencies are discovered. Maybe they should change this. But now that on-the-fly bundling isn't blocking, it may not be an anti-pattern anymore... the only issue is when these dependencies generate a page reload (and it is only the first time). We are showing a message in this case, and we could show something like:

12:18:24 AM [vite] ✨ previous optimized dependencies changed, reloading page
12:18:24 AM [vite] ✨ this reload could be avoided by adding to `optimizeDeps.include` some of the following dependencies: a, b, c, d

Without a message like this, even if we show the deps logs, the user will not know how to fix it. IMO, if they see previous optimized dependencies changed, reloading page they are going to google that and get to our docs where we could guide them in a new section.

Maybe just this:

12:18:24 AM [vite] ✨ newly discovered dependencies forced a page reload (consider using `optimizeDeps.include`)

My vote still goes to hide the logs in the general case, but I see the value on bumping the user to avoid unneeded page reloads.

[benmccann]

Why can't dependencies be discovered via dependency scanning when using Ladle? Do they manually disable Vite's dependency scanning? Adding dependencies manually to optimizeDeps.include is a bit burdensome and I'm not sure I'd recommend that instead of changing the way the app is written (assuming that's possible)

[patak-dev]

Maybe @tajo could explain a bit more why these dependencies are discovered late. Maybe ladle could add the proper entries to optimizeDeps.entries if they want to have more things optimized upfront. Looks like a more general problem in this kind of apps though (ping @IanVS, @JessicaSachs).

I would still move forward with hiding as much of the deps logs as possible, and only show them when there is a reload (maybe with extra information about how to improve things, but looks quite hard to log something concise...).

[IanVS]

Yes, the storybook vite builder does attempt to use optimizeDeps.entries based on the user's stories config, which has helped a lot after we added that feature. However, the way storybook works, there are a few packages which are not directly imported by the user's code, for example framework packages like @storybook/react or @storybook/vue. They are used by the storybook cli, but not imported in the user's code directly. More irritatingly, sub-dependencies of these packages also need to be included in optimizeDeps.include.. @bluwy was helping me troubleshoot this in discord, but I haven't yet gotten to the bottom of why it's happening.

[bluwy]

I think even if we report using optimizeDeps.include, it could bring false positives for cases where the users imports new deps while the server is running. So it's a hard one to tackle.

Ultimately, if we could prevent multiple on-the-fly bundling by encouraging proper initial bundling, that would help the end-user for faster web page TTI and reduced repeated esbuild bundling, which is an overall plus. Hiding the logs would also hide this potential optimization IMO, unless we can provide correct recommendation in the logs)

[patak-dev]

For the record, looks like vite-plugin-autoimport also ends up generating these late discovered deps: unplugin/unplugin-auto-import#124

@bluwy would you be ok if we remove the log for the first batch scanned deps and only log late discovered deps with a message like:

12:18:24 AM [vite] ✨ late discovered dependencies optimized: vue, pinia, luxon

And if a page reload

12:18:24 AM [vite] ✨ late discovered dependencies optimized: vue, pinia, luxon
12:18:24 AM [vite] ✨ previously optimized dependencies changed, a page reload is required

So at least we don't have logs if every deps is discovered by the scan phase?

I still think that it may be quite hard for the user to understand what is going on, but this would work for me

[bluwy]

Yep that sounds fine by me 👍 I dont usually find the initial scanned deps to be important too.

[tajo]

I think it's fine to hide most of these logs as long as it can be enabled for debugging.

Maybe @tajo could explain a bit more why these dependencies are discovered late.

It's because stories are loaded as

const Story = React.lazy(() => import('./foo.stories.js'));

So the dependencies inside of foo.stories.js are not discovered initially, right?

I tried to add all stories into optimizeDeps.entries to force all deps being pre-bundled upfront but it wasn't quite working, it still did some late discoveries. (I could try to create a repro for that and test it again with 2.9)

Ideally, it would be nice to eliminate any reloads since it's not a great experience while keeping the startup instant no matter how many stories and dependencies there are. Maybe with 2.9, it's actually ok to put everything into include/entries. Otherwise, there could be an option like optimizeDeps.entriesPreload - Vite could defer pre-bundling of these deps until the initial phase is done. This would keep the startup fast while all other dependencies would get pre-bundled in background before user clicks on another story.

[IanVS]

👍 The only nice part of seeing them was knowing whether it was a hot or cold start, and now that the distinction doesn't matter as much, I agree that it doesn't really help to see the list of optimized dependencies.

[benmccann]

sounds good to me. I might tweak the language a bit to something like:

12:18:24 AM [vite] ✨ newly discovered dependencies optimized: vue, pinia, luxon
12:18:24 AM [vite] ✨ optimized dependencies changed. reloading

[patak-dev]

sounds good to me. I might tweak the language a bit to something like:

12:18:24 AM [vite] ✨ newly discovered dependencies optimized: vue, pinia, luxon
12:18:24 AM [vite] ✨ optimized dependencies changed. reloading

The thing about newly is that the server may restart because of a lock file change and a new import. That is a new dependency, but it will not be logged. So newly doesn't say to me "this is a dep that was not discovered in the scan phase". I think late may be better here. unforeseen sounds too much 👀. But I'm fine with newly, it is what we were using so ok to me.

[patak-dev]

I tried to add all stories into optimizeDeps.entries to force all deps being pre-bundled upfront but it wasn't quite working, it still did some late discoveries. (I could try to create a repro for that and test it again with 2.9)

@tajo I think a repro is a good idea here, IMO we should be able to discover this. Lets create an issue and see if we can find the problem

[patak-dev]

Implemented suggestions, this is how it looks for the react-emotion playground now

[benmccann]

I didn't review the code super closely, but leaving an approval here in terms of the behavior and log messages

[patak-dev]

Maybe we could use a different emoji for this one. Like 🔄 or ⚙️. Not convinced by other options, probably better to keep the current one