From 3be9134d1cb882f4be3be8d57b2f8bde5ecde887 Mon Sep 17 00:00:00 2001 From: Pratik Naik Date: Tue, 28 Oct 2008 05:19:10 +0530 Subject: Simplify benchmarking and rescue --- actionpack/lib/action_controller/base.rb | 16 +++- actionpack/lib/action_controller/benchmarking.rb | 105 +++++++++++------------ actionpack/lib/action_controller/rescue.rb | 10 --- 3 files changed, 63 insertions(+), 68 deletions(-) (limited to 'actionpack') diff --git a/actionpack/lib/action_controller/base.rb b/actionpack/lib/action_controller/base.rb index ad6562024a..9c10c9a1d6 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) + @_flash @_response @_runtime) # 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,6 +862,9 @@ 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? @@ -940,6 +943,9 @@ 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 @@ -1208,6 +1214,7 @@ module ActionController #:nodoc: @template = @_response.template @_headers = @_response.headers + @_runtime = {} end def initialize_current_url @@ -1249,6 +1256,8 @@ module ActionController #:nodoc: end def perform_action + start = Time.now + if action_methods.include?(action_name) send(action_name) default_render unless performed? @@ -1260,6 +1269,11 @@ 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 fa572ebf3d..e0a52c14f3 100644 --- a/actionpack/lib/action_controller/benchmarking.rb +++ b/actionpack/lib/action_controller/benchmarking.rb @@ -6,11 +6,6 @@ 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 @@ -40,68 +35,64 @@ module ActionController #:nodoc: end end - 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 + private - render_output = nil - @view_runtime = Benchmark::realtime { render_output = render_without_benchmark(options, extra_options, &block) } + def log_benchmarks + return unless logger - 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 + seconds = [ @_runtime[:perform_action], 0.0001 ].max + logging_view = @_runtime.has_key?(:render) + logging_active_record = Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? - render_output - else - render_without_benchmark(options, extra_options, &block) - end - end + log_message = "Completed in #{sprintf("%.0f", seconds * 1000)}ms" - 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" + 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 - perform_action_without_benchmark + ")" end end - def view_runtime - "View: %.0f" % (@view_runtime * 1000) + 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 + + if @_runtime[:db_before_render] + db_runtime += @_runtime[:db_before_render] + db_runtime += @_runtime[:db_after_render] + 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] end + end - 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) + def reset_db_runtime + if logger && Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? + @_runtime[:db_before_render] = ActiveRecord::Base.connection.reset_runtime end + end end end diff --git a/actionpack/lib/action_controller/rescue.rb b/actionpack/lib/action_controller/rescue.rb index ec8e9b92d5..628190d606 100644 --- a/actionpack/lib/action_controller/rescue.rb +++ b/actionpack/lib/action_controller/rescue.rb @@ -43,10 +43,6 @@ 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 @@ -132,12 +128,6 @@ 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