Instrumentation query hooks bug + teardown behaviour

[swalkinshaw]

We're seeing some surprising behaviour when using query level instrumentation. This might have been a naive assumption, but we assumed that the sequence of before_query -> after_query would be reliable.

I've created a failing test case to demonstrate our situation: https://github.com/swalkinshaw/graphql-ruby/blob/45351d42dded3b682b59561b2ceb845d68b6d91c/spec/graphql/instrumentation_spec.rb

Summary:

• two instrumenters
• first one in the chain causes an exception during before_query (or maybe even during execution)
• second one relies on state from before_query in its after_query hook which causes an error
• RuntimeError: bad teardown gets raised instead of NameError.

The last point is especially confusing. The earlier exception is swallowed even though it happens first.

Basically, any instrumentation can't rely on state that's set in before_query being available in after_query if you have multiple instrumenters.

Here's an example in the wild: https://github.com/uniiverse/apollo-tracing-ruby/blob/master/lib/apollo_tracing.rb

This one relies on the existence of a key (apollo-tracing) in the query context. This could easily cause problems if you had another instrumenter.

Right now we've worked around this by ensuring any state we need actually exists but this seems like something the gem should ideally handle properly.

cc @eapache

[swalkinshaw]

cc @exAspArk too since this affects apollo-tracing

[swalkinshaw]

Thinking about this more, I don't think an instrumenter's after_query should depend on before_query running since there would definitely be use cases for using each independently.

So I'm not sure what or even if there's a solution to this. At a minimum the instrumentation docs should be updated to warn not to rely on state.

Beyond that, should an exception in one instrumenter's before_query stop the others from running? Same thing goes for after_query.

We could just rescue when calling each before_query than raise the first exception after they all run?

[rmosolgo]

These are great questions. I'm open to a lot of the solutions here and I agree, it's a bit murky in any case!

I will think about this more tomorrow ... Happy to take a recommendation 😅

[eapache]

there would definitely be use cases for using each independently.

I'm curious what you're thinking of here?

We could just rescue when calling each before_query than raise the first exception after they all run?

If a before_query raises, should the query even execute or should that just bubble up immediately? I suppose it's good to be robust to bad instrumentation, but sometimes the instrumentation may be important and the query won't execute properly without it anyway...

[swalkinshaw]

I guess any examples of using them independently could just be accomplished by putting code before or after you call schema.execute. But people may still reach for instrumentation anyway.

If a before_query raises, should the query even execute or should that just bubble up immediately?

My initial thought is the exception should be raised right away and the query shouldn't execute.

@rmosolgo it's kind of interesting you refer to after_query as "teardown". It's a semantic thing, but should they be considered like that?

One solution is just removing ensure. Exceptions will be raised right away, and there's no state issues.

[exAspArk]

Exceptions will be raised right away, and there's no state issues.

👍 please don't swallow exceptions :)

By the way, is it possible to introspect queries similarly to fields (or middlewares)? So, developers could define whether it's important for them to "teardown" after getting an exception or not? For example:

class MyInstrumenter
  def instrument(query)
    my_before_query
    execute(query)
    my_after_query
  ensure
    my_teardown
  end
end

[rmosolgo]

It gets complicated when we run multiple queries together: http://graphql-ruby.org/queries/multiplex.html

Should an error in one query cause the others to crash? Probably not, but maybe we can keep from running that one query.

But multiplexing is why begin ... end doesn't quite work 😖

[dylanahsmith]

I don't see why the semantics shouldn't just be

instrumenter1.before_query(query)
begin
  instrumenter2.before_query(query)
  begin
    # ...
  ensure
    instrumenter2.after_query(query)
  end
ensure
  instrumenter1.after_query(query)
end

as in the after_(query|multiplex) for an instrumenter should be called if its before_(query|multiplex) completes, regardless of any exceptions in other instrumenters or queries. That would preserve the intended teardown behaviour. Otherwise, another type of hook is needed for teardown (e.g. around_(query|multiplex)) to support this common use case.

Recursion could be used to do the same thing with an array of instrumenters

def call_query_hooks(instrumenters, query, i=0)
  if i >= instrumenters.length
    yield
  else
    instrumenters[i].before_query(query)
    begin
      call_query_hooks(instrumenters, query, i + 1) { yield }
    ensure
      instrumenters[i].after_query(query)
    end
  end
end

[rmosolgo]

If a before_ hook was called & returned without an error, its corresponding after_ hook will be called.

That semantic seems good to me, any objections? Otherwise I'll implement it!

[swalkinshaw]

I think that's the most logical behaviour 👍

The goal is still to isolate that within a multiple query I assume?

[rmosolgo]

Took a crack at it in #1100