Rails Ruby on Rails → 3.0.2

Comments and changes to this ticket

• 

  Rohit Arondekar July 9th, 2010 @ 02:46 AM

  • Milestone cleared.
  • State changed from “new” to “open”
  • Tag set to “rails 3, activerecord, loaderror, observer”
  • Importance changed from “” to “Low”

  Confirmed on Rails master on 1.9.2-RC1 too.

• 

  Rohit Arondekar July 9th, 2010 @ 03:09 AM

  This is a strange bug.

  I added the following just before the exception is raised in activesupport/lib/active_support/dependencies.rb : 465

    puts "For #{const_name}"
    puts "#{file_path}"
    puts "Loaded #{const_name}" if local_const_defined?(from_mod, const_name)
    puts "END"
  

  I get the following output in the console (truncated for clarity):

  First Try:

  ruby-1.9.2-rc1 > Bar
  For BarObserver
  /home/rohit/bugmash/newapp/app/models/bar_observer.rb
  Loaded BarObserver
  END
  For Bar
  /home/rohit/bugmash/newapp/app/models/bar.rb
  END
  LoadError: Expected /home/rohit/bugmash/newapp/app/models/bar.rb to define Bar
  

  Second Try:

  ruby-1.9.2-rc1 > Bar
  For Bar
  /home/rohit/bugmash/newapp/app/models/bar.rb
  Loaded Bar
  END
   => Bar(id: integer, created_at: datetime, updated_at: datetime)
  

  So there must be something going on in require_or_load method. Could it be that it thinks Bar is already loaded because of BarObserver? Will take a look later but I thought I should put what I found in here, in case somebody else wants to take a crack at it.

• 

  Rohit Arondekar July 9th, 2010 @ 11:02 AM

  • Assigned user set to “José Valim”
• 

  José Valim July 9th, 2010 @ 11:08 AM

  Rohit put a puts caller at the beginning of load_missing_constant error and it returned this: http://pastie.org/1037235

  By looking at this caller stack trace, is easier to grasp what is going on:

  1) When you invoke Bar, it will trigger load_missing_constant(Bar);

  2) Once Bar file is loaded, it will find and load ActiveRecord::Base, triggering a few hooks;

  3) One of these ActiveRecord hooks is called instantiate_observer and it will cause BarObserver to be loaded through load_missing_constant(BarObserver);

  4) BarObserver is then loaded and it will try to apply its hooks to the Bar class. We already asked Bar class to be loaded, but it hasn't happened yet, because we started to load ActiveRecord::Base, which loaded BarObserver which wants to load Bar once again. What happens at this point, is that Bar is loaded again by AS::Dependencies, causing for us to have two Bar references, but one of them is obviously invalid;

  I'm not sure what is the proper fix here. By doing things lazy is stepping on our toes once again. :(

• 

  José Valim July 9th, 2010 @ 11:15 AM

  The issue could be easily avoided by forcing ActiveRecord::Base to be loaded before loading Bar:

  irb > ActiveRecord::Base
  irb > Bar.create #=> works

• 

  Xavier Noria July 9th, 2010 @ 12:54 PM

  A minimal example that depicts the circularity involved:

  fxn@rails:~/tmp/h$ cat app/models/foo.rb
  class Foo < Bar
  end
  
  fxn@rails:~/tmp/h$ cat app/models/bar.rb 
  class Bar
  end
  
  Foo
  
  fxn@rails:~/tmp/h$ script/rails runner Foo
  /home/fxn/rails/railties/lib/rails/commands/runner.rb:50: /home/fxn/rails/activesupport/lib/active_support/dependencies.rb:465:in `load_missing_constant': Expected /home/fxn/tmp/h/app/models/foo.rb to define Foo (LoadError)
  

• 

  Xavier Noria July 9th, 2010 @ 01:29 PM

  The issue is not a deadlock, that would work in MRI, but it implies two executions of foo.rb:

  halmos:tmp fxn$ cat test_const_missing.rb
  def Object.const_missing(name)
    case name.to_s
    when 'Foo'
      load 'foo.rb'
      Foo
    when 'Bar'
      load 'bar.rb'
      Bar
    end
  end
  
  Foo
  halmos:tmp fxn$ cat foo.rb
  puts "in foo.rb"
  class Foo < Bar
    puts "defining Foo"
  end
  
  halmos:tmp fxn$ cat bar.rb 
  puts "in bar.rb"
  class Bar
    puts "defining Bar"
  end
  
  Foo
  
  halmos:tmp fxn$ ruby test_const_missing.rb 
  in foo.rb
  in bar.rb
  defining Bar
  in foo.rb
  defining Foo
  defining Foo
  

  Which is not good anyway (perhaps dependencies is complaining to prevent that issue?).

  I wonder if this justifies not lazy loading Active Record, looks like this loop is unsolvable.

• 

  José Valim July 18th, 2010 @ 10:04 AM

  • State changed from “open” to “resolved”

  Fixed here: http://github.com/rails/rails/commit/fa98eca75bd8666719bf3d061c8763...

• 

  Jeremy Kemper October 15th, 2010 @ 11:01 PM

  • Milestone set to “3.0.2”

  [bulk edit]