Infinite recursion in model class due to overwritten alias_m

arkadiy · November 12, 2005, 12:49pm

Hello all!

I am having an odd problem when I run a stock model_security-generated
code in my rails environment. I get an infinite recirsion along the
lines of

#{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:in
initialize_without_callbacks' #{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:ininitialize_without_callbacks’
#{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:in
initialize_without_callbacks' #{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:ininitialize_without_callbacks’
#{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:in
initialize_without_callbacks' #{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:ininitialize_without_callbacks’
#{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:in
initialize_without_callbacks' #{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:ininitialize_without_callbacks’
#{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:in
initialize_without_callbacks' #{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:ininitialize_without_callbacks’
#{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:in
initialize_without_callbacks' #{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:ininitialize_without_callbacks’
#{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:in
initialize' #{RAILS_ROOT}/app/models/user.rb:38:ininitialize’
#{RAILS_ROOT}/app/controllers/user_controller.rb:193:in new' #{RAILS_ROOT}/app/controllers/user_controller.rb:193:inlogin’
<<<<<<<<<<<<<<<<<<<

I traced the problem back to two lines in
activerecord-1.12.2/lib/active_record/callbacks.rb :

    alias_method :initialize_without_callbacks, :initialize
    alias_method :initialize, :initialize_with_callbacks

<<<<<<<<<

Those lines are executed twice. The second time around, the original
value stored in initialize_without_callbacks is overwritten by the new
value of initialize, hence infinite recursion.

Here are the call stacks for first and second calls:

First call:

Passing through alias_method
cluster:/usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:177:in
class_eval' /usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:177:inclass_eval’
/usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:177:in
append_features' /usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record.rb:56:ininclude’
/usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record.rb:56
/usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record.rb:53:in
class_eval' /usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record.rb:53:inclass_eval’
/usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record.rb:53
/usr/lib/ruby/gems/1.8/gems/activesupport-1.2.2/lib/active_support/dependencies.rb:206:in
load' /usr/lib/ruby/gems/1.8/gems/activesupport-1.2.2/lib/active_support/dependencies.rb:206:inload’
/usr/lib/ruby/gems/1.8/gems/activesupport-1.2.2/lib/active_support/dependencies.rb:38:in
require_or_load' /usr/lib/ruby/gems/1.8/gems/activesupport-1.2.2/lib/active_support/dependencies.rb:21:independ_on’
/usr/lib/ruby/gems/1.8/gems/activesupport-1.2.2/lib/active_support/dependencies.rb:177:in
require_dependency' /usr/lib/ruby/gems/1.8/gems/activesupport-1.2.2/lib/active_support/dependencies.rb:177:inrequire_dependency’
/usr/lib/ruby/gems/1.8/gems/activesupport-1.2.2/lib/active_support/dependencies.rb:192:in
const_missing' /usr/lib/ruby/gems/1.8/gems/actionpack-1.10.2/lib/action_controller/caching.rb:517 /usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:5:inrequire__’
/usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:5:in require' /usr/lib/ruby/gems/1.8/gems/activesupport-1.2.2/lib/active_support/dependencies.rb:213:inrequire’
/usr/lib/ruby/gems/1.8/gems/actionpack-1.10.2/lib/action_controller.rb:50
/usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:5:in
require__' /usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:5:inrequire’
/usr/local/lib/site_ruby/1.8/rubygems.rb:127:in activate' /usr/local/lib/site_ruby/1.8/rubygems.rb:135:inactivate’
/usr/local/lib/site_ruby/1.8/rubygems.rb:134:in each' /usr/local/lib/site_ruby/1.8/rubygems.rb:134:inactivate’
/usr/local/lib/site_ruby/1.8/rubygems.rb:135:in activate' /usr/local/lib/site_ruby/1.8/rubygems.rb:134:ineach’
/usr/local/lib/site_ruby/1.8/rubygems.rb:134:in activate' /usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:73:insearch_gempath’
/usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:71:in each' /usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:71:insearch_gempath’
/usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:4:in require' ./script/../config/boot.rb:14 script/server:2:inrequire’
script/server:2
<<<<<<<<<<<<<<<<

Second call:

Passing through alias_method
cluster:/usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:177:in
class_eval' /usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:177:inclass_eval’
/usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:177:in
append_features' /usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record.rb:56:ininclude’
/usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record.rb:56
/usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record.rb:53:in
class_eval' /usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record.rb:53:inclass_eval’
/usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record.rb:53
/usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:5:in
require__' /usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:5:inrequire’
/usr/lib/ruby/gems/1.8/gems/activesupport-1.2.2/lib/active_support/dependencies.rb:213:in
require' /usr/local/lib/site_ruby/1.8/rubygems.rb:127:inactivate’
/usr/local/lib/site_ruby/1.8/rubygems.rb:135:in activate' /usr/local/lib/site_ruby/1.8/rubygems.rb:134:ineach’
/usr/local/lib/site_ruby/1.8/rubygems.rb:134:in activate' /usr/local/lib/site_ruby/1.8/rubygems.rb:135:inactivate’
/usr/local/lib/site_ruby/1.8/rubygems.rb:134:in each' /usr/local/lib/site_ruby/1.8/rubygems.rb:134:inactivate’
/usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:73:in
search_gempath' /usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:71:ineach’
/usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:71:in
search_gempath' /usr/local/lib/site_ruby/1.8/rubygems/loadpath_manager.rb:4:inrequire’
./script/…/config/boot.rb:14
script/server:2:in `require’
script/server:2
<<<<<<<<<<<<<<<<<<<<<<<<<<

At this point, my (tiny) knowledge of Ruby inner workings is obviously
insufficient. So I ask the List: can anybody explain what’s going on,
and how to fix it?

The problem only occurs in dev environment, under script/server, never
under Apache/fcgi/production.

Sincerely -
Arkadiy

P.S. If you happen to answer, please CC to my private e-mail, I am not
subscribed to the list yet…

arkadiy · November 12, 2005, 12:49pm

Arkadiy B. <arkadiy@…> writes:

Hello all!

I am having an odd problem when I run a stock model_security-generated
code in my rails environment. I get an infinite recirsion along the lines of

Sincerely -
Arkadiy

P.S. If you happen to answer, please CC to my private e-mail, I am not
subscribed to the list yet…

While researching the infinite recursino problem, I ended up putting the
following output operator right after def initialize in
activerecord-1.12.2/lib/active_record/base.rb:

  def initialize(attributes = nil)
    @attributes = attributes_from_column_definition
    @new_record = true
    ensure_proper_type
    self.attributes = attributes unless attributes.nil?
    yield self if block_given?
  end

  print("ActiveRecord::Base::initialize UNdefined \n") if

!method_defined?(:initialize);
<<<<<<<<<<<<<<

Imagine my surprize when I actually got the output?

I can’t explain this situation to myself. Can someone help me here?

arkadiy · November 12, 2005, 12:49pm

This is just a SWAG but if you have “Agile Web Dev w/ Rails” turn to the
top half of
page 363 (3rd printing, September) where it discusses an infinite
recursion trap.

http://www.pragmaticprogrammer.com/titles/rails/

arkadiy · November 12, 2005, 12:49pm

Arkadiy B. <arkadiy@…> writes:

> self.attributes = attributes unless attributes.nil? > yield self if block_given? > end > > print("ActiveRecord::Base::initialize UNdefined \n") if > !method_defined?(:initialize); > <<<<<<<<<<<<< > Imagine my surprize when I actually got the output? > > I can't explain this situation to myself. Can someone help me here?

And I found my answer:

#method_defined? work with public and protected methods - from a post
on comp.lang.ruby

Taking that answer into account, I wonder if the following patch would
be
acceptable:

To replace line 184 and 185 in
activerecord-1.12.2/lib/active_record/callbacks.rb with

    if (!method_defined?(:initialize_without_callbacks) && \
        private_instance_methods(true).include?("initialize"))
      alias_method :initialize_without_callbacks, :initialize
      alias_method :initialize, :initialize_with_callbacks
    end

<<<<<<<<<<<<<<<

I’ll leave it to the learned community here to decide if the rest of
aliasing in
callbacks.rb needs to be treated this way

Sincerely -

Arkadiy

arkadiy · November 12, 2005, 12:49pm

Cuong T. <cuong.tran@…> writes:

You should first try to make sure you have the latest version before
offering any fixes.

Well, what do you know, there is 1.13 now, released yesterday!

Updating my gems now.

arkadiy · November 12, 2005, 12:49pm

You should first try to make sure you have the latest version before
offering any fixes.

On 11/8/05, Arkadiy B. [email protected] wrote:

Hello all!

I am having an odd problem when I run a stock model_security-generated
code in my rails environment. I get an infinite recirsion along the lines of

#{RAILS_ROOT}usr/lib/ruby/gems/1.8/gems/activerecord-1.12.2/lib/active_record/callbacks.rb:240:in
`initialize_without_callbacks’

… truncated…

arkadiy · November 12, 2005, 12:49pm

Arkadiy B. <arkadiy@…> writes:

You should first try to make sure you have the latest version before
offering any fixes.

Updating my gems now.

Same problems… The code looks the same, too.

arkadiy · November 12, 2005, 12:49pm

OK, this is perfectly ridiculous.

The aliases in collbacks.rb are not the only ones that get messed up.
Now
similar code in validations.rb is getting triggered. I must figure out
why the
code is executed twice.

arkadiy · November 12, 2005, 12:49pm

Arkadiy B. <arkadiy@…> writes:

Updating my gems now.

Nope, same coe in callbacks.rb, same result.

Back to my questions: is my suggestion any good? Why is the code run
twice in
the first place???

arkadiy · November 12, 2005, 12:49pm

Yes, that’s core ActiveRecord code. Let’s see your model code that’s
causing the issue.

–
rick
http://techno-weenie.net

arkadiy · November 12, 2005, 12:49pm

Rick O. <technoweenie@…> writes:

Yes, that’s core ActiveRecord code. Let’s see your model code that’s
causing the issue.

Please see another post I made. I think the problem is caused by
ActionPack
triggering the loading of ActiveRecord w/o declaring that it’s dependent
on it.

arkadiy · November 12, 2005, 12:49pm

I’ve figured out why ActiveRecord is loaded twice.

The problem is in a very different are of code.

ActionPack contains the following line

if defined? ActiveRecord::Observer

at around line 517

It seems that when Ruby sees this line, it ends up calling
const_missing, which
in turn triggers the first loading of ActiveRecord. Then the regular
rubgems
code loads ActiveRecord the second time.

I think we need to either add ActiveRecord to dependencies of ActionPack
(I
don’t know if that will cause any circular dependencies) or remove the
mention
of ActiveRecord::Observer by replacing the line above with

if Module.constants().include?(“ActiveRecord”) &&
ActiveRecord.const_defined?(:Observer)

(or something better with same effect)

How about this patch suggestion?

arkadiy · November 12, 2005, 12:49pm

On 11/8/05, Arkadiy B. [email protected] wrote:

Rick O. <technoweenie@…> writes:

Yes, that’s core ActiveRecord code. Let’s see your model code that’s
causing the issue.

Please see another post I made. I think the problem is caused by ActionPack
triggering the loading of ActiveRecord w/o declaring that it’s dependent on it.

If this was the case, it’d be happening to everyone else.

–
rick
http://techno-weenie.net

arkadiy · November 12, 2005, 12:49pm

Rick O. <technoweenie@…> writes:

Please see another post I made. I think the problem is caused by ActionPack
triggering the loading of ActiveRecord w/o declaring that it’s dependent
on it.

If this was the case, it’d be happening to everyone else.

Here is how I reproduce the problem.

rails sample
cd sample
scrip/generate model_security -
mv
app/controllers/ADD_TO_APPLICATION_CONTROLLER.ModelSecurity
app/controllers/application.rb
script/server

In the browser, go to 127.0.0.1:3000/user/list

Booom!

Another piece of information: if I add

require_gem ‘activerecord’

before

require ‘initializer’

in my boot.rb, the problem goes away. I think that code loads active
record first, so that when actionpack comes around, define? does not
trigger the load of ActiveRecord because ActiveRecord::Observer is
not a missing constant any more.

arkadiy · November 12, 2005, 12:49pm

Rick O. <technoweenie@…> writes:

Rick O. <technoweenie …> writes:
Please see another post I made. I think the problem is caused by ActionPack
triggering the loading of ActiveRecord w/o declaring that it’s dependent on
it.

If this was the case, it’d be happening to everyone else.

Well, I don’t get it either…

The problem is triggered by the code generated by
model_security_generator. Can
somebody whose Rails actually works check it out for me? Is “defined?”
on a
class name supposed to load that class? Or is it a bug in my version of
Ruby? I
have

$ ruby -v
ruby 1.8.2 (2005-04-11) [i386-linux]
<<<<<<<<<<<<<<

It’s a stock Debian package for Ruby, AFAIK.