FormidableLabs / envy

Node.js Telemetry & Network Viewer
https://envy-webui.vercel.app
MIT License
107 stars 0 forks source link

Envy NextJS connector sometimes shows traces as happening more than they do #200

Closed kgpax closed 8 months ago

kgpax commented 8 months ago

Issue

Observed when using Envy on a NextJS 14 project, we have an API route which calls a 3rd party backend API once. E.g.,

// api/foo/route.ts

export async function GET() {
  const { data } = await axios.get('https://example.com/api/bar');
  return NextResponse.json(data);
}

When this API router is called from a web page, Envy shows both the call to the API route and the call to the backend API, as we would expect:

GET 200 http://localhost:3000/api/foo
GET 200 https://example.com/api/bar

All good πŸ‘

However... if we reload the web page which makes this call, we notice that Envy shows two traces for the backend API:

GET 200 http://localhost:3000/api/foo
GET 200 https://example.com/api/bar
GET 200 https://example.com/api/bar

Wierd πŸ€”. What's more is that with enough page reloading or even maybe hot reloading during development, Envy will show that the API route makes many, many calls to the backend API for each call to the API route... even if hitting the API route directly. All this despite there only ever being one call actually being made to the backend API by the API route.

Interestingly, these are not even duplicate traces, since whilst almost all of the details are identical, the timings data differs, so something is legitimately treating these as separate traces to report to Envy.

Reproduction steps

I've created a branch bug/envy-nextjs-duplicate-traces which can demonstrate this issue. To see if for yourself:

Video

Not got time for the above, I recorded myself doing it...

https://github.com/FormidableLabs/envy/assets/17857833/40bf1b0f-49cc-483d-a180-7b941cf7094c

What's going on?

kgpax commented 8 months ago

Update: the issue could be related to this code:

https://github.com/FormidableLabs/envy/blob/814605627ea1be5fa7566675fd9e1deffaa81670/packages/nextjs/src/tracing.ts#L33-L39

The intent here is that the node enableTracing call is only done once, but there are cases (on first page refresh and on hot reload) where this gets called twice, presumably due to a race condition over two calls trying to set this.

If I put a console log inside this if (!initialized) block, then on the occasions where I see that log written twice (which shouldn't happen, in theory), this is where the number of traces being shown increases.