diff options
19 files changed, 192 insertions, 87 deletions
diff --git a/actionpack/lib/action_dispatch/middleware/debug_exceptions.rb b/actionpack/lib/action_dispatch/middleware/debug_exceptions.rb index 5da21ddd3d..417701ea54 100644 --- a/actionpack/lib/action_dispatch/middleware/debug_exceptions.rb +++ b/actionpack/lib/action_dispatch/middleware/debug_exceptions.rb @@ -15,6 +15,7 @@ module ActionDispatch begin response = @app.call(env) + # TODO: Maybe this should be in the router itself if response[1]['X-Cascade'] == 'pass' raise ActionController::RoutingError, "No route matches [#{env['REQUEST_METHOD']}] #{env['PATH_INFO'].inspect}" end @@ -22,7 +23,7 @@ module ActionDispatch raise exception if env['action_dispatch.show_exceptions'] == false end - response ? response : render_exception(env, exception) + exception ? render_exception(env, exception) : response end private diff --git a/actionpack/lib/action_dispatch/middleware/show_exceptions.rb b/actionpack/lib/action_dispatch/middleware/show_exceptions.rb index 9efe90a670..0c95248611 100644 --- a/actionpack/lib/action_dispatch/middleware/show_exceptions.rb +++ b/actionpack/lib/action_dispatch/middleware/show_exceptions.rb @@ -40,7 +40,7 @@ module ActionDispatch raise exception if env['action_dispatch.show_exceptions'] == false end - response ? response : render_exception_with_failsafe(env, exception) + response || render_exception_with_failsafe(env, exception) end private diff --git a/actionpack/test/dispatch/debug_exceptions_test.rb b/actionpack/test/dispatch/debug_exceptions_test.rb index e6c0a06878..f7411c7729 100644 --- a/actionpack/test/dispatch/debug_exceptions_test.rb +++ b/actionpack/test/dispatch/debug_exceptions_test.rb @@ -11,6 +11,8 @@ class DebugExceptionsTest < ActionDispatch::IntegrationTest env['action_dispatch.show_detailed_exceptions'] = @detailed req = ActionDispatch::Request.new(env) case req.path + when "/pass" + [404, { "X-Cascade" => "pass" }, []] when "/not_found" raise ActionController::UnknownAction when "/runtime_error" @@ -46,6 +48,13 @@ class DebugExceptionsTest < ActionDispatch::IntegrationTest end end + test 'raise an exception on cascade pass' do + @app = ProductionApp + assert_raise ActionController::RoutingError do + get "/pass", {}, {'action_dispatch.show_exceptions' => true} + end + end + test "rescue with diagnostics message" do @app = DevelopmentApp diff --git a/activerecord/CHANGELOG.md b/activerecord/CHANGELOG.md index 9ffd085925..f483fdd844 100644 --- a/activerecord/CHANGELOG.md +++ b/activerecord/CHANGELOG.md @@ -1,5 +1,8 @@ ## Rails 3.2.0 (unreleased) ## +* Implements `silence_auto_explain`. This method allows the user to selectively disable + automatic EXPLAINs within a block. *fxn* + * Implements automatic EXPLAIN logging for slow queries. A new configuration parameter `config.active_record.auto_explain_threshold_in_seconds` diff --git a/activerecord/lib/active_record/base.rb b/activerecord/lib/active_record/base.rb index 3d55729318..dcd091aecb 100644 --- a/activerecord/lib/active_record/base.rb +++ b/activerecord/lib/active_record/base.rb @@ -2213,7 +2213,7 @@ MSG include Associations, NamedScope include IdentityMap include ActiveModel::SecurePassword - extend Explain + include Explain # AutosaveAssociation needs to be included before Transactions, because we want # #save_with_autosave_associations to be wrapped inside a transaction. diff --git a/activerecord/lib/active_record/explain.rb b/activerecord/lib/active_record/explain.rb index 4d013f0ef4..b506108f21 100644 --- a/activerecord/lib/active_record/explain.rb +++ b/activerecord/lib/active_record/explain.rb @@ -1,76 +1,106 @@ module ActiveRecord - module Explain # :nodoc: - # logging_query_plan calls could appear nested in the call stack. In - # particular this happens when a relation fetches its records, since - # that results in find_by_sql calls downwards. - # - # This flag allows nested calls to detect this situation and bypass - # it, thus preventing repeated EXPLAINs. - LOGGING_QUERY_PLAN = :logging_query_plan + module Explain + extend ActiveSupport::Concern - # If auto explain is enabled, this method triggers EXPLAIN logging for the - # queries triggered by the block if it takes more than the threshold as a - # whole. That is, the threshold is not checked against each individual - # query, but against the duration of the entire block. This approach is - # convenient for relations. - def logging_query_plan(&block) - if (t = auto_explain_threshold_in_seconds) && !Thread.current[LOGGING_QUERY_PLAN] - begin - Thread.current[LOGGING_QUERY_PLAN] = true - start = Time.now - result, sqls, binds = collecting_sqls_for_explain(&block) - logger.warn(exec_explain(sqls, binds)) if Time.now - start > t - result - ensure - Thread.current[LOGGING_QUERY_PLAN] = false + module ClassMethods + # logging_query_plan calls could appear nested in the call stack. In + # particular this happens when a relation fetches its records, since + # that results in find_by_sql calls downwards. + # + # This flag allows nested calls to detect this situation and bypass + # it, thus preventing repeated EXPLAINs. + LOGGING_QUERY_PLAN = :logging_query_plan + + # If auto explain is enabled, this method triggers EXPLAIN logging for the + # queries triggered by the block if it takes more than the threshold as a + # whole. That is, the threshold is not checked against each individual + # query, but against the duration of the entire block. This approach is + # convenient for relations. + def logging_query_plan(&block) # :nodoc: + threshold = auto_explain_threshold_in_seconds + if threshold && !Thread.current[LOGGING_QUERY_PLAN] && !Thread.current[SILENCED] + begin + Thread.current[LOGGING_QUERY_PLAN] = true + start = Time.now + result, sqls, binds = collecting_sqls_for_explain(&block) + logger.warn(exec_explain(sqls, binds)) if Time.now - start > threshold + result + ensure + Thread.current[LOGGING_QUERY_PLAN] = false + end + else + yield end - else - block.call end - end - # SCHEMA queries cannot be EXPLAINed, also we do not want to run EXPLAIN on - # our own EXPLAINs now matter how loopingly beautiful that would be. - SKIP_EXPLAIN_FOR = %w(SCHEMA EXPLAIN) - def ignore_explain_notification?(payload) - payload[:exception] || SKIP_EXPLAIN_FOR.include?(payload[:name]) - end + # SCHEMA queries cannot be EXPLAINed, also we do not want to run EXPLAIN on + # our own EXPLAINs now matter how loopingly beautiful that would be. + SKIP_EXPLAIN_FOR = %w(SCHEMA EXPLAIN) + def ignore_explain_notification?(payload) # :nodoc: + payload[:exception] || SKIP_EXPLAIN_FOR.include?(payload[:name]) + end + + # Collects all queries executed while the passed block runs. Returns an + # array with three elements, the result of the block, the strings with the + # queries, and their respective bindings. + def collecting_sqls_for_explain # :nodoc: + sqls = [] + binds = [] + callback = lambda do |*args| + payload = args.last + unless ignore_explain_notification?(payload) + sqls << payload[:sql] + binds << payload[:binds] + end + end - # Collects all queries executed while the passed block runs. Returns an - # array with three elements, the result of the block, the strings with the - # queries, and their respective bindings. - def collecting_sqls_for_explain(&block) - sqls = [] - binds = [] - callback = lambda do |*args| - payload = args.last - unless ignore_explain_notification?(payload) - sqls << payload[:sql] - binds << payload[:binds] + result = nil + ActiveSupport::Notifications.subscribed(callback, "sql.active_record") do + result = yield end + + [result, sqls, binds] end - result = nil - ActiveSupport::Notifications.subscribed(callback, "sql.active_record") do - result = block.call + # Makes the adapter execute EXPLAIN for the given queries and bindings. + # Returns a formatted string ready to be logged. + def exec_explain(sqls, binds) # :nodoc: + sqls.zip(binds).map do |sql, bind| + [].tap do |msg| + msg << "EXPLAIN for: #{sql}" + unless bind.empty? + bind_msg = bind.map {|col, val| [col.name, val]}.inspect + msg.last << " #{bind_msg}" + end + msg << connection.explain(sql, bind) + end.join("\n") + end.join("\n") end - [result, sqls, binds] + SILENCED = :silence_explain + + # Silences automatic EXPLAIN logging for the duration of the block. + # + # This has high priority, no EXPLAINs will be run even if downwards + # the threshold is set to 0. + # + # As the name of the method suggests this only applies to automatic + # EXPLAINs, manual calls to +ActiveRecord::Relation#explain+ run. + def silence_auto_explain + # Implemented as a flag rather that setting the threshold to nil + # because we should not depend on a value that may be changed + # downwards. + Thread.current[SILENCED] = true + yield + ensure + Thread.current[SILENCED] = false + end end - # Makes the adapter execute EXPLAIN for the given queries and bindings. - # Returns a formatted string ready to be logged. - def exec_explain(sqls, binds) - sqls.zip(binds).map do |sql, bind| - [].tap do |msg| - msg << "EXPLAIN for: #{sql}" - unless bind.empty? - bind_msg = bind.map {|col, val| [col.name, val]}.inspect - msg.last << " #{bind_msg}" - end - msg << connection.explain(sql, bind) - end.join("\n") - end.join("\n") + # A convenience instance method that delegates to the class method of the + # same name. + def silence_auto_explain(&block) + self.class.silence_auto_explain(&block) end end end diff --git a/activerecord/lib/active_record/relation.rb b/activerecord/lib/active_record/relation.rb index 1db26562b8..30cd8679fe 100644 --- a/activerecord/lib/active_record/relation.rb +++ b/activerecord/lib/active_record/relation.rb @@ -154,7 +154,7 @@ module ActiveRecord # # Please see further details in the # {Active Record Query Interface guide}[http://edgeguides.rubyonrails.org/active_record_querying.html#running-explain]. - def explain + def explain _, sqls, binds = collecting_sqls_for_explain { exec_query } exec_explain(sqls, binds) end diff --git a/activerecord/test/cases/explain_test.rb b/activerecord/test/cases/explain_test.rb index d3eb9c2cb2..ff460b44eb 100644 --- a/activerecord/test/cases/explain_test.rb +++ b/activerecord/test/cases/explain_test.rb @@ -80,6 +80,17 @@ if ActiveRecord::Base.connection.supports_explain? assert_equal expected, base.exec_explain(sqls, binds) end + def test_silence_auto_explain + base.expects(:collecting_sqls_for_explain).never + base.logger.expects(:warn).never + + [base, cars(:honda)].each do |target| + target.silence_auto_explain do + with_threshold(0) { Car.all } + end + end + end + def with_threshold(threshold) current_threshold = base.auto_explain_threshold_in_seconds base.auto_explain_threshold_in_seconds = threshold diff --git a/activesupport/lib/active_support/core_ext/string/output_safety.rb b/activesupport/lib/active_support/core_ext/string/output_safety.rb index 5d7f74bb65..7b359a039b 100644 --- a/activesupport/lib/active_support/core_ext/string/output_safety.rb +++ b/activesupport/lib/active_support/core_ext/string/output_safety.rb @@ -20,7 +20,7 @@ class ERB if s.html_safe? s else - s.gsub(/&/, "&").gsub(/\"/, """).gsub(/>/, ">").gsub(/</, "<").html_safe + s.gsub(/[&"><]/n) { |special| HTML_ESCAPE[special] }.html_safe end end diff --git a/activesupport/test/core_ext/string_ext_test.rb b/activesupport/test/core_ext/string_ext_test.rb index ade09efc56..47b9f68ed0 100644 --- a/activesupport/test/core_ext/string_ext_test.rb +++ b/activesupport/test/core_ext/string_ext_test.rb @@ -21,12 +21,6 @@ class StringInflectionsTest < Test::Unit::TestCase include InflectorTestCases include ConstantizeTestCases - def test_erb_escape - string = [192, 60].pack('CC') - expected = 192.chr + "<" - assert_equal expected, ERB::Util.html_escape(string) - end - def test_strip_heredoc_on_an_empty_string assert_equal '', ''.strip_heredoc end @@ -497,6 +491,23 @@ class OutputSafetyTest < ActiveSupport::TestCase assert string.html_safe? assert !string.to_param.html_safe? end + + test "ERB::Util.html_escape should escape unsafe characters" do + string = '<>&"' + expected = '<>&"' + assert_equal expected, ERB::Util.html_escape(string) + end + + test "ERB::Util.html_escape should correctly handle invalid UTF-8 strings" do + string = [192, 60].pack('CC') + expected = 192.chr + "<" + assert_equal expected, ERB::Util.html_escape(string) + end + + test "ERB::Util.html_escape should not escape safe strings" do + string = "<b>hello</b>".html_safe + assert_equal string, ERB::Util.html_escape(string) + end end class StringExcludeTest < ActiveSupport::TestCase diff --git a/railties/CHANGELOG.md b/railties/CHANGELOG.md index 64abff6cb3..2841996b56 100644 --- a/railties/CHANGELOG.md +++ b/railties/CHANGELOG.md @@ -1,7 +1,7 @@ ## Rails 3.2.0 (unreleased) ## * New applications get a flag - `config.active_record.auto_explain_threshold_in_seconds` in the evironments + `config.active_record.auto_explain_threshold_in_seconds` in the environments configuration files. With a value of 0.5 in development.rb, and commented out in production.rb. No mention in test.rb. *fxn* diff --git a/railties/guides/source/active_record_querying.textile b/railties/guides/source/active_record_querying.textile index 352f23dc01..742aefc32f 100644 --- a/railties/guides/source/active_record_querying.textile +++ b/railties/guides/source/active_record_querying.textile @@ -1369,6 +1369,43 @@ EXPLAIN for: SELECT `posts`.* FROM `posts` WHERE `posts`.`user_id` IN (1) under MySQL. +h4. Automatic EXPLAIN + +Active Record is able to run EXPLAIN automatically on slow queries and log its +output. This feature is controlled by the configuration parameter + +<ruby> +config.active_record.auto_explain_threshold_in_seconds +</ruby> + +If set to a number, any query exceeding those many seconds will have its EXPLAIN +automatically triggered and logged. In the case of relations, the threshold is +compared to the total time needed to fetch records. So, a relation is seen as a +unit of work, no matter whether the implementation of eager loading involves +several queries under the hood. + +A threshold of +nil+ disables automatic EXPLAINs. + +The default threshold in development mode is 0.5 seconds, and +nil+ in test and +production modes. + +h5. Disabling Automatic EXPLAIN + +Automatic EXPLAIN can be selectively silenced with +silence_auto_explain+, which +is a class and instance method of +ActiveRecord::Base+: + +<ruby> +silence_auto_explain do + # no automatic EXPLAIN is triggered here +end +</ruby> + +That may be useful for queries you know are slow but fine, like a heavyweight +report of an admin interface. + +As its name suggests, +silence_auto_explain+ only silences automatic EXPLAINs. +Explicit calls to +ActiveRecord::Relation#explain+ run. + h4. Interpreting EXPLAIN Interpretation of the output of EXPLAIN is beyond the scope of this guide. The diff --git a/railties/guides/source/active_support_core_extensions.textile b/railties/guides/source/active_support_core_extensions.textile index 7959a88c5b..6646e9cd05 100644 --- a/railties/guides/source/active_support_core_extensions.textile +++ b/railties/guides/source/active_support_core_extensions.textile @@ -1301,7 +1301,7 @@ NOTE: Defined in +active_support/core_ext/string/output_safety.rb+. h5. Transformation -As a rule of thumb, except perhaps for concatenation as explained above, any method that may change a string gives you an unsafe string. These are +donwcase+, +gsub+, +strip+, +chomp+, +underscore+, etc. +As a rule of thumb, except perhaps for concatenation as explained above, any method that may change a string gives you an unsafe string. These are +downcase+, +gsub+, +strip+, +chomp+, +underscore+, etc. In the case of in-place transformations like +gsub!+ the receiver itself becomes unsafe. @@ -2053,6 +2053,16 @@ end NOTE: Defined in +active_support/core_ext/enumerable.rb+. +h4. +pluck+ + +The +pluck+ method collects the value of the passed method for each element and returns the result as an array. + +<ruby> +people.pluck(:name) # => [ "David Heinemeier Hansson", "Jamie Heinemeier Hansson" ] +</ruby> + +NOTE: Defined in +active_support/core_ext/enumerable.rb+. + h4. +each_with_object+ The +inject+ method offers iteration with an accumulator: diff --git a/railties/guides/source/asset_pipeline.textile b/railties/guides/source/asset_pipeline.textile index 3681501293..8ff1035a1c 100644 --- a/railties/guides/source/asset_pipeline.textile +++ b/railties/guides/source/asset_pipeline.textile @@ -410,10 +410,6 @@ For Apache: <plain> <LocationMatch "^/assets/.*$"> - # Some browsers still send conditional-GET requests if there's a - # Last-Modified header or an ETag header even if they haven't - # reached the expiry date sent in the Expires header. - Header unset Last-Modified Header unset ETag FileETag None # RFC says only cache for 1 year @@ -429,10 +425,6 @@ location ~ ^/assets/ { expires 1y; add_header Cache-Control public; - # Some browsers still send conditional-GET requests if there's a - # Last-Modified header or an ETag header even if they haven't - # reached the expiry date sent in the Expires header. - add_header Last-Modified ""; add_header ETag ""; break; } diff --git a/railties/guides/source/command_line.textile b/railties/guides/source/command_line.textile index 9284a542f3..3fa6c059e1 100644 --- a/railties/guides/source/command_line.textile +++ b/railties/guides/source/command_line.textile @@ -391,7 +391,7 @@ Action Pack version 3.2.0.beta Active Resource version 3.2.0.beta Action Mailer version 3.2.0.beta Active Support version 3.2.0.beta -Middleware ActionDispatch::Static, Rack::Lock, Rack::Runtime, Rack::MethodOverride, ActionDispatch::RequestId, Rails::Rack::Logger, ActionDispatch::ShowExceptions, ActionDispatch::RemoteIp, ActionDispatch::Reloader, ActionDispatch::Callbacks, ActiveRecord::ConnectionAdapters::ConnectionManagement, ActiveRecord::QueryCache, ActionDispatch::Cookies, ActionDispatch::Session::CookieStore, ActionDispatch::Flash, ActionDispatch::ParamsParser, ActionDispatch::Head, Rack::ConditionalGet, Rack::ETag, ActionDispatch::BestStandardsSupport +Middleware ActionDispatch::Static, Rack::Lock, Rack::Runtime, Rack::MethodOverride, ActionDispatch::RequestId, Rails::Rack::Logger, ActionDispatch::ShowExceptions, ActionDispatch::DebugExceptions, ActionDispatch::RemoteIp, ActionDispatch::Reloader, ActionDispatch::Callbacks, ActiveRecord::ConnectionAdapters::ConnectionManagement, ActiveRecord::QueryCache, ActionDispatch::Cookies, ActionDispatch::Session::CookieStore, ActionDispatch::Flash, ActionDispatch::ParamsParser, ActionDispatch::Head, Rack::ConditionalGet, Rack::ETag, ActionDispatch::BestStandardsSupport Application root /home/foobar/commandsapp Environment development Database adapter sqlite3 diff --git a/railties/guides/source/configuring.textile b/railties/guides/source/configuring.textile index 24bf9d863b..8e65dbccbb 100644 --- a/railties/guides/source/configuring.textile +++ b/railties/guides/source/configuring.textile @@ -268,7 +268,7 @@ h4. Configuring Active Record * +config.active_record.identity_map+ controls whether the identity map is enabled, and is false by default. -* +config.active_record.auto_explain_threshold_in_seconds+ configures the threshold for automatic EXPLAINs (+nil+ disables this feature). Queries taking more than those many seconds get their query plan logged. Default is 0.5 in development mode. +* +config.active_record.auto_explain_threshold_in_seconds+ configures the threshold for automatic EXPLAINs (+nil+ disables this feature). Queries exceeding the threshold get their query plan logged. Default is 0.5 in development mode. The MySQL adapter adds one additional configuration option: diff --git a/railties/guides/source/performance_testing.textile b/railties/guides/source/performance_testing.textile index 2440927542..958b13cd9e 100644 --- a/railties/guides/source/performance_testing.textile +++ b/railties/guides/source/performance_testing.textile @@ -151,7 +151,7 @@ Performance tests can be run in two modes: Benchmarking and Profiling. h5. Benchmarking -Benchmarking makes it easy to quickly gather a few metrics about each test tun. By default, each test case is run *4 times* in benchmarking mode. +Benchmarking makes it easy to quickly gather a few metrics about each test run. By default, each test case is run *4 times* in benchmarking mode. To run performance tests in benchmarking mode: diff --git a/railties/guides/source/rails_on_rack.textile b/railties/guides/source/rails_on_rack.textile index d6cbd84b1f..9526526bc7 100644 --- a/railties/guides/source/rails_on_rack.textile +++ b/railties/guides/source/rails_on_rack.textile @@ -95,6 +95,7 @@ use ActiveSupport::Cache::Strategy::LocalCache use Rack::Runtime use Rails::Rack::Logger use ActionDispatch::ShowExceptions +use ActionDispatch::DebugExceptions use ActionDispatch::RemoteIp use Rack::Sendfile use ActionDispatch::Callbacks diff --git a/railties/test/generators/app_generator_test.rb b/railties/test/generators/app_generator_test.rb index 41bb4d8b20..baa80419a6 100644 --- a/railties/test/generators/app_generator_test.rb +++ b/railties/test/generators/app_generator_test.rb @@ -329,8 +329,8 @@ class AppGeneratorTest < Rails::Generators::TestCase def test_generated_environments_file_for_sanitizer run_generator [destination_root, "--skip-active-record"] - ["config/environments/development.rb", "config/environments/test.rb"].each do |env_file| - assert_file env_file do |file| + %w(development test).each do |env| + assert_file "config/environments/#{env}.rb" do |file| assert_no_match(/config.active_record.mass_assignment_sanitizer = :strict/, file) end end @@ -338,7 +338,7 @@ class AppGeneratorTest < Rails::Generators::TestCase def test_generated_environments_file_for_auto_explain run_generator [destination_root, "--skip-active-record"] - %w(development test production).each do |env| + %w(development production).each do |env| assert_file "config/environments/#{env}.rb" do |file| assert_no_match %r(auto_explain_threshold_in_seconds), file end |