Prefer to pass block when logging.

The Logger by default includes a guard which checks for the
logging level. By removing the custom logging guards, we can decouple
the logging guard from the logging action to be done.

This also follows the good practice listed on http://guides.rubyonrails.org/debugging_rails_applications.html#impact-of-logs-on-performance.

actionmailer/lib/action_mailer/log_subscriber.rb

@@ -6,25 +6,27 @@ module ActionMailer
   class LogSubscriber < ActiveSupport::LogSubscriber
     # An email was delivered.
     def deliver(event)
-      return unless logger.info?
-      recipients = Array(event.payload[:to]).join(', ')
-      info("\nSent mail to #{recipients} (#{event.duration.round(1)}ms)")
-      debug(event.payload[:mail])
+      info do
+        recipients = Array(event.payload[:to]).join(', ')
+        "\nSent mail to #{recipients} (#{event.duration.round(1)}ms)"
+      end
+
+      debug { event.payload[:mail] }
     end
 
     # An email was received.
     def receive(event)
-      return unless logger.info?
-      info("\nReceived mail (#{event.duration.round(1)}ms)")
-      debug(event.payload[:mail])
+      info { "\nReceived mail (#{event.duration.round(1)}ms)" }
+      debug { event.payload[:mail] }
     end
 
     # An email was generated.
     def process(event)
-      return unless logger.debug?
-      mailer = event.payload[:mailer]
-      action = event.payload[:action]
-      debug("\n#{mailer}##{action}: processed outbound mail in #{event.duration.round(1)}ms")
+      debug do
+        mailer = event.payload[:mailer]
+        action = event.payload[:action]
+        "\n#{mailer}##{action}: processed outbound mail in #{event.duration.round(1)}ms"
+      end
     end
 
     # Use the logger configured for ActionMailer::Base

actionpack/lib/action_controller/log_subscriber.rb

@@ -16,50 +16,51 @@ def start_processing(event)
     end
 
     def process_action(event)
-      return unless logger.info?
-
-      payload   = event.payload
-      additions = ActionController::Base.log_process_action(payload)
-
-      status = payload[:status]
-      if status.nil? && payload[:exception].present?
-        exception_class_name = payload[:exception].first
-        status = ActionDispatch::ExceptionWrapper.status_code_for_exception(exception_class_name)
+      info do
+        payload   = event.payload
+        additions = ActionController::Base.log_process_action(payload)
+
+        status = payload[:status]
+        if status.nil? && payload[:exception].present?
+          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 #{event.duration.round}ms"
+        message << " (#{additions.join(" | ")})" unless additions.blank?
+        message
       end
-      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].inspect} rendered or redirected")
+      info { "Filter chain halted as #{event.payload[:filter].inspect} rendered or redirected" }
     end
 
     def send_file(event)
-      info("Sent file #{event.payload[:path]} (#{event.duration.round(1)}ms)")
+      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 #{event.payload[:filename]} (#{event.duration.round(1)}ms)")
+      info { "Sent data #{event.payload[:filename]} (#{event.duration.round(1)}ms)" }
     end
 
     def unpermitted_parameters(event)
-      unpermitted_keys = event.payload[:keys]
-      debug("Unpermitted parameter#{'s' if unpermitted_keys.size > 1}: #{unpermitted_keys.join(", ")}")
+      debug do
+        unpermitted_keys = event.payload[:keys]
+        "Unpermitted parameter#{'s' if unpermitted_keys.size > 1}: #{unpermitted_keys.join(", ")}"
+      end
     end
 
     def deep_munge(event)
-      message = "Value for params[:#{event.payload[:keys].join('][:')}] was set "\
-                "to nil, because it was one of [], [null] or [null, null, ...]. "\
-                "Go to http://guides.rubyonrails.org/security.html#unsafe-query-generation "\
-                "for more information."\
-
-      debug(message)
+      debug do
+        "Value for params[:#{event.payload[:keys].join('][:')}] was set "\
+        "to nil, because it was one of [], [null] or [null, null, ...]. "\
+        "Go to http://guides.rubyonrails.org/security.html#unsafe-query-generation "\
+        "for more information."\
+      end
     end
 
     %w(write_fragment read_fragment exist_fragment?

actionview/lib/action_view/log_subscriber.rb

@@ -13,11 +13,11 @@ def initialize
     end
 
     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 << " (#{event.duration.round(1)}ms)"
-      info(message)
+      info do
+        message = "  Rendered #{from_rails_root(event.payload[:identifier])}"
+        message << " within #{from_rails_root(event.payload[:layout])}" if event.payload[:layout]
+        message << " (#{event.duration.round(1)}ms)"
+      end
     end
     alias :render_partial :render_template
     alias :render_collection :render_template

activesupport/lib/active_support/testing/tagged_logging.rb

@@ -6,7 +6,7 @@ module TaggedLogging #:nodoc:
       attr_writer :tagged_logger
 
       def before_setup
-        if tagged_logger
+        if tagged_logger && tagged_logger.info?
           heading = "#{self.class}: #{name}"
           divider = '-' * heading.size
           tagged_logger.info divider

railties/lib/rails/rack/logger.rb

@@ -34,7 +34,7 @@ def call_app(request, env)
 
         instrumenter = ActiveSupport::Notifications.instrumenter
         instrumenter.start 'request.action_dispatch', request: request
-        logger.info started_request_message(request)
+        logger.info { started_request_message(request) }
         resp = @app.call(env)
         resp[2] = ::Rack::BodyProxy.new(resp[2]) { finish(request) }
         resp