What causes the extreme slowness when changing from rails 3.2.12 to 3.2.13

Question

This morning, I updated rails from 3.2.12 to 3.2.13, which resulted in a major delay in loading my views. This is from loading my home page:

Rails 3.2.12:
Completed 200 OK in 387ms (Views: 339.0ms | ActiveRecord: 27.1ms)

Rails 3.2.13:
Completed 200 OK in 4416ms (Views: 4361.2ms | ActiveRecord: 28.7ms)

The only difference between the two commits it the Rails version, which of course did also result in a lot of other gems being updated... This is the difference in the Gemfile.lock:

GEM
   remote: https://rubygems.org/
   specs:
-    actionmailer (3.2.12)
-      actionpack (= 3.2.12)
-      mail (~> 2.4.4)
-    actionpack (3.2.12)
-      activemodel (= 3.2.12)
-      activesupport (= 3.2.12)
+    actionmailer (3.2.13)
+      actionpack (= 3.2.13)
+      mail (~> 2.5.3)
+    actionpack (3.2.13)
+      activemodel (= 3.2.13)
+      activesupport (= 3.2.13)
       builder (~> 3.0.0)
       erubis (~> 2.7.0)
       journey (~> 1.0.4)
@@ -14,19 +14,19 @@ GEM
       rack-cache (~> 1.2)
       rack-test (~> 0.6.1)
       sprockets (~> 2.2.1)
-    activemodel (3.2.12)
-      activesupport (= 3.2.12)
+    activemodel (3.2.13)
+      activesupport (= 3.2.13)
       builder (~> 3.0.0)
-    activerecord (3.2.12)
-      activemodel (= 3.2.12)
-      activesupport (= 3.2.12)
+    activerecord (3.2.13)
+      activemodel (= 3.2.13)
+      activesupport (= 3.2.13)
       arel (~> 3.0.2)
       tzinfo (~> 0.3.29)
-    activeresource (3.2.12)
-      activemodel (= 3.2.12)
-      activesupport (= 3.2.12)
-    activesupport (3.2.12)
-      i18n (~> 0.6)
+    activeresource (3.2.13)
+      activemodel (= 3.2.13)
+      activesupport (= 3.2.13)
+    activesupport (3.2.13)
+      i18n (= 0.6.1)
       multi_json (~> 1.0)
     airbrake (3.1.7)
       activesupport
@@ -129,7 +129,7 @@ GEM
     hashr (0.0.22)
     hike (1.2.1)
     honeypot-captcha (0.0.2)
-    i18n (0.6.4)
+    i18n (0.6.1)
     journey (1.0.4)
     jquery-rails (2.2.0)
       railties (>= 3.0, < 5.0)
@@ -146,7 +146,7 @@ GEM
     kgio (2.8.0)
     listen (0.7.2)
     lumberjack (1.0.2)
-    mail (2.4.4)
+    mail (2.5.3)
       i18n (>= 0.4.0)
       mime-types (~> 1.16)
       treetop (~> 1.4.8)
@@ -155,7 +155,7 @@ GEM
     mime-types (1.21)
     mocha (0.10.5)
       metaclass (~> 0.0.1)
-    multi_json (1.6.1)
+    multi_json (1.7.1)
     mysql2 (0.3.11)
     nested_form (0.3.1)
     net-scp (1.0.4)
@@ -180,14 +180,14 @@ GEM
       rack
     rack-test (0.6.2)
       rack (>= 1.0)
-    rails (3.2.12)
-      actionmailer (= 3.2.12)
-      actionpack (= 3.2.12)
-      activerecord (= 3.2.12)
-      activeresource (= 3.2.12)
-      activesupport (= 3.2.12)
+    rails (3.2.13)
+      actionmailer (= 3.2.13)
+      actionpack (= 3.2.13)
+      activerecord (= 3.2.13)
+      activeresource (= 3.2.13)
+      activesupport (= 3.2.13)
       bundler (~> 1.0)
-      railties (= 3.2.12)
+      railties (= 3.2.13)
     rails_admin (0.4.3)
       bootstrap-sass (~> 2.2)
       builder (~> 3.0)
@@ -202,9 +202,9 @@ GEM
       rails (~> 3.1)
       remotipart (~> 1.0)
       sass-rails (~> 3.1)
-    railties (3.2.12)
-      actionpack (= 3.2.12)
-      activesupport (= 3.2.12)
+    railties (3.2.13)
+      actionpack (= 3.2.13)
+      activesupport (= 3.2.13)
       rack-ssl (~> 1.3.2)
       rake (>= 0.8.7)
       rdoc (~> 3.4)
@@ -212,7 +212,7 @@ GEM
     raindrops (0.10.0)
     rake (10.0.3)
     rb-fsevent (0.9.1)
-    rdoc (3.12.1)
+    rdoc (3.12.2)
       json (~> 1.4)
     remotipart (1.0.2)
     rest-client (1.6.7)
@@ -266,7 +266,7 @@ GEM
       eventmachine (>= 0.12.6)
       rack (>= 1.0.0)
     thor (0.17.0)
-    tilt (1.3.4)
+    tilt (1.3.6)
     tire (0.5.4)
       activemodel (>= 3.0)
       hashr (~> 0.0.19)
@@ -280,7 +280,7 @@ GEM
       actionpack (>= 3.1)
       execjs
       railties (>= 3.1)
-    tzinfo (0.3.35)
+    tzinfo (0.3.37)
     uglifier (1.3.0)
       execjs (>= 0.3.0)
       multi_json (~> 1.0, >= 1.0.2)
@@ -325,7 +325,7 @@ DEPENDENCIES
   nested_form
   newrelic_rpm (~> 3.5.5.38)
   pry
-  rails (= 3.2.12)
+  rails (= 3.2.13)
   rails_admin
   rb-fsevent (= 0.9.1)
   rmagick

Other then these two files nothing has changed.

From reading Diagnosing the cause of slow view rendering I understand that stuff in the asset pipeline can be slowing it down, but I dont see a difference when I change the value of "config.assets.debug = false" inside of development.rb.

I suppose I do have a lot of assets in my asset pipeline I still need to clean up, which I will do before I deploy to production, but I wonder why this has now suddenly caused the lag after updating Rails. Question is: What is causing it and can I do something about it?

Let me know if you need more info. Any help is greatly appreciated.

EDIT: I also created an issue on the github.com/rails/rails, which seems to be picked up as a regression: https://github.com/rails/rails/issues/9803.

Answer 1

We had the same issues with Discourse. I extracted the relevant security fixes into a monkey patch you can apply to a Rails 3.2 application:

module HTML
  class WhiteListSanitizer
      # Sanitizes a block of css code. Used by #sanitize when it comes across a style attribute
    def sanitize_css(style)
      # disallow urls
      style = style.to_s.gsub(/url\s*\(\s*[^\s)]+?\s*\)\s*/, ' ')

      # gauntlet
      if style !~ /\A([:,;#%.\sa-zA-Z0-9!]|\w-\w|\'[\s\w]+\'|\"[\s\w]+\"|\([\d,\s]+\))*\z/ ||
          style !~ /\A(\s*[-\w]+\s*:\s*[^:;]*(;|$)\s*)*\z/
        return ''
      end

      clean = []
      style.scan(/([-\w]+)\s*:\s*([^:;]*)/) do |prop,val|
        if allowed_css_properties.include?(prop.downcase)
          clean <<  prop + ': ' + val + ';'
        elsif shorthand_css_properties.include?(prop.split('-')[0].downcase)
          unless val.split().any? do |keyword|
            !allowed_css_keywords.include?(keyword) &&
              keyword !~ /\A(#[0-9a-f]+|rgb\(\d+%?,\d*%?,?\d*%?\)?|\d{0,2}\.?\d{0,2}(cm|em|ex|in|mm|pc|pt|px|%|,|\))?)\z/
          end
            clean << prop + ': ' + val + ';'
          end
        end
      end
      clean.join(' ')
    end
  end
end

module HTML
  class WhiteListSanitizer
    self.protocol_separator = /:|(&#0*58)|(&#x70)|(&#x0*3a)|(%|&#37;)3A/i

    def contains_bad_protocols?(attr_name, value)
      uri_attributes.include?(attr_name) &&
      (value =~ /(^[^\/:]*):|(&#0*58)|(&#x70)|(&#x0*3a)|(%|&#37;)3A/i && !allowed_protocols.include?(value.split(protocol_separator).first.downcase.strip))
    end
  end
end

module ActiveRecord
  class Relation

    def where_values_hash
      equalities = with_default_scope.where_values.grep(Arel::Nodes::Equality).find_all { |node|
        node.left.relation.name == table_name
      }

      Hash[equalities.map { |where| [where.left.name, where.right] }].with_indifferent_access
    end

  end
end

module ActiveRecord
  class PredicateBuilder # :nodoc:
    def self.build_from_hash(engine, attributes, default_table, allow_table_name = true)
      predicates = attributes.map do |column, value|
        table = default_table

        if allow_table_name && value.is_a?(Hash)
          table = Arel::Table.new(column, engine)

          if value.empty?
            '1 = 2'
          else
            build_from_hash(engine, value, table, false)
          end
        else
          column = column.to_s

          if allow_table_name && column.include?('.')
            table_name, column = column.split('.', 2)
            table = Arel::Table.new(table_name, engine)
          end

          attribute = table[column]

          case value
          when ActiveRecord::Relation
            value = value.select(value.klass.arel_table[value.klass.primary_key]) if value.select_values.empty?
            attribute.in(value.arel.ast)
          when Array, ActiveRecord::Associations::CollectionProxy
            values = value.to_a.map {|x| x.is_a?(ActiveRecord::Base) ? x.id : x}
            ranges, values = values.partition {|v| v.is_a?(Range) || v.is_a?(Arel::Relation)}

            array_predicates = ranges.map {|range| attribute.in(range)}

            if values.include?(nil)
              values = values.compact
              if values.empty?
                array_predicates << attribute.eq(nil)
              else
                array_predicates << attribute.in(values.compact).or(attribute.eq(nil))
              end
            else
              array_predicates << attribute.in(values)
            end

            array_predicates.inject {|composite, predicate| composite.or(predicate)}
          when Range, Arel::Relation
            attribute.in(value)
          when ActiveRecord::Base
            attribute.eq(value.id)
          when Class
            # FIXME: I think we need to deprecate this behavior
            attribute.eq(value.name)
          when Integer, ActiveSupport::Duration
            # Arel treats integers as literals, but they should be quoted when compared with strings
            column = engine.connection.schema_cache.columns_hash[table.name][attribute.name.to_s]
            attribute.eq(Arel::Nodes::SqlLiteral.new(engine.connection.quote(value, column)))
          else
            attribute.eq(value)
          end
        end
      end

      predicates.flatten
    end
  end
end

With the security patches applied and Rails 3.2.13 reverted the performance returns to normal. We also were experiencing UTF-8 errors when precompiling our assets and this is no longer happening. It seems there is a bunch of non-security related stuff in the 3.2.13 patch that is breaking stuff :(

Answer 2

@fredwu fixed this in a pull request: https://github.com/rails/rails/pull/9820

To use this fix right away (and don't have to wait on a new Rails release) you can monkey patch the AssetsPaths class in your own application by using the following code:

module Sprockets
  module Helpers
    module RailsHelper
      class AssetPaths < ::ActionView::AssetPaths
        private
        def rewrite_extension(source, dir, ext)
          source_ext = File.extname(source)[1..-1]
          if !ext || ext == source_ext
            source
          elsif source_ext.blank?
            "#{source}.#{ext}"
          elsif File.exists?(source) || exact_match_present?(source)
            source
          else
            "#{source}.#{ext}"
          end
        end
      end
    end
  end
end