From dbbaccbcda7475766919723dda53c0f92afddc4b Mon Sep 17 00:00:00 2001 From: Pratik Naik Date: Thu, 20 Nov 2008 04:50:34 +0530 Subject: Revert "Simplify benchmarking and rescue". Need a different approach. This reverts commit 3be9134d1cb882f4be3be8d57b2f8bde5ecde887. --- actionpack/lib/action_controller/base.rb | 16 +--- actionpack/lib/action_controller/benchmarking.rb | 105 ++++++++++++----------- actionpack/lib/action_controller/rescue.rb | 10 +++ 3 files changed, 68 insertions(+), 63 deletions(-) diff --git a/actionpack/lib/action_controller/base.rb b/actionpack/lib/action_controller/base.rb index 9c10c9a1d6..ad6562024a 100644 --- a/actionpack/lib/action_controller/base.rb +++ b/actionpack/lib/action_controller/base.rb @@ -264,7 +264,7 @@ module ActionController #:nodoc: # Controller specific instance variables which will not be accessible inside views. @@protected_instance_variables = %w(@assigns @performed_redirect @performed_render @variables_added @request_origin @url @parent_controller @action_name @before_filter_chain_aborted @action_cache_path @_session @_cookies @_headers @_params - @_flash @_response @_runtime) + @_flash @_response) # Prepends all the URL-generating helpers from AssetHelper. This makes it possible to easily move javascripts, stylesheets, # and images to a dedicated asset server away from the main web server. Example: @@ -862,9 +862,6 @@ module ActionController #:nodoc: # # render :xml => post.to_xml, :status => :created, :location => post_url(post) def render(options = nil, extra_options = {}, &block) #:doc: - start = Time.now - reset_db_runtime - raise DoubleRenderError, "Can only render or redirect once per action" if performed? if options.nil? @@ -943,9 +940,6 @@ module ActionController #:nodoc: render_for_file(default_template_name, options[:status], layout) end end - ensure - @_runtime[:render] = Time.now - start - log_render_benchmark end # Renders according to the same rules as render, but returns the result in a string instead @@ -1214,7 +1208,6 @@ module ActionController #:nodoc: @template = @_response.template @_headers = @_response.headers - @_runtime = {} end def initialize_current_url @@ -1256,8 +1249,6 @@ module ActionController #:nodoc: end def perform_action - start = Time.now - if action_methods.include?(action_name) send(action_name) default_render unless performed? @@ -1269,11 +1260,6 @@ module ActionController #:nodoc: else raise UnknownAction, "No action responded to #{action_name}. Actions: #{action_methods.sort.to_sentence}", caller end - rescue Exception => exception - rescue_action(exception) - ensure - @_runtime[:perform_action] = Time.now - start - log_benchmarks end def performed? diff --git a/actionpack/lib/action_controller/benchmarking.rb b/actionpack/lib/action_controller/benchmarking.rb index e0a52c14f3..fa572ebf3d 100644 --- a/actionpack/lib/action_controller/benchmarking.rb +++ b/actionpack/lib/action_controller/benchmarking.rb @@ -6,6 +6,11 @@ module ActionController #:nodoc: module Benchmarking #:nodoc: def self.included(base) base.extend(ClassMethods) + + base.class_eval do + alias_method_chain :perform_action, :benchmark + alias_method_chain :render, :benchmark + end end module ClassMethods @@ -35,64 +40,68 @@ module ActionController #:nodoc: end end - private - - def log_benchmarks - return unless logger - - seconds = [ @_runtime[:perform_action], 0.0001 ].max - logging_view = @_runtime.has_key?(:render) - logging_active_record = Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? + protected + def render_with_benchmark(options = nil, extra_options = {}, &block) + if logger + if Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? + db_runtime = ActiveRecord::Base.connection.reset_runtime + end - log_message = "Completed in #{sprintf("%.0f", seconds * 1000)}ms" + render_output = nil + @view_runtime = Benchmark::realtime { render_output = render_without_benchmark(options, extra_options, &block) } - if logging_view || logging_active_record - log_message << " (" - log_message << view_runtime if logging_view + if Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? + @db_rt_before_render = db_runtime + @db_rt_after_render = ActiveRecord::Base.connection.reset_runtime + @view_runtime -= @db_rt_after_render + end - if logging_active_record - log_message << ", " if logging_view - log_message << active_record_runtime + ")" + render_output else - ")" + render_without_benchmark(options, extra_options, &block) end - end - - log_message << " | #{headers["Status"]}" - log_message << " [#{complete_request_uri rescue "unknown"}]" - - logger.info(log_message) - response.headers["X-Runtime"] = "#{sprintf("%.0f", seconds * 1000)}ms" - end - - def view_runtime - "View: %.0f" % (@_runtime[:render] * 1000) - end - - def active_record_runtime - db_runtime = ActiveRecord::Base.connection.reset_runtime + end - if @_runtime[:db_before_render] - db_runtime += @_runtime[:db_before_render] - db_runtime += @_runtime[:db_after_render] + private + def perform_action_with_benchmark + if logger + seconds = [ Benchmark::measure{ perform_action_without_benchmark }.real, 0.0001 ].max + logging_view = defined?(@view_runtime) + logging_active_record = Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? + + log_message = "Completed in #{sprintf("%.0f", seconds * 1000)}ms" + + if logging_view || logging_active_record + log_message << " (" + log_message << view_runtime if logging_view + + if logging_active_record + log_message << ", " if logging_view + log_message << active_record_runtime + ")" + else + ")" + end + end + + log_message << " | #{headers["Status"]}" + log_message << " [#{complete_request_uri rescue "unknown"}]" + + logger.info(log_message) + response.headers["X-Runtime"] = "#{sprintf("%.0f", seconds * 1000)}ms" + else + perform_action_without_benchmark + end end - "DB: %.0f" % (db_runtime * 1000) - end - - def log_render_benchmark - return unless logger - - if @_runtime.has_key?(:db_before_render) - @_runtime[:db_after_render] = ActiveRecord::Base.connection.reset_runtime - @_runtime[:render] -= @_runtime[:db_after_render] + def view_runtime + "View: %.0f" % (@view_runtime * 1000) end - end - def reset_db_runtime - if logger && Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? - @_runtime[:db_before_render] = ActiveRecord::Base.connection.reset_runtime + def active_record_runtime + db_runtime = ActiveRecord::Base.connection.reset_runtime + db_runtime += @db_rt_before_render if @db_rt_before_render + db_runtime += @db_rt_after_render if @db_rt_after_render + "DB: %.0f" % (db_runtime * 1000) end - end end end diff --git a/actionpack/lib/action_controller/rescue.rb b/actionpack/lib/action_controller/rescue.rb index 628190d606..ec8e9b92d5 100644 --- a/actionpack/lib/action_controller/rescue.rb +++ b/actionpack/lib/action_controller/rescue.rb @@ -43,6 +43,10 @@ module ActionController #:nodoc: base.extend(ClassMethods) base.send :include, ActiveSupport::Rescuable + + base.class_eval do + alias_method_chain :perform_action, :rescue + end end module ClassMethods @@ -128,6 +132,12 @@ module ActionController #:nodoc: end private + def perform_action_with_rescue #:nodoc: + perform_action_without_rescue + rescue Exception => exception + rescue_action(exception) + end + def rescues_path(template_name) "#{File.dirname(__FILE__)}/templates/rescues/#{template_name}.erb" end -- cgit v1.2.3