Lighthouse has a new layout. Prefer the old one? Return to the old layout, and switch back any time from the link at the top of each page.

This project is archived and is in readonly mode.

Dramatic rendering slowdown from 3.0.3 to 3.0.6

#6695

I am experiencing a 10x slowdown on some pages when upgrading from 3.0.3 to 3.0.6.

3.0.3: Completed 200 OK in 1332ms (Views: 1261.9ms | ActiveRecord: 61.2ms)
3.0.6: Completed 200 OK in 12668ms (Views: 12629.0ms | ActiveRecord: 25.4ms)

This is a page that renders a whole lot of partials, maybe 50-100 (one for each record). Regular pages, with a limited number of partials, seem less slow. The slowdown is apparent in both the development and production environments.

Please let me know if I should provide additional information.

Reported by stiang · April 12th, 2011 @ 11:49 AM

State: committed
Milestone: 3.0.6
Assigned to: Santiago Pastorino Santiago Pastorino
Importance: Low

Activity

  1. Santiago Pastorino
    Santiago Pastorino
    • State changed from new to open
    • Milestone set to 3.0.6
    • Assigned user set to Santiago Pastorino
    • Importance changed from to Low

    Can you check if reverting this commit https://github.com/rails/rails/commit/86acbf1cc050c8fa8c74a10c735e4... fix your issue?

    April 13th, 2011 @ 04:55 PM

  2. stiang
    stiang

    Indeed it does, Santiago, specifically the changes to activerecord/lib/active_record/attribute_methods/read.rb. Reverting those makes my app perform as it did with 3.0.3 (or even a little better, it seems).

    April 14th, 2011 @ 07:45 AM

  3. stiang
    stiang

    I’ve investigated this a bit more and come to the conclusion that rescue is extremely expensive on ruby 1.8. When I run this gist I get the following results on my machine:

    Showing results for 1000000 method calls
    
    Method IS NOT defined
    =====================
    With rescue:      10.35 seconds
    With respond_to:  0.64 seconds
    Direct call:      0.35 seconds
    
    Method IS defined
    =================
    With rescue:      0.57 seconds
    With respond_to:  0.85 seconds
    Direct call:      0.35 seconds
    

    Unless I’m misunderstanding something, it would appear that changing

    def read_attribute(attr_name)
      send "_#{attr_name}"
    rescue NoMethodError
      _read_attribute attr_name
    end
    

    in read.rb to something like

    def read_attribute(attr_name)
      if respond_to? "_#{attr_name}"
       send "_#{attr_name}"
      else
        _read_attribute attr_name
      end
    end
    

    should improve the speed dramatically when the underscore method doesn’t exist, and only add a slight penalty (the respond_to call) when it does. Any thoughts?

    April 14th, 2011 @ 02:12 PM

  4. stiang
    stiang

    I added a pull request for this change after verifying that the tests pass with it.

    (Actually, this test failed, but that appears to be wholly unrelated to my change.)

    April 14th, 2011 @ 04:00 PM

  5. Santiago Pastorino