Understanding graphql tracing

[zyqxd]

Looking for some insights into graphql tracing. Specifically a newrelic report, but I'm sure other tracers have similar behaviours. My goal is to see if there are any performance optimizations.

My understanding is that there are a few actions tied to the GraphQL/execute key, specifically:

      # lib/graphql/tracing/new_relic_tracing.rb
      self.platform_keys = {
        "execute_multiplex" => "GraphQL/execute",
        "execute_query" => "GraphQL/execute",
        "execute_query_lazy" => "GraphQL/execute",
      }

On newrelic, we have some key transactions that we monitor. A couple of them have the behaviour where almost half the response time is spent doing GraphQL/execute

Example response times. Brown is the time spent executing and blue is the total response time

The reason why I feel like there are optimizations to be made here is because we also have queries where the GraphQL component of the request is very fast, example purple and yellow are execute, green is validate:

1. There are 3 transactions for GraphQL/execute per query, is my thinking that all of the previously mentioned platform_keys get executed each one time correct?

2. Graphql language parsing is foreign to me so it's entirely possible that there are no gains to be made other than a smaller query / less fields. Would less nesting help this? Or is there some other trick involving structure of your fields?

3. Is it there any possible way / configuration to get a deeper understanding into what this execute transaction is doing?

4. Since most of the query is the same except a few arguments, is there possible cache gains here?

Thanks

cc @rmosolgo, Apologies for the tag, I understand you're busy. I thought you may have the best insight into this.

[rmosolgo]

Could you share some example queries and responses for these? The problem is, "a query" in GraphQL can refer to very different things, depending on how much work the server has to do to build a response. For example, consider this query string:

query($companyId: ID!) {
  company(id: $companyId) {
    employees { name } 
  }
}

Depending on the company ID, the query above may prepare a response with only a few objects in the response (for a company with a few employees) or it may prepare a response with bazillions of objects (for a multinational conglomerate megacorp). So, without some domain understanding, it's hard to make sense of it 😅

[zyqxd]

The queries we have all contain numerous connections and fields (some arrays). They get quite large. It makes sense that the response is tied to the complexity of building the response, especially in a case similar to your example.

However, newrelic is logging data fetching as separate transaction instances. This makes me think that there's additional work done by the graphql gem here and I'd like to understand what it would be. Rather than pasting queries and responses, I thought it may make more sense to instrument the response with more insight into that "execute" chunk.

[rmosolgo]

Ahh, yeah, that makes sense. Just to be sure, do your traces include any of these keys?

graphql-ruby/lib/graphql/tracing/new_relic_tracing.rb

Lines 38 to 48 in 75de903

	def platform_field_key(type, field)
	"GraphQL/#{type.graphql_name}/#{field.graphql_name}"
	end
	def platform_authorized_key(type)
	"GraphQL/Authorize/#{type.graphql_name}"
	end
	def platform_resolve_type_key(type)
	"GraphQL/ResolveType/#{type.graphql_name}"
	end

Also, what version of GraphQL-Ruby are you using?

[zyqxd]

We're currently on v1.8.12, in the process of upgrading to 2.x (first to 1.11). Understandably this is a few versions out of date, could this also be why execute is taking so long?

As for trace keys, we're getting platform_field_keys showing up. Examples (%Time | Avg calls | Avg time)

GraphQL | validate | 6.6 | 1.0 | 21.4
GraphQL | analyze | 3.1 | 2.0 | 10.1
GraphQL | Post/topics | 2.5 | 3.12 | 8.19
GraphQL | ActivityEvent/subject | 1.7 | 2.33 | 5.42
GraphQL | Product/positiveReviewTags | 1.6 | 2.0 | 5.26

We're still getting tho that large execute chunk

GraphQL | execute | 28.4 | 3.0 | 91.6

[rmosolgo]

Woah! 1.8, that's pretty classic. Sorry, I honestly can't dive in on such an old version anymore. But yes, I'd expect updating to improve performance.