From 4ecdf24bdedfdd1cca1f079259ff2490e2074067 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jos=C3=A9=20Valim?= Date: Wed, 30 Dec 2009 13:07:48 +0100 Subject: [PATCH] Kick AR logging back to life and move ControllerRuntime inside ActiveRecord::Rails. --- .../activerecord/controller_runtime_test.rb | 39 +++++++++++++++++++ activerecord/lib/active_record/base.rb | 1 - .../connection_adapters/abstract_adapter.rb | 10 +++-- .../lib/active_record/controller_runtime.rb | 27 ------------- activerecord/lib/active_record/rails.rb | 3 +- .../active_record/rails/controller_runtime.rb | 29 ++++++++++++++ 6 files changed, 77 insertions(+), 32 deletions(-) create mode 100644 actionpack/test/activerecord/controller_runtime_test.rb delete mode 100644 activerecord/lib/active_record/controller_runtime.rb create mode 100644 activerecord/lib/active_record/rails/controller_runtime.rb diff --git a/actionpack/test/activerecord/controller_runtime_test.rb b/actionpack/test/activerecord/controller_runtime_test.rb new file mode 100644 index 0000000000..dd31add4b4 --- /dev/null +++ b/actionpack/test/activerecord/controller_runtime_test.rb @@ -0,0 +1,39 @@ +require 'active_record_unit' +require 'active_record/rails/controller_runtime' +require 'fixtures/project' + +ActionController::Base.send :include, ActiveRecord::Rails::ControllerRuntime + +class ARLoggingController < ActionController::Base + def show + render :inline => "<%= Project.all %>" + end +end + +class ARLoggingTest < ActionController::TestCase + tests ARLoggingController + + def setup + super + set_logger + end + + def wait + ActiveSupport::Notifications.notifier.wait + end + + def test_log_with_active_record + get :show + wait + assert_match /ActiveRecord runtime/, logs[3] + end + + private + def set_logger + @controller.logger = MockLogger.new + end + + def logs + @logs ||= @controller.logger.logged.compact.map {|l| l.to_s.strip} + end +end diff --git a/activerecord/lib/active_record/base.rb b/activerecord/lib/active_record/base.rb index 07c5545171..c4bdbdad08 100755 --- a/activerecord/lib/active_record/base.rb +++ b/activerecord/lib/active_record/base.rb @@ -1,4 +1,3 @@ -require 'benchmark' require 'yaml' require 'set' require 'active_support/benchmarkable' diff --git a/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb b/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb index 8fae26b790..d09aa3c4d2 100755 --- a/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb +++ b/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb @@ -1,6 +1,7 @@ require 'date' require 'bigdecimal' require 'bigdecimal/util' +require 'active_support/core_ext/benchmark' # TODO: Autoload these files require 'active_record/connection_adapters/abstract/schema_definitions' @@ -191,7 +192,6 @@ module ActiveRecord end def log_info(sql, name, ms) - @runtime += ms if @logger && @logger.debug? name = '%s (%.1fms)' % [name || 'SQL', ms] @logger.debug(format_log_entry(name, sql.squeeze(' '))) @@ -199,8 +199,12 @@ module ActiveRecord end protected - def log(sql, name, &block) - ActiveSupport::Notifications.instrument(:sql, :sql => sql, :name => name, &block) + def log(sql, name) + result = nil + ActiveSupport::Notifications.instrument(:sql, :sql => sql, :name => name) do + @runtime += Benchmark.ms { result = yield } + end + result rescue Exception => e # Log message and raise exception. # Set last_verification to 0, so that connection gets verified diff --git a/activerecord/lib/active_record/controller_runtime.rb b/activerecord/lib/active_record/controller_runtime.rb deleted file mode 100644 index 1281901ae8..0000000000 --- a/activerecord/lib/active_record/controller_runtime.rb +++ /dev/null @@ -1,27 +0,0 @@ -module ActiveRecord - module ControllerRuntime - extend ActiveSupport::Concern - - attr_internal :db_runtime - - def cleanup_view_runtime - if Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? - db_rt_before_render = ActiveRecord::Base.connection.reset_runtime - runtime = super - db_rt_after_render = ActiveRecord::Base.connection.reset_runtime - self.db_runtime = db_rt_before_render + db_rt_after_render - runtime - db_rt_after_render - else - super - end - end - - module ClassMethods - def process_log_action(controller) - super - db_runtime = controller.send :db_runtime - logger.info(" ActiveRecord runtime: %.1fms" % db_runtime.to_f) if db_runtime - end - end - end -end \ No newline at end of file diff --git a/activerecord/lib/active_record/rails.rb b/activerecord/lib/active_record/rails.rb index e7de699974..69f38e75c8 100644 --- a/activerecord/lib/active_record/rails.rb +++ b/activerecord/lib/active_record/rails.rb @@ -3,13 +3,14 @@ # here. This is needed for correctly setting up the middleware. # In the future, this might become an optional require. require "action_controller/rails" +require "active_record/rails/controller_runtime" module ActiveRecord class Plugin < Rails::Plugin plugin_name :active_record include_modules_in "ActiveRecord::Base" - config.action_controller.include "ActiveRecord::ControllerRuntime" + config.action_controller.include "ActiveRecord::Rails::ControllerRuntime" rake_tasks do load "active_record/rails/databases.rake" diff --git a/activerecord/lib/active_record/rails/controller_runtime.rb b/activerecord/lib/active_record/rails/controller_runtime.rb new file mode 100644 index 0000000000..9ae40c5c8f --- /dev/null +++ b/activerecord/lib/active_record/rails/controller_runtime.rb @@ -0,0 +1,29 @@ +module ActiveRecord + module Rails + module ControllerRuntime + extend ActiveSupport::Concern + + attr_internal :db_runtime + + def cleanup_view_runtime + if ActiveRecord::Base.connected? + db_rt_before_render = ActiveRecord::Base.connection.reset_runtime + runtime = super + db_rt_after_render = ActiveRecord::Base.connection.reset_runtime + self.db_runtime = db_rt_before_render + db_rt_after_render + runtime - db_rt_after_render + else + super + end + end + + module ClassMethods + def log_process_action(controller) + super + db_runtime = controller.send :db_runtime + logger.info(" ActiveRecord runtime: %.1fms" % db_runtime.to_f) if db_runtime + end + end + end + end +end \ No newline at end of file