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

(Unstable) server-side network request debug route #1284

Merged
merged 19 commits into from Sep 7, 2023

Conversation

wizardlyhel
Copy link
Contributor

@wizardlyhel wizardlyhel commented Aug 29, 2023

WHAT is this pull request doing?

(Unstable) A new virtual route that logs the network requests happening at the server side.

Screenshot 2023-09-06 at 1 43 54 PM

Features

  • Log the main request and the sub requests
  • Main request
    • URL format: <cache status> <purpose?> <url>
    • (Green bar) Time spent on server
    • (Blue bar) Time spent on streaming
  • Sub request
    • URL format: <cache status> <purpose?> <query name>
  • Summary bar
  • Option to show PUT requests

Known issues

  • Sometimes, request/sub request don't get logged - Rerun npm run dev will fix this

How to test

After running npm run dev in a project, you should see

Screenshot 2023-08-31 at 10 42 57 AM

Open http://localhost:3000/debug-network

Screenshot 2023-09-06 at 1 46 33 PM

Clicking on the link will open http://localhost:3000 in another tab.

Navigate around the app and you should see server-side network requests being logged in the network flame graph

Post-merge steps

Checklist

  • I've read the Contributing Guidelines
  • I've considered possible cross-platform impacts (Mac, Linux, Windows)
  • I've added a changeset if this PR contains user-facing or noteworthy changes
  • I've added tests to cover my changes
  • I've added or updated the documentation

@wizardlyhel wizardlyhel changed the title Unstable server request debug tool (Unstable) server-side network request debug route Aug 29, 2023
* Undo changes in demo-store

* Undo changes in remix-oxygen to prevent having multiple request-id

* Undo changes in hydrogen storefront client

* Move request logging logic to CLI

* Ensure there is a request-id and log parent request event in CLI

* Log sub request event using a global fetch stub

* Send server events from the CLI realm instead of the app

* Refactor server events

* Refactor code to use defaultDispatcher from MiniOxygen

* Rely on AsyncLocalStorage to handle ids to support requests to 3p APIs

* Cleanup

* Update to MiniOxygen 2.2.0 to use globalFetch and onRequest

* Fix queryName for mock.shop

* Fix types
@github-actions

This comment has been minimized.

@wizardlyhel
Copy link
Contributor Author

@frandiox I realized that the CLI path doesn't pick up the request to cache api. Any way we can patch cache api to get these network requests?

@blittle
Copy link
Contributor

blittle commented Sep 1, 2023

It might be kinda cool to have at the bottom a summary, similar to the chrome devtools network tab
image

Co-authored-by: Helen Lin <helen.lin@shopify.com>
@wizardlyhel
Copy link
Contributor Author

@frandiox Do we need to pass around the waitUntil?

Comment on lines 34 to 37
globalThis.__H2O_LOG_EVENT = createEventLogger(context);
globalThis.__H2O_LOG_EVENT = createEventLogger(context, {
requestId: request.headers.get('request-id'),
purpose: request.headers.get('purpose'),
});
Copy link
Contributor

@frandiox frandiox Sep 7, 2023

Choose a reason for hiding this comment

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

@wizardlyhel The problem with this approach is that we are now leaking the request-id to the global scope. This works fine if you only have 1 tab open or only hover 1 thing at a time. The moment you have 2 parallel requests or more, it starts overwriting the request-id in the global scope and it won't be deterministic which id is used for sub-requests.

That's what AsyncLocalStorage was preventing. And also why I think we should pass this info down from createStorefrontClient and createWithCache somehow if we want it to work in prod eventually without AsyncLocalStorage.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Oh good point - forgot about multiple request problem

Copy link
Contributor Author

Choose a reason for hiding this comment

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

We already have that request-id in createStorefrontClient just isn't passed down all the way to where we are handling cache logging. If we want it also with createWithCache, then it would also needs to be passed down.

.changeset/thin-carpets-walk.md Outdated Show resolved Hide resolved
Copy link
Contributor

@frandiox frandiox left a comment

Choose a reason for hiding this comment

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

I've changed flame-cart-js dependency to be downloaded via CDN in the browser directly to avoid increasing the size of the CLI installation. Hope that's ok.

Aside from that, I'm finding that a lot of requests are missing from the events. This wasn't happening yesterday so it might be related to recent changes? Here's missing most of the requests, including MISS/HIT/STALE (this is the home page of skeleton template so it should have more requests).
image

Also, check the comment about AsyncLocalStorage, it might be related to this issue.

The problem with this approach is that we are now leaking the request-id to the global scope. This works fine if you only have 1 tab open but the moment you have 2 parallel requests or more, it starts overwriting the request-id to the global scope and it won't be deterministic which id is used for sub-requests.

That's what AsyncLocalStorage was preventing. And also why I think we should pass this info down from createStorefrontClient and createWithCache somehow if we want it to work in prod eventually without AsyncLocalStorage.

@frandiox
Copy link
Contributor

frandiox commented Sep 7, 2023

@wizardlyhel so the interval wasn't working properly. I've replaced it with an event emitter and now there are no more missing events 🎉

Also, you can now open multiple tabs on the /debug-network route and they all show the same info. Clicking the "clear" button removes the server event history and clears the local data in the current tab, but other tabs will keep their info locally until they are reloaded.

Do we need to pass around the waitUntil?

If the user didn't pass waitUntil to the loader context, we should pass the version of waitUntil we have during storefront fetch.
We could make this and env required parameters of the Oxygen adapter instead, I guess...

@wizardlyhel
Copy link
Contributor Author

wizardlyhel commented Sep 7, 2023

@frandiox Thanks for the interval update. I didn't know there is a different way we can send messages.

As for asyncLocalStoreage, let's just use it for local dev for now and we'll think of another way for production/workerd.

We could make waitUntil and env required parameters of the Oxygen adapter instead

Optional for now. Calendar release required.

I've changed flame-cart-js dependency to be downloaded via CDN in the browser directly to avoid increasing the size of the CLI installation. Hope that's ok.

Awesome

@wizardlyhel
Copy link
Contributor Author

@frandiox Do you think we need to bring back globalFetch patch. Otherwise, we don't see fetch calls .. but then .. no one should be doing raw fetch calls .. at least wrap it with createWithCache

@wizardlyhel wizardlyhel merged commit 71a0737 into main Sep 7, 2023
10 checks passed
@wizardlyhel wizardlyhel deleted the hl-server-requests-tool branch September 7, 2023 20:29
@frandiox
Copy link
Contributor

frandiox commented Sep 8, 2023

Do you think we need to bring back globalFetch patch. Otherwise, we don't see fetch calls .. but then .. no one should be doing raw fetch calls .. at least wrap it with createWithCache

@wizardlyhel I was tinkering with globalFetch quite a lot and concluded that for now we should forget about it. The reasons:

  • If we start tracking requests with the globalFetch hook like in my prototype, we start getting log duplicates (once from withCache/storefront, another one with fetch) unless we dedup them in globalFetch or later. However, it's really hard to dedup them because we use different identifiers for both: "cache key" for withCache/storefront, and a raw URL/body for fetch (the only thing we have).
  • They can always wrap raw fetch in withCache with NoCache policy if they need. It's weird to do this for GET requests particularly but at least it's possible.

There might be workarounds and perhaps we can revisit this at some point but for now I think it's a good call to skip raw fetch 👍

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