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

Send server-side timing info for debugging/tracing #272

Open
aickin opened this issue Jun 6, 2016 · 5 comments
Open

Send server-side timing info for debugging/tracing #272

aickin opened this issue Jun 6, 2016 · 5 comments

Comments

@aickin
Copy link
Contributor

aickin commented Jun 6, 2016

I've been thinking about a new dev happiness feature for react-server that could be quite neat: server-side timing info.

The idea is to send down timing info of critical events on the server, including but not limited to:

  • when handle route is called, and when its promise resolves
  • when title, meta, stylesheets are called, and, if they return promises, when those resolve
  • when getElements is called, and, in the case of promises, when each of those elements resolves
  • when each ReactServerAgent request is sent, and when it returns (including late arrivals)
  • when the headers are written
  • when the <head> tag is opened and closed
  • when the <body> tag is opened and closed

Hopefully, these timings could be combined to create a DevTools panel that visualizes the server-side waterfall. This could answer questions like:

  • What RSA requests are taking the most time?
  • What's the critical path to getting the head and various elements written out?
  • How are the server timeout and late arrivals interacting with the rendering?

I think this could be quite a powerful feature for debugging SSR. What do you think?

@gigabo
Copy link
Contributor

gigabo commented Jun 6, 2016

Sounds cool! Some of those timings are already logged on the server, and it should be straightforward to instrument the rest. The real feature here is getting server-side timings sent to the client and presenting them somehow.

For a waterfall-style presentation we would need start/end times relative to the beginning of the request as well as durations. This is straightforward to get for all timing events that happen in a request context.

Ideas for how to send the timing info? Seems like easiest would be to just send it in the primary document like late data responses and node arrival alerts. There's a little bit of a chicken/egg problem at the end of the request there, but maybe the very tail-end timings don't matter? Could alternatively open up a secondary channel, but that's more complicated.

It would be extra awesome to be able to accurately merge server/client stats in the same waterfall! Would just need an offset for the server's request start time relative to the browser's navigation timing API start time... Not sure how well we can estimate that...

The more I think about this the more excited I get! Good idea @aickin!

@gigabo gigabo added enhancement New functionality. epic labels Jun 6, 2016
@aickin
Copy link
Contributor Author

aickin commented Jun 6, 2016

Ideas for how to send the timing info? Seems like easiest would be to just send it in the primary document like late data responses and node arrival alerts.

Yeah, that's what I was thinking. If we wanted to be really fancy, we'd send the timings down as the occur throughout the page so that the waterfall could be built and updated as the page loads. But frankly, that sounds like a lot of work for not a lot of payoff. I think I'd just put all the timings below the late arrivals and have the devtools panel say "Waiting for data..." until it comes in.

There's a little bit of a chicken/egg problem at the end of the request there, but maybe the very tail-end timings don't matter?

Good point! I would just punt on getting the true end-of-response time.

Could alternatively open up a secondary channel, but that's more complicated.

Not worth it. If you read out the timings after late arrivals and right before </body>, you're close enough to the end of the response.

Would just need an offset for the server's request start time relative to the browser's navigation timing API start time... Not sure how well we can estimate that...

I think that's one of those "seems not that hard but is actually functionally impossible" problems in computer science.

The more I think about this the more excited I get!

🎉 Yeah, the more I think about it, the more I think it could be super powerful to see the server-side waterfall with a single click in DevTools. (Makes a great demo, too... ;)

@vinsewah
Copy link
Contributor

vinsewah commented Aug 8, 2016

Redfin will be looking to tackle this soon. Stay tuned!

vinsewah pushed a commit to vinsewah/react-server that referenced this issue Aug 22, 2016
vinsewah pushed a commit to vinsewah/react-server that referenced this issue Aug 26, 2016
vinsewah pushed a commit to vinsewah/react-server that referenced this issue Aug 26, 2016
vinsewah pushed a commit to vinsewah/react-server that referenced this issue Aug 26, 2016
@vinsewah
Copy link
Contributor

The work to do this has been merged!

@gigabo
Copy link
Contributor

gigabo commented Nov 30, 2016

@bharath-rengarajan has an amazing chrome plugin that generates a waterfall graph from the server timing data. Gotta get that into this repo and up on the chrome store!

@gigabo gigabo added performance and removed enhancement New functionality. labels Nov 30, 2016
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

No branches or pull requests

3 participants