Tracing includes a long section that should not be there

[sorenbs]

When tracing https://airbnb.now.sh/ I get a long section (roughly 4 seconds) in the beginning of the trace, even though the entire request took less than 200 ms:

[rmosolgo]

I tried GraphQL-Playground today with the hope of using the tracing pane, but I encountered a similar issue. To debug, my teammate suggested stubbing my server with some example data, so I grabbed the example from https://github.com/apollographql/apollo-tracing#example.

The example data demonstrated the same issue:

However, while setting up my stub, I did a botched find-and-replace (: to =>, turning JSON into a Ruby hash) which made startTime and endTime invalid (you can see in the response pane), and gave in an interesting rendering:

So, I suspect that the issue is with the startTime/endTime, since the field timings seem to work nicely!

[thearrow]

Seeing a similar issue - tracing is not working at all for me.

I always see one single long Request bar (always ~40k-50k ms) and nothing else (even after scrolling the tracing window which seems to be very wide):

The actual tracing data in the response seems to be there and be fine:

The simple test resolver is like so:

Have tried with every variation of simple test resolvers - sync, async, slow, fast, etc. result is always the same.

Versions: package.json:

"apollo-server": "^2.0.0-rc.5",
"graphql": "^0.13.2",
"graphql-import": "^0.6.0",
"graphql-type-json": "^0.2.1"

yarn.lock:

graphql-playground-html@1.6.0:
  version "1.6.0"
  resolved "https://registry.yarnpkg.com/graphql-playground-html/-/graphql-playground-html-1.6.0.tgz#6ec4d54325ab2e5352506fdb89eb37c3fc718bf8"
  dependencies:
    graphql-config "2.0.0"

graphql-playground-middleware-express@^1.7.0:
  version "1.7.2"
  resolved "https://registry.yarnpkg.com/graphql-playground-middleware-express/-/graphql-playground-middleware-express-1.7.2.tgz#5f7bf3683494fe17893d1b54bbecee5e222c2e78"
  dependencies:
    graphql-playground-html "1.6.0"

[mklingberg]

@schickling, @Huvik please correct me if im wrong here :) but the current Trace implementation depends on browser and server clocks beeing exactly in sync.

Sadly this renders the trace window useless in scenarios outside your local dev. machine.

The problem seems to be with the trace calculation

const { tracing, tracingSupported, startTime, endTime, open } = this.props const requestMs = tracing && startTime ? Math.abs(new Date(tracing.startTime).getTime() - startTime.getTime()) : 0 const responseMs = tracing && endTime ? Math.abs(endTime.getTime() - new Date(tracing.endTime).getTime()) : 0 const requestDuration = 1000 * 1000 * requestMs

where delta is calculated as the difference between tracing.startTime (server clock) and startTime (client clock)...

(ResponseTracing.tsx:76)

[Ririshi]

Sorry to bump an old issue, but the problem still seems to exist. My server is a Docker container, and I am using GraphQL Playground on the (Windows) host machine. The images below show what is happening quite well.

This first image is the default view, where only the "Request" line is visible. Here, I've made the tracing pane much wider, and the search query is visible now. This query is pretty large. When I scroll down through the query, the text eventually moves outside the viewport, and the horizontal scrollbar will not let me scroll towards that overflowing text.

I hope someone is able to fix the issue highlighted above my comment. In the meantime, does anyone know a different tool I can use to visualize my GraphQL traces? I am trying to make our Lighthouse PHP GraphQL API faster, but it is quite tough to debug it without proper tracing.