Error "504 (Outdated Optimize Dep)" when force re-optimization on the server start by using vite --force

[anyesu]

Describe the bug

中文说明

GET http://localhost:5173/node_modules/.vite/deps/element-ui_lib_button.js?v=bc3e4ba5 504 (Outdated Optimize Dep)

On my project built with vue-element-admin , this error sometimes occurs when using the vite --force to start the project, so the page displays a white screen. However, the error disappears when restart the project again. Although this way can solve the problem, it is quite annoying to have this error from time to time.

The reason for this problem is that the id will be changed through tryOptimizedResolve in vite:resolve , but the optimizer does not actually pre-build the corresponding file because there is no outdatedResult .

The timing of this problem is random ( maybe related to the complexity of the project files ) , and it is difficult to reproduce it stably. However, after repeated trials, I finally found a specific situation that can definitely cause this problem:

• Any url except / and /favicon.ico which can trigger additional transformRequest in transformMiddleware , .e.g /xxx . This is very important!

  vite/packages/vite/src/node/server/middlewares/transform.ts

  Line 44 in 898fee7

  const knownIgnoreList = new Set(['/', '/favicon.ico'])

  vite/packages/vite/src/node/server/middlewares/transform.ts

  Lines 56 to 58 in 898fee7

  	if (req.method !== 'GET' || knownIgnoreList.has(req.url!)) {
  	return next()
  	}

  vite/packages/vite/src/node/server/middlewares/transform.ts

  Lines 203 to 205 in 898fee7

  	const result = await transformRequest(url, server, {
  	html: req.headers.accept?.includes('text/html'),
  	})

• Import statements dynamically added by plugins as what unplugin-auto-import does, they cannot be optimized by crawl of static imports and will trigger addMissingDep during transform .

  vite/packages/vite/src/node/optimizer/optimizer.ts

  Line 541 in 898fee7

  missing = addMissingDep(id, resolved)

• The slow transformIndexHtml which is used to increase the time interval between the first request /xxx and preTransformRequest .

  vite/packages/vite/src/node/server/middlewares/indexHtml.ts

  Lines 348 to 365 in 898fee7

  	function preTransformRequest(server: ViteDevServer, url: string, base: string) {
  	if (!server.config.server.preTransformRequests) return
  	url = unwrapId(stripBase(url, base))
  	// transform all url as non-ssr as html includes client-side assets only
  	server.transformRequest(url).catch((e) => {
  	if (
  	e?.code === ERR_OUTDATED_OPTIMIZED_DEP ||
  	e?.code === ERR_CLOSED_SERVER
  	) {
  	// these are expected errors
  	return
  	}
  	// Unexpected error, log the issue but avoid an unhandled exception
  	server.config.logger.error(e.message)
  	})
  	}

• Pre-build a large scss file ( .e.g element-ui ) which may cost a few seconds to make the optimize step slower.

Sorry for my poor Chinglish, but I think you can understand what I mean after running the demo below.

Reproduction

https://stackblitz.com/edit/vitejs-vite-imqoo8?file=vite.config.js

Steps to reproduce

In order to better observe the problem, I added a patch file created with patch-package to show more logs.

pnpm i
pnpm run dev

Open the browser and visit the page, you can see nothing and will find 504 (Outdated Optimize Dep) error in devtools.

Then you can see the following log in terminal:

  Forced re-optimization of dependencies
    vite:deps scanning for dependencies... +0ms

    VITE v4.4.9  ready in 986 ms

    ➜  Local:   http://localhost:5173/
    ➜  Network: use --host to expose
    ➜  press h to show help
+ call delayDepsOptimizerUntil('/not_root') 0ms after the last
+ call markIdAsDone('/not_root') 0ms after the last
    vite:deps Crawling dependencies using entries:
    vite:deps   /home/projects/vitejs-vite-imqoo8/index.html +0ms
    vite:deps ✨ static imports crawl ended +871ms
+ metadata.discovered ( size: 1 ) : element-ui/packages/theme-chalk/src/index.scss
    vite:deps Scan completed in 927.22ms: no dependencies found +95ms
+ metadata.discovered ( size: 1 ) : element-ui/packages/theme-chalk/src/index.scss
+ call delayDepsOptimizerUntil('main.js') 177ms after the last
+ call delayDepsOptimizerUntil('node_modules/.vite/deps/element-ui_lib_button.js?v=1d7c7005') 10ms after the last
    vite:deps Dependencies bundled in 1216.69ms +0ms
+ metadata.discovered ( size: 2 ) : element-ui/packages/theme-chalk/src/index.scss, element-ui/lib/button
    vite:deps ✨ using post-scan optimizer result, the scanner found every used dependency +1s
    vite:deps ✨ dependencies optimized +1ms
+ call delayDepsOptimizerUntil('node_modules/.pnpm/vite@4.4.9_sass@1.66.1/node_modules/vite/dist/client/client.mjs') 1175ms after the last
+ call delayDepsOptimizerUntil('node_modules/.pnpm/vite@4.4.9_sass@1.66.1/node_modules/vite/dist/client/env.mjs') 3ms after the last
+ call delayDepsOptimizerUntil('node_modules/.vite/deps/element-ui_lib_button.js?v=1d7c7005') 405ms after the last

If you run the project multiple times, you will find that the order of the logs may be different.

According to the log we can find two things:

• The delayDepsOptimizerUntil('main.js') was called 177ms after the delayDepsOptimizerUntil('/not_root') be called.

  This time difference exceeds callCrawlEndIfIdleAfterMs so the onCrawlEnd was called earlier than expected.

• The length of metadata.discovered was changed from 1 to 2.

  When this line of code was executed, the actual length of crawlDeps is 1, which is the same as scanDeps , so it goes to else ( using post-scan optimizer result... ) .

  vite/packages/vite/src/node/optimizer/optimizer.ts

  Lines 622 to 635 in 898fee7

  	const crawlDeps = Object.keys(metadata.discovered)
  	// Await for the scan+optimize step running in the background
  	// It normally should be over by the time crawling of user code ended
  	await depsOptimizer.scanProcessing
  	if (!isBuild && optimizationResult && !config.optimizeDeps.noDiscovery) {
  	const result = await optimizationResult.result
  	optimizationResult = undefined
  	currentlyProcessing = false
  	const scanDeps = Object.keys(result.metadata.optimized)
  	if (scanDeps.length === 0 && crawlDeps.length === 0) {

Then we can change the content of the vite.config.js file:

- process.env.NO_SLOW || slowTransformIndexHtml(),
+ // process.env.NO_SLOW || slowTransformIndexHtml(),

vite will restart automatically, and then we will look at the logs afterwards:

  [vite] vite.config.js changed, restarting server...
  Forced re-optimization of dependencies
    vite:deps scanning for dependencies... +25m
  [vite] server restarted.
+ call delayDepsOptimizerUntil('/not_root') 0ms after the last
+ call markIdAsDone('/not_root') 0ms after the last
    vite:deps Crawling dependencies using entries:
    vite:deps   /home/projects/vitejs-vite-imqoo8/index.html +25m
+ call delayDepsOptimizerUntil('main.js') 823ms after the last
    vite:deps Scan completed in 928.80ms: no dependencies found +99ms
+ call delayDepsOptimizerUntil('node_modules/.vite/deps/element-ui_lib_button.js?v=e80a6e76') 100ms after the last
+ call markIdAsDone('/home/projects/vitejs-vite-imqoo8/main.js') 922ms after the last
    vite:deps ✨ static imports crawl ended +988ms
+ metadata.discovered ( size: 2 ) : element-ui/packages/theme-chalk/src/index.scss, element-ui/lib/button
+ metadata.discovered ( size: 2 ) : element-ui/packages/theme-chalk/src/index.scss, element-ui/lib/button
    vite:deps Dependencies bundled in 1137.07ms +25m
+ metadata.discovered ( size: 2 ) : element-ui/packages/theme-chalk/src/index.scss, element-ui/lib/button
    vite:deps ✨ new dependencies were found while crawling that weren't detected by the scanner +1s
    vite:deps ✨ re-running optimizer +0ms
    vite:deps new dependencies found: element-ui/packages/theme-chalk/src/index.scss, element-ui/lib/button +6ms
    vite:deps Dependencies bundled in 1032.49ms +1s
    vite:deps ✨ dependencies optimized +1s
+ call delayDepsOptimizerUntil('node_modules/.vite/deps/chunk-76J2PTFD.js?v=b0e72c20') 2196ms after the last
+ call delayDepsOptimizerUntil('node_modules/.pnpm/vite@4.4.9_sass@1.66.1/node_modules/vite/dist/client/client.mjs') 4394ms after the last
+ call delayDepsOptimizerUntil('node_modules/.pnpm/vite@4.4.9_sass@1.66.1/node_modules/vite/dist/client/env.mjs') 2ms after the last

The length of metadata.discovered was no longer changed, and the re-running optimizer step was executed as expected.

Open the browser and visit the page, you can see Hello,World! and no error in devtools.

Another strange thing here is that the delayDepsOptimizerUntil('main.js') was called 823ms after the previous, which looks like pre-build of scss was run before.

System Info

System:
    OS: Windows 10 10.0.19045
    CPU: (16) x64 11th Gen Intel(R) Core(TM) i7-11700 @ 2.50GHz
    Memory: 26.00 GB / 47.81 GB
  Binaries:
    Node: 16.20.2 - ~\AppData\Local\pnpm\node.EXE
    Yarn: 1.22.18 - D:\software\nodejs\node_global\yarn.CMD
    npm: 8.19.4 - ~\AppData\Local\pnpm\npm.CMD
    pnpm: 8.6.12 - ~\AppData\Local\pnpm\pnpm.EXE
  Browsers:
    Edge: Spartan (44.19041.1266.0), Chromium (116.0.1938.69)
    Internet Explorer: 11.0.19041.1566

Used Package Manager

pnpm

Logs

No response

Validations

• Follow our Code of Conduct
• Read the Contributing Guidelines.
• Read the docs.
• Check that there isn't already an issue that reports the same bug to avoid creating a duplicate.
• Make sure this is a Vite issue and not a framework-specific issue. For example, if it's a Vue SFC related bug, it should likely be reported to vuejs/core instead.
• Check that this is a concrete bug. For Q&A open a GitHub Discussion or join our Discord Chat Server.
• The provided reproduction is a minimal reproducible example of the bug.

[stackblitz]

Start a new pull request in StackBlitz Codeflow.

• vitejs-vite-imqoo8 (Open reproduction)