graphql-batch icon indicating copy to clipboard operation
graphql-batch copied to clipboard

Bullet throws "avoid eager loading" when using AssociationLoader

Open gopeter opened this issue 6 years ago • 2 comments

I don't know if this is a bug or just a dumb question, but let me explain it 😄

Starting with this simple type:

class Types::ProjectType < Types::BaseNode
  graphql_name 'Project'

  field :title, String, null: false
  field :milestones, Types::MilestoneType.connection_type, null: false

  def milestones
    object.milestones
  end
end

And running this query:

query {
  projects(perPage: 10) {
    edges {
      node {
        title
        milestones {
          edges {
            node {
              title
            }
          }
        }
      }
    }
  }
}

Returns the desired result, but leads to this:

  Milestone Load (0.9ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 1]]
  Milestone Load (0.5ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 2]]
  Milestone Load (0.7ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 3]]
  Milestone Load (0.6ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 4]]
  Milestone Load (0.6ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 5]]
  Milestone Load (0.7ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 6]]
  Milestone Load (0.5ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 7]]
  Milestone Load (0.5ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 8]]
  Milestone Load (0.8ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 9]]
  Milestone Load (0.8ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 10]]

So I thought it would be good to use the AssociationLoader to eager load the milestones using this:

def milestones
  Loaders::AssociationLoader.for(Project, :milestones).load(object)
end

But this ends up in this:

  Milestone Load (0.7ms)  SELECT "milestones".* FROM "milestones" WHERE "milestones"."project_id" IN ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10)  [["project_id", 1], ["project_id", 2], ["project_id", 3], ["project_id", 4], ["project_id", 5], ["project_id", 6], ["project_id", 7], ["project_id", 8], ["project_id", 9], ["project_id", 10]]
  Milestone Load (0.5ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 1]]
  Milestone Load (0.5ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 2]]
  Milestone Load (0.4ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 3]]
  Milestone Load (0.7ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 4]]
  Milestone Load (0.5ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 5]]
  Milestone Load (0.5ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 6]]
  Milestone Load (1.0ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 7]]
  Milestone Load (0.5ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 8]]
  Milestone Load (0.5ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 9]]
  Milestone Load (0.6ms)  SELECT milestones.*, milestones.id AS cursor_0 FROM "milestones" WHERE "milestones"."project_id" = $1 ORDER BY milestones.id asc  [["project_id", 10]]
Completed 200 OK in 497ms (Views: 0.4ms | ActiveRecord: 34.6ms)


user: peter_goebel
POST /graphql
AVOID eager loading detected
  Project => [:milestones]
  Remove from your finder: :includes => [:milestones]
Call stack

Why are all milestones still queried individually even with eager loading/preloading?

gopeter avatar May 21 '19 13:05 gopeter

I just had a look at other usages of this gem and found an interesting approach: https://github.com/annict/annict/blob/master/app/graphql/foreign_key_loader.rb

Eager loading works fine using this loader:

Loaders::ForeignKeyLoader.for(Milestone, :project_id).load([object.id])

results in

  Milestone Load (41.3ms)  SELECT "milestones".* FROM "milestones" WHERE "milestones"."project_id" IN ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10)  [["project_id", 1], ["project_id", 2], ["project_id", 3], ["project_id", 4], ["project_id", 5], ["project_id", 6], ["project_id", 7], ["project_id", 8], ["project_id", 9], ["project_id", 10]]
Completed 200 OK in 401ms (Views: 1.2ms | ActiveRecord: 70.7ms)

gopeter avatar May 21 '19 21:05 gopeter

Is Loaders::AssociationLoader the same as the example AssociationLoader? Or could it be a bug in your association loader?

Are you seeing the N+1 queries in the log even without the bullet gem? Or could this be a false positive from the bullet gem?

dylanahsmith avatar Apr 14 '20 19:04 dylanahsmith