Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: server middleware graph #67

Merged
merged 9 commits into from
Apr 19, 2023
Merged

Conversation

sun0day
Copy link
Contributor

@sun0day sun0day commented Apr 12, 2023

Description

Support showing vite dev server middleware perfs

image

Linked Issues

This PR depends on vitejs/vite#12787

Additional context

@antfu antfu marked this pull request as draft April 12, 2023 21:15
@antfu
Copy link
Member

antfu commented Apr 12, 2023

Marking as draft until Vite shipped it. Ideally, we should also have some logic to hide the tab when running on older vite that does support it.

@sun0day
Copy link
Contributor Author

sun0day commented Apr 15, 2023

Vite would not expose a public API for server-side related perfs after discussion in vitejs/vite#12787, there is no way for vite-plugin-inspect to get the server start-up time, dependencies scanning time, pre-bundle time... but luckily we can get the middleware resolving time via configureServer hook. @antfu

serverPerf.middleware![url] = []

// @ts-expect-error handle needs 3 or 4 arguments
await (middlewareArgs.length === 4 ? handle(err, req, res, next) : handle(req, res, next))
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can you help review the middleware timing logic? @sapphi-red @bluwy @patak-dev thanks

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would you explain a bit more what is self here? I'm lost why it needs to be computed at this point, seems to be the same info you have in total and could check the full array later 🤔

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Consider it as something like self time & total time in cpuprofile. Here total means the middleware execution total time and self equals total minus the next() middleware's total

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Oh, I see. Makes sense, I wasn't clearly thinking in the next() recursion here.
Maybe to avoid race conditions the best would be to avoid computing self until you have the complete array with total times. Only keeping each total is enough, and later you can compute them knowing all the values are there. But this looks good to me 👍🏼

@sun0day sun0day marked this pull request as ready for review April 15, 2023 10:17
@patak-dev
Copy link

I got a negative time in the playground after:

  • cold start (showed all the urls with positive times)
  • stop server then warm start (only three url appeared when the page refreshed)
  • then refresh manually and I see this screenshot

image

const total = Date.now() - start
const metrics = serverPerf.middleware![url]

// middleware selfTime = totalTime - next.totalTime

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should read prev here, no?

Suggested change
// middleware selfTime = totalTime - next.totalTime
// middleware selfTime = totalTime - prev.totalTime

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No, it's next() totalTime, thinking about the onion model.

@sun0day
Copy link
Contributor Author

sun0day commented Apr 15, 2023

I got a negative time in the playground after:

  • cold start (showed all the urls with positive times)
  • stop server then warm start (only three url appeared when the page refreshed)
  • then refresh manually and I see this screenshot

I met the negative time before, I think it's due to the async function next(){} and there are no await next() but only next() calls. I think we can filter these negative time directly

@antfu antfu changed the title Feat/server perf feat: server middleware graph Apr 19, 2023
@antfu antfu merged commit 0e686ad into antfu-collective:main Apr 19, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants