salsify/goldiloader

Getting nomethoderror 'each' on NilClass after adding this gem

Closed this issue · 21 comments

This gem looks like it would really simplify my performance hunt. But after adding it I am getting in a number of places NoMethodError 'each' on NilClass. Here is one code #sample:

  def compatible_persons(tenant = nil)
    # all active persons with same email address
    candidates = persons
    # if tenant provided - subset to just those in that tenant
    candidates = candidates.select { |person| person.tenant_id.equal?(tenant.id) } if tenant
    # if SP person and no persons with SP person email on list, then use SP persons master
    candidates = [master] if !candidates.any? && schellingpoint_person?
    candidates
  end

I get errors on the .select line, and was getting errors on the candidates.any? line which was candidates.blank? before I changed it to !candidates.any?. I tried candidates.none? and that still elicited the error.

I should add am running Rails 4.2.4 on Ruby 2.2.4.

Without the gem installed this worked fine, and after removing it, it works as expected. I had to remove the gem, but would be willing to help if I got some guidance on what to look for.

What is the full stack trace of the exception?

activerecord (4.2.4) lib/active_record/associations/preloader/association.rb, line 93
ActiveRecord::Associations::Preloader::HasMany#associated_records_by_owner  activerecord (4.2.4) lib/active_record/associations/preloader/association.rb, line 92
ActiveRecord::Associations::Preloader::HasMany#preload  activerecord (4.2.4) lib/active_record/associations/preloader/collection_association.rb, line 13
ActiveRecord::Associations::Preloader::HasMany#run  activerecord (4.2.4) lib/active_record/associations/preloader/association.rb, line 20
block (2 levels) in ActiveRecord::Associations::Preloader#preloaders_for_one  activerecord (4.2.4) lib/active_record/associations/preloader.rb, line 146
block in ActiveRecord::Associations::Preloader#preloaders_for_one  activerecord (4.2.4) lib/active_record/associations/preloader.rb, line 144
ActiveRecord::Associations::Preloader#preloaders_for_one  activerecord (4.2.4) lib/active_record/associations/preloader.rb, line 143
ActiveRecord::Associations::Preloader#preloaders_on  activerecord (4.2.4) lib/active_record/associations/preloader.rb, line 115
block in ActiveRecord::Associations::Preloader#preload  activerecord (4.2.4) lib/active_record/associations/preloader.rb, line 103
ActiveRecord::Associations::Preloader#preload  activerecord (4.2.4) lib/active_record/associations/preloader.rb, line 102
Goldiloader::AssociationLoader.eager_load  goldiloader (0.0.10) lib/goldiloader/association_loader.rb, line 25
Goldiloader::AssociationLoader.load  goldiloader (0.0.10) lib/goldiloader/association_loader.rb, line 12
ActiveRecord::Associations::HasManyAssociation#load_with_auto_include  goldiloader (0.0.10) lib/goldiloader/active_record_patches.rb, line 76
ActiveRecord::Associations::HasManyAssociation#load_target_with_auto_include  goldiloader (0.0.10) lib/goldiloader/active_record_patches.rb, line 114
ActiveRecord::Associations::HasManyAssociation#select  activerecord (4.2.4) lib/active_record/associations/collection_association.rb, line 77
Person::ActiveRecord_Associations_CollectionProxy#select  activerecord (4.2.4) lib/active_record/associations/collection_proxy.rb, line 111
User#compatible_persons  app/models/internal/user.rb, line 73
User#current_active_client=  app/models/internal/user.rb, line 101
PersonsController#establish_context  app/controllers/application_controller.rb, line 102
block in ActiveSupport::Callbacks::Callback#make_lambda  activesupport (4.2.4) lib/active_support/callbacks.rb, line 432
block in ActiveSupport::Callbacks::Filters::Around.halting_and_conditional  activesupport (4.2.4) lib/active_support/callbacks.rb, line 291
block in ActiveSupport::Callbacks::CallbackSequence#around  activesupport (4.2.4) lib/active_support/callbacks.rb, line 497
ActiveSupport::Callbacks::CallbackSequence#call  activesupport (4.2.4) lib/active_support/callbacks.rb, line 505
PersonsController#__run_callbacks__  activesupport (4.2.4) lib/active_support/callbacks.rb, line 92
PersonsController#_run_process_action_callbacks  activesupport (4.2.4) lib/active_support/callbacks.rb, line 778
PersonsController#run_callbacks  activesupport (4.2.4) lib/active_support/callbacks.rb, line 81
PersonsController#process_action  actionpack (4.2.4) lib/abstract_controller/callbacks.rb, line 19
PersonsController#process_action  actionpack (4.2.4) lib/action_controller/metal/rescue.rb, line 29
block in PersonsController#process_action  actionpack (4.2.4) lib/action_controller/metal/instrumentation.rb, line 32
block in ActiveSupport::Notifications.instrument  activesupport (4.2.4) lib/active_support/notifications.rb, line 164
ActiveSupport::Notifications::Instrumenter#instrument  activesupport (4.2.4) lib/active_support/notifications/instrumenter.rb, line 20
ActiveSupport::Notifications.instrument  activesupport (4.2.4) lib/active_support/notifications.rb, line 164
PersonsController#process_action  actionpack (4.2.4) lib/action_controller/metal/instrumentation.rb, line 30
PersonsController#process_action  actionpack (4.2.4) lib/action_controller/metal/params_wrapper.rb, line 250
PersonsController#process_action  activerecord (4.2.4) lib/active_record/railties/controller_runtime.rb, line 18
PersonsController#process  actionpack (4.2.4) lib/abstract_controller/base.rb, line 137
PersonsController#process  actionview (4.2.4) lib/action_view/rendering.rb, line 30
PersonsController#dispatch  actionpack (4.2.4) lib/action_controller/metal.rb, line 196
PersonsController#dispatch  actionpack (4.2.4) lib/action_controller/metal/rack_delegation.rb, line 13
block in PersonsController.action  actionpack (4.2.4) lib/action_controller/metal.rb, line 237
ActionDispatch::Routing::RouteSet::Dispatcher#dispatch  actionpack (4.2.4) lib/action_dispatch/routing/route_set.rb, line 76
ActionDispatch::Routing::RouteSet::Dispatcher#serve  actionpack (4.2.4) lib/action_dispatch/routing/route_set.rb, line 45
block in ActionDispatch::Journey::Router#serve  actionpack (4.2.4) lib/action_dispatch/journey/router.rb, line 43
ActionDispatch::Journey::Router#serve  actionpack (4.2.4) lib/action_dispatch/journey/router.rb, line 30
ActionDispatch::Routing::RouteSet#call  actionpack (4.2.4) lib/action_dispatch/routing/route_set.rb, line 821
MetaRequest::Middlewares::AppRequestHandler#call  meta_request (0.4.0) lib/meta_request/middlewares/app_request_handler.rb, line 13
MetaRequest::Middlewares::MetaRequestHandler#call  meta_request (0.4.0) lib/meta_request/middlewares/meta_request_handler.rb, line 13
block in Warden::Manager#call  warden (1.2.6) lib/warden/manager.rb, line 35
Warden::Manager#call  warden (1.2.6) lib/warden/manager.rb, line 34
Rack::ETag#call  rack (1.6.4) lib/rack/etag.rb, line 24
Rack::ConditionalGet#call  rack (1.6.4) lib/rack/conditionalget.rb, line 25
Rack::Head#call  rack (1.6.4) lib/rack/head.rb, line 13
ActionDispatch::ParamsParser#call  actionpack (4.2.4) lib/action_dispatch/middleware/params_parser.rb, line 27
ActionDispatch::Flash#call  actionpack (4.2.4) lib/action_dispatch/middleware/flash.rb, line 260
ActionDispatch::Session::CookieStore#context  rack (1.6.4) lib/rack/session/abstract/id.rb, line 225
ActionDispatch::Session::CookieStore#call  rack (1.6.4) lib/rack/session/abstract/id.rb, line 220
ActionDispatch::Cookies#call  actionpack (4.2.4) lib/action_dispatch/middleware/cookies.rb, line 560
ActiveRecord::QueryCache#call  activerecord (4.2.4) lib/active_record/query_cache.rb, line 36
ActiveRecord::ConnectionAdapters::ConnectionManagement#call  activerecord (4.2.4) lib/active_record/connection_adapters/abstract/connection_pool.rb, line 653
block in ActionDispatch::Callbacks#call  actionpack (4.2.4) lib/action_dispatch/middleware/callbacks.rb, line 29
ActiveSupport::Callbacks::Filters::End#call  activesupport (4.2.4) lib/active_support/callbacks.rb, line 117
block (2 levels) in ActiveSupport::Callbacks::CallbackChain#compile  activesupport (4.2.4) lib/active_support/callbacks.rb, line 555
ActiveSupport::Callbacks::CallbackSequence#call  activesupport (4.2.4) lib/active_support/callbacks.rb, line 505
ActionDispatch::Callbacks#__run_callbacks__  activesupport (4.2.4) lib/active_support/callbacks.rb, line 92
ActionDispatch::Callbacks#_run_call_callbacks  activesupport (4.2.4) lib/active_support/callbacks.rb, line 778
ActionDispatch::Callbacks#run_callbacks  activesupport (4.2.4) lib/active_support/callbacks.rb, line 81
ActionDispatch::Callbacks#call  actionpack (4.2.4) lib/action_dispatch/middleware/callbacks.rb, line 27
ActionDispatch::Reloader#call  actionpack (4.2.4) lib/action_dispatch/middleware/reloader.rb, line 73
ActionDispatch::RemoteIp#call  actionpack (4.2.4) lib/action_dispatch/middleware/remote_ip.rb, line 78
BetterErrors::Middleware#protected_app_call  better_errors (2.1.1) lib/better_errors/middleware.rb, line 84
BetterErrors::Middleware#better_errors_call  better_errors (2.1.1) lib/better_errors/middleware.rb, line 79
BetterErrors::Middleware#call  better_errors (2.1.1) lib/better_errors/middleware.rb, line 57
ActionDispatch::DebugExceptions#call  actionpack (4.2.4) lib/action_dispatch/middleware/debug_exceptions.rb, line 17
Rack::ResponseHeaders#call  rack-contrib (1.4.0) lib/rack/contrib/response_headers.rb, line 17
MetaRequest::Middlewares::Headers#call  meta_request (0.4.0) lib/meta_request/middlewares/headers.rb, line 16
ActionDispatch::ShowExceptions#call  actionpack (4.2.4) lib/action_dispatch/middleware/show_exceptions.rb, line 30
Rails::Rack::Logger#call_app  railties (4.2.4) lib/rails/rack/logger.rb, line 38
block in Rails::Rack::Logger#call  railties (4.2.4) lib/rails/rack/logger.rb, line 20
block in ActiveSupport::Logger#tagged  activesupport (4.2.4) lib/active_support/tagged_logging.rb, line 68
ActiveSupport::Logger::SimpleFormatter#tagged  activesupport (4.2.4) lib/active_support/tagged_logging.rb, line 26
ActiveSupport::Logger#tagged  activesupport (4.2.4) lib/active_support/tagged_logging.rb, line 68
Rails::Rack::Logger#call  railties (4.2.4) lib/rails/rack/logger.rb, line 20
RequestStore::Middleware#call  request_store (1.3.0) lib/request_store/middleware.rb, line 9
ActionDispatch::RequestId#call  actionpack (4.2.4) lib/action_dispatch/middleware/request_id.rb, line 21
Rack::MethodOverride#call  rack (1.6.4) lib/rack/methodoverride.rb, line 22
Rack::Runtime#call  rack (1.6.4) lib/rack/runtime.rb, line 18
ActiveSupport::Cache::Strategy::LocalCache::Middleware#call  activesupport (4.2.4) lib/active_support/cache/strategy/local_cache_middleware.rb, line 28
Rack::Lock#call  rack (1.6.4) lib/rack/lock.rb, line 17
ActionDispatch::Static#call  actionpack (4.2.4) lib/action_dispatch/middleware/static.rb, line 116
Rack::Sendfile#call  rack (1.6.4) lib/rack/sendfile.rb, line 113
block in Honeybadger::Rack::ErrorNotifier#call  honeybadger (2.5.0) lib/honeybadger/rack/error_notifier.rb, line 33
Honeybadger::Config#with_request  honeybadger (2.5.0) lib/honeybadger/config.rb, line 198
Honeybadger::Rack::ErrorNotifier#call  honeybadger (2.5.0) lib/honeybadger/rack/error_notifier.rb, line 30
Honeybadger::Rack::UserFeedback#call  honeybadger (2.5.0) lib/honeybadger/rack/user_feedback.rb, line 28
Honeybadger::Rack::UserInformer#call  honeybadger (2.5.0) lib/honeybadger/rack/user_informer.rb, line 18
Aot::Application#call  railties (4.2.4) lib/rails/engine.rb, line 518
Aot::Application#call  railties (4.2.4) lib/rails/application.rb, line 165
Rack::ContentLength#call  rack (1.6.4) lib/rack/content_length.rb, line 15
block in Thin::Connection#pre_process  thin (1.6.4) lib/thin/connection.rb, line 86
Thin::Connection#pre_process  thin (1.6.4) lib/thin/connection.rb, line 84
Thin::Connection#process  thin (1.6.4) lib/thin/connection.rb, line 53
Thin::Connection#receive_data  thin (1.6.4) lib/thin/connection.rb, line 39
EventMachine.run  eventmachine (1.0.9.1) lib/eventmachine.rb, line 193
Thin::Backends::TcpServer#start  thin (1.6.4) lib/thin/backends/base.rb, line 73
Thin::Server#start  thin (1.6.4) lib/thin/server.rb, line 162
Rack::Handler::Thin.run  rack (1.6.4) lib/rack/handler/thin.rb, line 19
Rails::Server#start  rack (1.6.4) lib/rack/server.rb, line 286
Rails::Server#start  railties (4.2.4) lib/rails/commands/server.rb, line 80
block in Rails::CommandsTasks#server  railties (4.2.4) lib/rails/commands/commands_tasks.rb, line 80
Rails::CommandsTasks#server  railties (4.2.4) lib/rails/commands/commands_tasks.rb, line 75
Rails::CommandsTasks#run_command!  railties (4.2.4) lib/rails/commands/commands_tasks.rb, line 39
<top (required)>  railties (4.2.4) lib/rails/commands.rb, line 17
<main>  

Line #73 is the .select line.

BTW goldiloader. Nice name.

Hah. I have to give credit to @mattcross for the name.

I can't reproduce the issue. A few questions:

  1. If you remove the goldiloader gem, do you still see the problem if you load the association via Rails eager loading (i.e. something like User.includes(:persons).find(...))
  2. Can you try modifying this gist to reproduce the bug? (See the ActiveRecord contribution guide for details on how to run it)

I need to step away but will do what you request and post results ASAP. Thanks for looking at it.

Here is results to reproduce #1:

User.includes(:persons).find_by(email: 'tchambers@schellingpoint.com')
  User Load (0.4ms)  SELECT  `users`.* FROM `users` WHERE `users`.`email` = 'tchambers@schellingpoint.com' LIMIT 1
    1 rows, 488 bytes

  Person Load (0.5ms)  SELECT `persons`.* FROM `persons` WHERE `persons`.`active` = 1 AND (exists(select 1 from collectives c
      where c.active = 1 and c.id = persons.tenant_id)) AND `persons`.`email` IN ('tChambers@Schellingpoint.com')  ORDER BY `persons`.`name` ASC, `persons`.`id` ASC
    9 rows, 2927 bytes

NoMethodError: undefined method `each' for nil:NilClass
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader/association.rb:93:in `block in associated_records_by_owner'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader/association.rb:92:in `each'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader/association.rb:92:in `associated_records_by_owner'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader/collection_association.rb:13:in `preload'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader/association.rb:20:in `run'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader.rb:146:in `block (2 levels) in preloaders_for_one'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader.rb:144:in `each'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader.rb:144:in `map'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader.rb:144:in `block in preloaders_for_one'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader.rb:143:in `each'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader.rb:143:in `flat_map'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader.rb:143:in `preloaders_for_one'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader.rb:115:in `preloaders_on'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader.rb:103:in `block in preload'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader.rb:102:in `each'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/associations/preloader.rb:102:in `flat_map'
... 1 levels...
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/relation.rb:645:in `block in exec_queries'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/relation.rb:644:in `each'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/relation.rb:644:in `exec_queries'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/relation.rb:515:in `load'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/relation.rb:243:in `to_a'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/relation/finder_methods.rb:475:in `find_take'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/relation/finder_methods.rb:105:in `take'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/activerecord-4.2.4/lib/active_record/relation/finder_methods.rb:84:in `find_by'
    from (irb):9
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/railties-4.2.4/lib/rails/commands/console.rb:110:in `start'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/railties-4.2.4/lib/rails/commands/console.rb:9:in `start'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/railties-4.2.4/lib/rails/commands/commands_tasks.rb:68:in `console'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/railties-4.2.4/lib/rails/commands/commands_tasks.rb:39:in `run_command!'
    from /Users/tj/.rvm/gems/ruby-2.2.4@global/gems/railties-4.2.4/lib/rails/commands.rb:17:in `<top (required)>'
    from bin/rails:4:in `require'
    from bin/rails:4:in `<main>'2.2.4 :010 >

@jturkel based on my being able to reproduce sans goldiloader, should I still use your gist? or should I use a standard active record example to reproduce in a test?

Sounds like you've either found a bug in Rails eager loading or the User#persons association is somehow configured incorrectly. It looks like you're using Person#email as the foreign key in the association. I noticed in your query log that the user has an email of "tchambers@schellingpoint.com" but the person has an email "tChambers@Schellingpoint.com" which could definitely confuse Rails. What is your association definition?

In the meantime, you can disable automatic eagerloading on the persons association with the auto_include option so you can use Goldiloader for other assocations.

It's the other way around, but I tried making them both exactly same lowercase and still get the error.

I will try the auto_include option and see if this shows elsewhere. It appears to NOT be a goldiloader issue, but one in Rails.

BTW - I am using MySQL with mysql2 so it is case-insensitive.

User association definition:

has_many :persons,
foreign_key: :email,
primary_key: :email,
class_name: Person

Person default scope:

COLLECTIVE_FILTER ||= 'exists(select 1 from collectives c
where c.active = 1 and c.id = persons.tenant_id)'.freeze

default_scope do
where(active: true).where(COLLECTIVE_FILTER).order(:name, :id)
end

Yeah. Definitely sounds like a Rails bug. Looking at where the exception is coming from Rails is failing to match up records based on the primary key/foreign key relationship in Ruby. Let me know if you hit any other issues with goldiloader.

I added the auto_include: false and it failed elsewhere on a user = @person.user - the reverse association. I tried adding the auto_include on that and it still failed. What concerned me is that my IDE, RubyMine was telling me that the primary_key :email could not be located as a method (it is an attribute on the table).

SOoo...

I tried something very unusual that has worked for me in the past.

I added a method

  def email
    super
  end

To both User and Person.

To my surprise it worked around the issue. Hmmm...

@tjchambers - I took another shot at reproducing this (and possibly automatically disabling automatic eager loading on affected associations until the rails bug is fixed) but didn't have any luck. The gist can be found here. Can you see if you can create a test case to reproduce the problem?

@jturkel THis is very close to my model but there are some default scopes involved.This is a great kickstart for me to get close with this though. Assuming this is not a mysql2 only problem this really helps. I will add enough to get it to fail. I am confident that can be done.

@jturkel after trying my best to reproduce I fell back to debugging the AR code. The problem is indeed a case-sensitivity issue. So I cannot reproduce it in SQLITE. The issue is that the person records have the email in a different case TChambers@schellingpoint.com then the query tchambers@schellingpoint.com so when it is looking at mapping the owner key, it expects to find a master record with the eager loaded email address value, and of course they don't match.

do you know of a gist template I can use to submit case-sensitive activerecord issues?

Further reading on the web leads me to infer this is a longstanding opinion of the Rails team - that they should not do case-insensitive comparisons internally. With Rails 4.2 they now support citext column type in Postgres. I do not use postgres (yet), but my inference is even though they support that type for that adapter, that you would still experience my issue above in Postgres with that column type even though they appear to be supportive of the transformation in that adapter.

I am closing this, because I feel it is a conflict between case-insensitivity in the db and the Rails hack to map master-detail associations which is case-sensitive. It is not specifically a goldiloader issue, and cannot be fixed in goldiloader.

@tjchambers - Were you able to get things working (other than #32) by disabling auto_include on the affected associations?

I have not gotten back around to it yet, I spent all my available time trying to understand this one. I suspect that #32 is a different issue as it should not involve case-sensitivity.