Merge pull request #7708 from bdurand/optimize_log_subscribers

Optimize log subscribers to check if the log level is sufficient

2 files changed, 16 insertions, 8 deletions

diff --git a/actionpack/lib/action_controller/log_subscriber.rb b/actionpack/lib/action_controller/log_subscriber.rb
index f41d1bb4b9..3d274e7dd7 100644
--- a/actionpack/lib/action_controller/log_subscriber.rb
+++ b/actionpack/lib/action_controller/log_subscriber.rb
@@ -4,6 +4,8 @@ module ActionController
     INTERNAL_PARAMS = %w(controller action format _method only_path)
 
     def start_processing(event)
+      return unless logger.info?
+
       payload = event.payload
       params  = payload[:params].except(*INTERNAL_PARAMS)
       format  = payload[:format]
@@ -14,6 +16,8 @@ module ActionController
     end
 
     def process_action(event)
+      return unless logger.info?
+
       payload   = event.payload
       additions = ActionController::Base.log_process_action(payload)
 
@@ -22,35 +26,36 @@ module ActionController
         exception_class_name = payload[:exception].first
         status = ActionDispatch::ExceptionWrapper.status_code_for_exception(exception_class_name)
       end
-      message = "Completed #{status} #{Rack::Utils::HTTP_STATUS_CODES[status]} in %.0fms" % event.duration
+      message = "Completed #{status} #{Rack::Utils::HTTP_STATUS_CODES[status]} in #{event.duration.round}ms"
       message << " (#{additions.join(" | ")})" unless additions.blank?
 
       info(message)
     end
 
     def halted_callback(event)
-      info "Filter chain halted as #{event.payload[:filter]} rendered or redirected"
+      info("Filter chain halted as #{event.payload[:filter]} rendered or redirected")
     end
 
     def send_file(event)
-      info("Sent file %s (%.1fms)" % [event.payload[:path], event.duration])
+      info("Sent file #{event.payload[:path]} (#{event.duration.round(1)}ms)")
     end
 
     def redirect_to(event)
-      info "Redirected to #{event.payload[:location]}"
+      info("Redirected to #{event.payload[:location]}")
     end
 
     def send_data(event)
-      info("Sent data %s (%.1fms)" % [event.payload[:filename], event.duration])
+      info("Sent data #{event.payload[:filename]} (#{event.duration.round(1)}ms)")
     end
 
     %w(write_fragment read_fragment exist_fragment?
        expire_fragment expire_page write_page).each do |method|
       class_eval <<-METHOD, __FILE__, __LINE__ + 1
         def #{method}(event)
+          return unless logger.info?
           key_or_path = event.payload[:key] || event.payload[:path]
           human_name  = #{method.to_s.humanize.inspect}
-          info("\#{human_name} \#{key_or_path} \#{"(%.1fms)" % event.duration}")
+          info("\#{human_name} \#{key_or_path} (\#{event.duration.round(1)}ms)")
         end
       METHOD
     end
diff --git a/actionpack/lib/action_view/log_subscriber.rb b/actionpack/lib/action_view/log_subscriber.rb
index cc3a871576..fd9a543e0a 100644
--- a/actionpack/lib/action_view/log_subscriber.rb
+++ b/actionpack/lib/action_view/log_subscriber.rb
@@ -3,10 +3,13 @@ module ActionView
   #
   # Provides functionality so that Rails can output logs from Action View.
   class LogSubscriber < ActiveSupport::LogSubscriber
+    VIEWS_PATTERN = /^app\/views\//.freeze
+
     def render_template(event)
+      return unless logger.info?
       message = "  Rendered #{from_rails_root(event.payload[:identifier])}"
       message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout]
-      message << (" (%.1fms)" % event.duration)
+      message << " (#{event.duration.round(1)}ms)"
       info(message)
     end
     alias :render_partial :render_template
@@ -19,7 +22,7 @@ module ActionView
   protected
 
     def from_rails_root(string)
-      string.sub("#{Rails.root}/", "").sub(/^app\/views\//, "")
+      string.sub("#{Rails.root}/", "").sub(VIEWS_PATTERN, "")
     end
   end
 end