diff --git a/activerecord/CHANGELOG.md b/activerecord/CHANGELOG.md index 39bbcb795f1e7..8317e4e2f5056 100644 --- a/activerecord/CHANGELOG.md +++ b/activerecord/CHANGELOG.md @@ -1,5 +1,14 @@ ## Rails 4.0.0 (unreleased) ## +* The auto explain feature has been removed. This feature was + activated by configuring `config.active_record.auto_explain_threshold_in_seconds`. + The configuration option was deprecated and has no more effect. + + You can still use `ActiveRecord::Relation#explain` to see the EXPLAIN output for + any given relation. + + *Yves Senn* + * The `:on` option for `after_commit` and `after_rollback` now accepts an Array of actions. Fixes #988. diff --git a/activerecord/lib/active_record/explain.rb b/activerecord/lib/active_record/explain.rb index 70683eb731df1..b2a9a54af1715 100644 --- a/activerecord/lib/active_record/explain.rb +++ b/activerecord/lib/active_record/explain.rb @@ -2,43 +2,7 @@ module ActiveRecord module Explain - def self.extended(base) - base.mattr_accessor :auto_explain_threshold_in_seconds, instance_accessor: false - end - - # If the database adapter supports explain and 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. - - # - # The available_queries_for_explain thread variable collects the queries - # to be explained. If the value is nil, it means queries are not being - # currently collected. A false value indicates collecting is turned - # off. Otherwise it is an array of queries. - def logging_query_plan # :nodoc: - return yield unless logger - - threshold = auto_explain_threshold_in_seconds - current = Thread.current - if connection.supports_explain? && threshold && current[:available_queries_for_explain].nil? - begin - queries = current[:available_queries_for_explain] = [] - start = Time.now - result = yield - logger.warn(exec_explain(queries)) if Time.now - start > threshold - result - ensure - current[:available_queries_for_explain] = nil - end - else - yield - end - end - - # Relation#explain needs to be able to collect the queries regardless of - # whether auto explain is enabled. This method serves that purpose. + # Relation#explain needs to be able to collect the queries. def collecting_queries_for_explain # :nodoc: current = Thread.current original, current[:available_queries_for_explain] = current[:available_queries_for_explain], [] @@ -68,20 +32,5 @@ def str.inspect end str end - - # 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 - current = Thread.current - original, current[:available_queries_for_explain] = current[:available_queries_for_explain], false - yield - ensure - current[:available_queries_for_explain] = original - end end end diff --git a/activerecord/lib/active_record/querying.rb b/activerecord/lib/active_record/querying.rb index f08b9c614d43a..e04a3d09765ec 100644 --- a/activerecord/lib/active_record/querying.rb +++ b/activerecord/lib/active_record/querying.rb @@ -33,18 +33,16 @@ module Querying # Post.find_by_sql ["SELECT title FROM posts WHERE author = ? AND created > ?", author_id, start_date] # # => [#"The Cheap Man Buys Twice"}>, ...] def find_by_sql(sql, binds = []) - logging_query_plan do - result_set = connection.select_all(sanitize_sql(sql), "#{name} Load", binds) - column_types = {} + result_set = connection.select_all(sanitize_sql(sql), "#{name} Load", binds) + column_types = {} - if result_set.respond_to? :column_types - column_types = result_set.column_types - else - ActiveSupport::Deprecation.warn "the object returned from `select_all` must respond to `column_types`" - end - - result_set.map { |record| instantiate(record, column_types) } + if result_set.respond_to? :column_types + column_types = result_set.column_types + else + ActiveSupport::Deprecation.warn "the object returned from `select_all` must respond to `column_types`" end + + result_set.map { |record| instantiate(record, column_types) } end # Returns the result of an SQL statement that should only include a COUNT(*) in the SELECT part. @@ -57,10 +55,8 @@ def find_by_sql(sql, binds = []) # # Product.count_by_sql "SELECT COUNT(*) FROM sales s, customers c WHERE s.customer_id = c.id" def count_by_sql(sql) - logging_query_plan do - sql = sanitize_conditions(sql) - connection.select_value(sql, "#{name} Count").to_i - end + sql = sanitize_conditions(sql) + connection.select_value(sql, "#{name} Count").to_i end end end diff --git a/activerecord/lib/active_record/railtie.rb b/activerecord/lib/active_record/railtie.rb index a979be6999318..64eac3aca73d3 100644 --- a/activerecord/lib/active_record/railtie.rb +++ b/activerecord/lib/active_record/railtie.rb @@ -112,7 +112,18 @@ class Railtie < Rails::Railtie # :nodoc: `config/application.rb` file and any `mass_assignment_sanitizer` options from your `config/environments/*.rb` files. - See http://guides.rubyonrails.org/security.html#mass-assignment for more information + See http://guides.rubyonrails.org/security.html#mass-assignment for more information. + EOF + end + + unless app.config.active_record.delete(:auto_explain_threshold_in_seconds).nil? + ActiveSupport::Deprecation.warn <<-EOF.strip_heredoc, [] + The Active Record auto explain feature has been removed. + + To disable this message remove the `active_record.auto_explain_threshold_in_seconds` + option from the `config/environments/*.rb` config file. + + See http://guides.rubyonrails.org/4_0_release_notes.html for more information. EOF end @@ -124,7 +135,7 @@ class Railtie < Rails::Railtie # :nodoc: To disable this message remove the `observers` option from your `config/application.rb` or from your initializers. - See http://guides.rubyonrails.org/4_0_release_notes.html for more information + See http://guides.rubyonrails.org/4_0_release_notes.html for more information. EOF end ensure @@ -146,13 +157,6 @@ class Railtie < Rails::Railtie # :nodoc: end end - initializer "active_record.validate_explain_support" do |app| - if app.config.active_record[:auto_explain_threshold_in_seconds] && - !ActiveRecord::Base.connection.supports_explain? - warn "auto_explain_threshold_in_seconds is set but will be ignored because your adapter does not support this feature. Please unset the configuration to avoid this warning." - end - end - # Expose database runtime to controller for logging. initializer "active_record.log_runtime" do |app| require "active_record/railties/controller_runtime" diff --git a/activerecord/lib/active_record/relation.rb b/activerecord/lib/active_record/relation.rb index 0053530f73da5..bc50802c4ae43 100644 --- a/activerecord/lib/active_record/relation.rb +++ b/activerecord/lib/active_record/relation.rb @@ -444,17 +444,7 @@ def delete(id_or_array) # # Post.where(published: true).load # => # def load - unless loaded? - # We monitor here the entire execution rather than individual SELECTs - # because from the point of view of the user fetching the records of a - # relation is a single unit of work. You want to know if this call takes - # too long, not if the individual queries take too long. - # - # It could be the case that none of the queries involved surpass the - # threshold, and at the same time the sum of them all does. The user - # should get a query plan logged in that case. - logging_query_plan { exec_queries } - end + exec_queries unless loaded? self end diff --git a/activerecord/lib/active_record/relation/delegation.rb b/activerecord/lib/active_record/relation/delegation.rb index 615309964c8b8..00a506c3a79d2 100644 --- a/activerecord/lib/active_record/relation/delegation.rb +++ b/activerecord/lib/active_record/relation/delegation.rb @@ -12,7 +12,7 @@ module Delegation # :nodoc: delegate :to_xml, :to_yaml, :length, :collect, :map, :each, :all?, :include?, :to_ary, :to => :to_a delegate :table_name, :quoted_table_name, :primary_key, :quoted_primary_key, - :connection, :columns_hash, :auto_explain_threshold_in_seconds, :to => :klass + :connection, :columns_hash, :to => :klass module ClassSpecificRelation extend ActiveSupport::Concern diff --git a/activerecord/test/cases/explain_test.rb b/activerecord/test/cases/explain_test.rb index aa2a6d75095b1..b1d276f9ebb0a 100644 --- a/activerecord/test/cases/explain_test.rb +++ b/activerecord/test/cases/explain_test.rb @@ -14,46 +14,9 @@ def connection base.connection end - def test_logging_query_plan_with_logger - base.logger.expects(:warn).with do |message| - message.starts_with?('EXPLAIN for:') - end - - with_threshold(0) do - Car.where(:name => 'honda').to_a - end - end - - def test_logging_query_plan_without_logger - original = base.logger - base.logger = nil - - class << base.logger - def warn; raise "Should not be called" end - end - - with_threshold(0) do - car = Car.where(:name => 'honda').first - assert_equal 'honda', car.name - end - ensure - base.logger = original - end - - def test_collect_queries_for_explain - base.auto_explain_threshold_in_seconds = nil - queries = Thread.current[:available_queries_for_explain] = [] - - with_threshold(0) do - Car.where(:name => 'honda').to_a - end - - sql, binds = queries[0] - assert_match "SELECT", sql - assert_match "honda", sql - assert_equal [], binds - ensure - Thread.current[:available_queries_for_explain] = nil + def test_relation_explain + message = Car.where(:name => 'honda').explain + assert_match(/^EXPLAIN for:/, message) end def test_collecting_queries_for_explain @@ -68,16 +31,6 @@ def test_collecting_queries_for_explain assert_equal [cars(:honda)], result end - def test_logging_query_plan_when_counting_by_sql - base.logger.expects(:warn).with do |message| - message.starts_with?('EXPLAIN for:') - end - - with_threshold(0) do - Car.count_by_sql "SELECT COUNT(*) FROM cars WHERE name = 'honda'" - end - end - def test_exec_explain_with_no_binds sqls = %w(foo bar) binds = [[], []] @@ -113,25 +66,8 @@ def test_unsupported_connection_adapter base.logger.expects(:warn).never - with_threshold(0) do - Car.where(:name => 'honda').to_a - end - end - - def test_silence_auto_explain - base.expects(:collecting_sqls_for_explain).never - base.logger.expects(:warn).never - base.silence_auto_explain do - with_threshold(0) { Car.all.to_a } - end + Car.where(:name => 'honda').to_a end - def with_threshold(threshold) - current_threshold = base.auto_explain_threshold_in_seconds - base.auto_explain_threshold_in_seconds = threshold - yield - ensure - base.auto_explain_threshold_in_seconds = current_threshold - end end end diff --git a/guides/code/getting_started/config/environments/development.rb b/guides/code/getting_started/config/environments/development.rb index ed2667ac581b3..d169e9452c188 100644 --- a/guides/code/getting_started/config/environments/development.rb +++ b/guides/code/getting_started/config/environments/development.rb @@ -22,10 +22,6 @@ # Only use best-standards-support built into browsers. config.action_dispatch.best_standards_support = :builtin - # Log the query plan for queries taking more than this (works - # with SQLite, MySQL, and PostgreSQL). - config.active_record.auto_explain_threshold_in_seconds = 0.5 - # Raise an error on page load if there are pending migrations config.active_record.migration_error = :page_load diff --git a/guides/code/getting_started/config/environments/production.rb b/guides/code/getting_started/config/environments/production.rb index 58dab2a319d75..368a7351222c8 100644 --- a/guides/code/getting_started/config/environments/production.rb +++ b/guides/code/getting_started/config/environments/production.rb @@ -72,10 +72,6 @@ # Send deprecation notices to registered listeners. config.active_support.deprecation = :notify - # Log the query plan for queries taking more than this (works - # with SQLite, MySQL, and PostgreSQL). - # config.active_record.auto_explain_threshold_in_seconds = 0.5 - # Disable automatic flushing of the log to improve performance. # config.autoflush_log = false diff --git a/guides/source/active_record_querying.md b/guides/source/active_record_querying.md index 62d6294ae5034..bc3b1669d23ac 100644 --- a/guides/source/active_record_querying.md +++ b/guides/source/active_record_querying.md @@ -1609,45 +1609,6 @@ EXPLAIN for: SELECT `posts`.* FROM `posts` WHERE `posts`.`user_id` IN (1) under MySQL. -### 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 -``` - -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. - -INFO. Automatic EXPLAIN gets disabled if Active Record has no logger, regardless -of the value of the threshold. - -#### Disabling Automatic EXPLAIN - -Automatic EXPLAIN can be selectively silenced with `ActiveRecord::Base.silence_auto_explain`: - -```ruby -ActiveRecord::Base.silence_auto_explain do - # no automatic EXPLAIN is triggered here -end -``` - -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. - ### Interpreting EXPLAIN Interpretation of the output of EXPLAIN is beyond the scope of this guide. The diff --git a/guides/source/configuring.md b/guides/source/configuring.md index be46e15078c8c..dbbeec71260a4 100644 --- a/guides/source/configuring.md +++ b/guides/source/configuring.md @@ -268,8 +268,6 @@ config.middleware.delete "Rack::MethodOverride" * `config.active_record.lock_optimistically` controls whether Active Record will use optimistic locking and is true by default. -* `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. - * +config.active_record.cache_timestamp_format+ controls the format of the timestamp value in the cache key. Default is +:number+. The MySQL adapter adds one additional configuration option: diff --git a/railties/lib/rails/generators/rails/app/templates/config/environments/development.rb.tt b/railties/lib/rails/generators/rails/app/templates/config/environments/development.rb.tt index c4cc1162a44be..d0e62d09cc367 100644 --- a/railties/lib/rails/generators/rails/app/templates/config/environments/development.rb.tt +++ b/railties/lib/rails/generators/rails/app/templates/config/environments/development.rb.tt @@ -20,10 +20,6 @@ config.active_support.deprecation = :log <%- unless options.skip_active_record? -%> - # Log the query plan for queries taking more than this (works - # with SQLite, MySQL, and PostgreSQL). - config.active_record.auto_explain_threshold_in_seconds = 0.5 - # Raise an error on page load if there are pending migrations config.active_record.migration_error = :page_load <%- end -%> diff --git a/railties/lib/rails/generators/rails/app/templates/config/environments/production.rb.tt b/railties/lib/rails/generators/rails/app/templates/config/environments/production.rb.tt index 0ab91d9864f6f..5669fe6d6453e 100644 --- a/railties/lib/rails/generators/rails/app/templates/config/environments/production.rb.tt +++ b/railties/lib/rails/generators/rails/app/templates/config/environments/production.rb.tt @@ -76,12 +76,6 @@ # Send deprecation notices to registered listeners. config.active_support.deprecation = :notify - <%- unless options.skip_active_record? -%> - # Log the query plan for queries taking more than this (works - # with SQLite, MySQL, and PostgreSQL). - # config.active_record.auto_explain_threshold_in_seconds = 0.5 - <%- end -%> - # Disable automatic flushing of the log to improve performance. # config.autoflush_log = false diff --git a/railties/test/generators/app_generator_test.rb b/railties/test/generators/app_generator_test.rb index 83f43d1025f08..53618e1f4f83f 100644 --- a/railties/test/generators/app_generator_test.rb +++ b/railties/test/generators/app_generator_test.rb @@ -342,15 +342,6 @@ def test_new_hash_style end end - def test_generated_environments_file_for_auto_explain - run_generator [destination_root, "--skip-active-record"] - %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 - end - end - def test_pretend_option output = run_generator [File.join(destination_root, "myapp"), "--pretend"] assert_no_match(/run bundle install/, output)