Schema#multiplex causes context.namespace(:interpreter)[:current_path] to be nil inside `then` block

[DmitryTsepelev]

Describe the bug

I found a case when context.namespace(:interpreter)[:current_path] is nil (to be precise, most of the keys inside the :interpreter hash are missing). The problem appears when Schema#multiplex is called and I try to get the current path inside .then block in promise, i.e.:

class Tweet < GraphQL::Schema::Object
    field :content, String, null: false
    field :author, Types::User, null: false

    def author
      puts "Tweet:author current_path=#{context.namespace(:interpreter)[:current_path]}"

      Batch::RecordLoader.for(::User).load(object.author_id).then do |author|
        puts "Tweet:author after batch current_path=#{context.namespace(:interpreter)[:current_path]}"
        author
      end
    end
  end

However, it works fine when Schema#execute is used.

Not sure if I should go to the graphql-batch repo with this issue.

Versions

graphql version: latest
graphql-batch version: latest

Steps to reproduce

A whole example:

begin
  require "bundler/inline"
rescue LoadError => e
  $stderr.puts "Bundler version 1.10 or later is required. Please update your Bundler"
  raise e
end

gemfile(true) do
  source "https://rubygems.org"

  gem "rails", "6.0.3"
  gem "pg"
  gem "graphql", "~> 1.12"
  gem "rspec-rails", "~> 4.0.1"
  gem "db-query-matchers"
  gem "ar_lazy_preload"
  gem "graphql-batch"
end

require "active_record"

class App < Rails::Application
  config.logger = Logger.new('/dev/null')
end

App.initialize!

ActiveRecord::Base.establish_connection(adapter: "postgresql", database: "nplusonedb")

ActiveRecord::Schema.define do
  enable_extension "plpgsql"

  create_table "users", force: :cascade do |t|
    t.string "nickname", null: false
    t.datetime "created_at", precision: 6, null: false
    t.datetime "updated_at", precision: 6, null: false
  end

  create_table "tweets", force: :cascade do |t|
    t.text "content", null: false
    t.bigint "author_id", null: false
    t.datetime "created_at", precision: 6, null: false
    t.datetime "updated_at", precision: 6, null: false
  end

  add_foreign_key "tweets", "users", column: "author_id"
end

class User < ActiveRecord::Base
  has_many :tweets, foreign_key: :author_id
end

class Tweet < ActiveRecord::Base
  belongs_to :author, class_name: "User"
end

module Batch
  class RecordLoader < GraphQL::Batch::Loader
    def initialize(model)
      @model = model
    end

    def perform(ids)
      @model.where(id: ids).each { |record| fulfill(record.id, record) }
      ids.each { |id| fulfill(id, nil) unless fulfilled?(id) }
    end
  end
end

module Types
  class User < GraphQL::Schema::Object
    field :nickname, String, null: false
  end

  class Tweet < GraphQL::Schema::Object
    field :content, String, null: false
    field :author, Types::User, null: false

    def author
      puts "Tweet:author current_path=#{context.namespace(:interpreter)[:current_path]}"

      Batch::RecordLoader.for(::User).load(object.author_id).then do |author|
        puts "Tweet:author after batch current_path=#{context.namespace(:interpreter)[:current_path]}"
        author
      end
    end
  end
end

class FeedResolver < GraphQL::Schema::Resolver
  type [Types::Tweet], null: false

  def resolve(limit: nil, offset: nil)
    Tweet.limit(limit).offset(offset)
  end
end

module Types
  class Query < GraphQL::Schema::Object
    field :feed, [Types::Tweet], null: false, resolver: FeedResolver do
      argument :limit, Integer, required: false
      argument :offset, Integer, required: false
    end
  end
end

class GraphqlSchema < GraphQL::Schema
  query Types::Query
  use GraphQL::Batch
end

Tweet.delete_all
User.delete_all

john = User.create(nickname: "John")
max = User.create(nickname: "Max")

john.tweets.create(content: "Hi!", created_at: Time.new(2020, 6, 12, 10))
max.tweets.create(content: "Hello!", created_at: Time.new(2020, 6, 13, 10))
john.tweets.create(content: "My second tweet is here", created_at: Time.new(2020, 6, 15, 10))
max.tweets.create(content: "The weather is nice", created_at: Time.new(2020, 6, 17, 10))

puts "\nSchema#multiplex\n"

query1 = <<~GQL
  query {
    feed(offset: 0, limit: 2) {
      content
      author {
        nickname
      }
    }
  }
GQL

query2 = <<~GQL
  query {
    feed(offset: 2, limit: 2) {
      content
      author {
        nickname
      }
    }
  }
GQL

puts GraphqlSchema.multiplex([{ query: query1 }, { query: query2 }]).map(&:to_h).inspect

puts "\nSchema#execute\n"

puts GraphqlSchema.execute(query1).to_h.inspect

Expected behavior

I want to be able to get the current path inside the promise 🙂

Actual behavior

Current path is available only inside first promise block. Here is what I see in the console:

Schema#multiplex
Tweet:author current_path=["feed", 0, "author"]
Tweet:author current_path=["feed", 1, "author"]
Tweet:author current_path=["feed", 0, "author"]
Tweet:author current_path=["feed", 1, "author"]
Tweet:author after batch current_path=["feed", 0, "author"]
Tweet:author after batch current_path=
Tweet:author after batch current_path=["feed", 0, "author"]
Tweet:author after batch current_path=
[{"data"=>{"feed"=>[{"content"=>"Hi!", "author"=>{"nickname"=>"John"}}, {"content"=>"Hello!", "author"=>{"nickname"=>"Max"}}]}}, {"data"=>{"feed"=>[{"content"=>"My second tweet is here", "author"=>{"nickname"=>"John"}}, {"content"=>"The weather is nice", "author"=>{"nickname"=>"Max"}}]}}]

Schema#execute
Tweet:author current_path=["feed", 0, "author"]
Tweet:author current_path=["feed", 1, "author"]
Tweet:author after batch current_path=["feed", 0, "author"]
Tweet:author after batch current_path=["feed", 0, "author"]

[rmosolgo]

Hey, thanks for the details on this issue! Yes, this sounds like a bug to me, and this is the right place to report it.

I would have expected those context values to be populated by this:

graphql-ruby/lib/graphql/execution/interpreter/runtime.rb

Line 489 in e151620

set_all_interpreter_context(owner_object, field, arguments, path)

But evidently that's not the case!

[rmosolgo]

(derp, wrong button.)

[DmitryTsepelev]

I've tried to add logging right after graphql-ruby/lib/graphql/execution/interpreter/runtime.rb:489 and figured out, that it's called once before resolving the lazy object (and 3 more times after):

Schema#multiplex
Tweet:author current_path=["feed", 0, "author"]
Tweet:author current_path=["feed", 1, "author"]
Tweet:author current_path=["feed", 0, "author"]
Tweet:author current_path=["feed", 1, "author"]
set_all_interpreter_context(owner_object, #<GraphQL::Schema::Field:0x00007fcf0af871f0>, {}, ["feed", 0, "author"])
Tweet:author after batch current_path=["feed", 0, "author"]
Tweet:author after batch current_path=
Tweet:author after batch current_path=["feed", 0, "author"]
Tweet:author after batch current_path=
set_all_interpreter_context(owner_object, #<GraphQL::Schema::Field:0x00007fcf0af871f0>, {}, ["feed", 1, "author"])
set_all_interpreter_context(owner_object, #<GraphQL::Schema::Field:0x00007fcf0af871f0>, {}, ["feed", 0, "author"])
set_all_interpreter_context(owner_object, #<GraphQL::Schema::Field:0x00007fcf0af871f0>, {}, ["feed", 1, "author"])
[{"data"=>{"feed"=>[{"content"=>"Hi!", "author"=>{"nickname"=>"John"}}, {"content"=>"Hello!", "author"=>{"nickname"=>"Max"}}]}}, {"data"=>{"feed"=>[{"content"=>"My second tweet is here", "author"=>{"nickname"=>"John"}}, {"content"=>"The weather is nice", "author"=>{"nickname"=>"Max"}}]}}]

[rmosolgo]

Ohhh, interesting. I guess it's because the promise created by .then is actually executed at graphql-batch's discretion. It probably runs that promise while running the one for the previous field, which would be before the Execution::Lazy which contains the promise is executed. So, GraphQL-Ruby has no chance of updating context in that case -- control flow is in the hands of graphql-batch instead.

As a work-around, you might have to capture context[:current_path] outside the promise and somehow pass it in (using lexical scope) to the code inside it.

Otherwise, I'm not sure how GraphQL-Ruby could inject runtime info (for other fields) into GraphQL-batch's promise resolution 😖

Although practically irrelevant, it looks like GraphQL::Dataloader "just works" in this regard. Thanks for your excellent reproduction of this issue -- when I modified it to use GraphQL::Dataloader, it outputted the expected:

Diff of replication example

 git diff --no-index original_issue.rb modified_issue.rb
diff --git a/original_issue.rb b/modified_issue.rb
index 9cf7ec80a..36f46bbde 100644
--- a/original_issue.rb
+++ b/modified_issue.rb
@@ -54,14 +54,15 @@ class Tweet < ActiveRecord::Base
 end

 module Batch
-  class RecordLoader < GraphQL::Batch::Loader
-    def initialize(model)
-      @model = model
+  class RecordSource < GraphQL::Dataloader::Source
+    def initialize(model_class)
+      @model_class = model_class
     end

-    def perform(ids)
-      @model.where(id: ids).each { |record| fulfill(record.id, record) }
-      ids.each { |id| fulfill(id, nil) unless fulfilled?(id) }
+    def fetch(ids)
+      records = @model_class.where(id: ids)
+      # return a list with `nil` for any ID that wasn't found
+      ids.map { |id| records.find { |r| r.id == id.to_i } }
     end
   end
 end
@@ -78,10 +79,9 @@ module Types
     def author
       puts "Tweet:author current_path=#{context.namespace(:interpreter)[:current_path]}"

-      Batch::RecordLoader.for(::User).load(object.author_id).then do |author|
-        puts "Tweet:author after batch current_path=#{context.namespace(:interpreter)[:current_path]}"
-        author
-      end
+      author = dataloader.with(Batch::RecordSource, ::User).load(object.author_id)
+      puts "Tweet:author after batch current_path=#{context.namespace(:interpreter)[:current_path]}"
+      author
     end
   end
 end
@@ -105,7 +105,7 @@ end

 class GraphqlSchema < GraphQL::Schema
   query Types::Query
-  use GraphQL::Batch
+  use GraphQL::Dataloader
 end

 Tweet.delete_all

[DmitryTsepelev]

Yeah, I don't see any clear way to update the context inside the promise block. Closing the issue, thank you for the help!