Do not send the whole controller in notifications, cherry pick required pieces.

5 files changed, 54 insertions, 22 deletions

diff --git a/actionpack/lib/action_controller/base.rb b/actionpack/lib/action_controller/base.rb
index 4f564a6377..260e5da336 100644
--- a/actionpack/lib/action_controller/base.rb
+++ b/actionpack/lib/action_controller/base.rb
@@ -32,12 +32,12 @@ module ActionController
     include ActionController::Streaming
     include ActionController::HttpAuthentication::Basic::ControllerMethods
     include ActionController::HttpAuthentication::Digest::ControllerMethods
-    include ActionController::FilterParameterLogging
     include ActionController::Translation
 
     # Add instrumentations hooks at the bottom, to ensure they instrument
     # all the methods properly.
     include ActionController::Instrumentation
+    include ActionController::FilterParameterLogging
 
     # TODO: Extract into its own module
     # This should be moved together with other normalizing behavior
diff --git a/actionpack/lib/action_controller/metal/filter_parameter_logging.rb b/actionpack/lib/action_controller/metal/filter_parameter_logging.rb
index 9e03f50759..0b1e1ee6ab 100644
--- a/actionpack/lib/action_controller/metal/filter_parameter_logging.rb
+++ b/actionpack/lib/action_controller/metal/filter_parameter_logging.rb
@@ -58,6 +58,11 @@ module ActionController
 
   protected
 
+    def append_info_to_payload(payload)
+      super
+      payload[:params] = filter_parameters(request.params)
+    end
+
     def filter_parameters(params)
       params.dup.except!(*INTERNAL_PARAMS)
     end
diff --git a/actionpack/lib/action_controller/metal/instrumentation.rb b/actionpack/lib/action_controller/metal/instrumentation.rb
index 4549f6c451..7222b7b2fa 100644
--- a/actionpack/lib/action_controller/metal/instrumentation.rb
+++ b/actionpack/lib/action_controller/metal/instrumentation.rb
@@ -2,7 +2,10 @@ require 'abstract_controller/logger'
 
 module ActionController
   # Adds instrumentation to several ends in ActionController::Base. It also provides
-  # some hooks related with process_action logging and view runtime.
+  # some hooks related with process_action, this allows an ORM like ActiveRecord
+  # and/or DataMapper to plug in ActionController and show related information.
+  #
+  # Check ActiveRecord::Railties::ControllerRuntime for an example.
   module Instrumentation
     extend ActiveSupport::Concern
 
@@ -13,9 +16,17 @@ module ActionController
     attr_internal :view_runtime
 
     def process_action(action, *args)
-      ActiveSupport::Notifications.instrument("action_controller.process_action",
-        :controller => self, :action => action) do
-        super
+      ActiveSupport::Notifications.instrument("action_controller.process_action") do |payload|
+        result = super
+        payload[:controller]  = self.class.name
+        payload[:action]      = self.action_name
+        payload[:formats]     = request.formats.map(&:to_s)
+        payload[:remote_ip]   = request.remote_ip
+        payload[:method]      = request.method
+        payload[:status]      = response.status
+        payload[:request_uri] = request.request_uri rescue "unknown"
+        append_info_to_payload(payload)
+        result
       end
     end
 
@@ -47,11 +58,16 @@ module ActionController
     end
 
     def redirect_to(*args)
-      super
-      ActiveSupport::Notifications.instrument("action_controller.redirect_to",
-        :status => self.status, :location => self.location)
+      ActiveSupport::Notifications.instrument("action_controller.redirect_to") do |payload|
+        result = super
+        payload[:status]   = self.status
+        payload[:location] = self.location
+        result
+      end
     end
 
+  protected
+
     # A hook which allows you to clean up any time taken into account in
     # views wrongly, like database querying time.
     #
@@ -64,13 +80,20 @@ module ActionController
       yield
     end
 
+    # Everytime after an action is processed, this method is invoked
+    # with the payload, so you can add more information.
+    # :api: plugin
+    def append_info_to_payload(payload) #:nodoc:
+      payload[:view_runtime] = view_runtime
+    end
+
     module ClassMethods
       # A hook which allows other frameworks to log what happened during
       # controller process action. This method should return an array
       # with the messages to be added.
       # :api: plugin
-      def log_process_action(controller) #:nodoc:
-        messages, view_runtime = [], controller.send(:view_runtime)
+      def log_process_action(payload) #:nodoc:
+        messages, view_runtime = [], payload[:view_runtime]
         messages << ("Views: %.1fms" % view_runtime.to_f) if view_runtime
         messages
       end
diff --git a/actionpack/lib/action_controller/railties/subscriber.rb b/actionpack/lib/action_controller/railties/subscriber.rb
index 0556c6b40e..a9f5d16c58 100644
--- a/actionpack/lib/action_controller/railties/subscriber.rb
+++ b/actionpack/lib/action_controller/railties/subscriber.rb
@@ -2,22 +2,19 @@ module ActionController
   module Railties
     class Subscriber < Rails::Subscriber
       def process_action(event)
-        controller = event.payload[:controller]
-        request    = controller.request
+        payload = event.payload
 
-        info "\nProcessed #{controller.class.name}##{event.payload[:action]} " \
-          "to #{request.formats.join(', ')} (for #{request.remote_ip} at #{event.time.to_s(:db)}) " \
-          "[#{request.method.to_s.upcase}]"
+        info "\nProcessed #{payload[:controller]}##{payload[:action]} " \
+          "to #{payload[:formats].join(', ')} (for #{payload[:remote_ip]} at #{event.time.to_s(:db)}) " \
+          "[#{payload[:method].to_s.upcase}]"
 
-        params = controller.send(:filter_parameters, request.params)
-        info "  Parameters: #{params.inspect}" unless params.empty?
+        info "  Parameters: #{payload[:params].inspect}" unless payload[:params].blank?
 
-        additions = ActionController::Base.log_process_action(controller)
+        additions = ActionController::Base.log_process_action(payload)
 
         message = "Completed in %.0fms" % event.duration
         message << " (#{additions.join(" | ")})" unless additions.blank?
-        message << " | #{controller.response.status}"
-        message << " [#{request.request_uri rescue "unknown"}]\n\n"
+        message << " | #{payload[:status]} [#{payload[:request_uri]}]\n\n"
 
         info(message)
       end
diff --git a/activerecord/lib/active_record/railties/controller_runtime.rb b/activerecord/lib/active_record/railties/controller_runtime.rb
index a4f4e15c2e..aed1c59b00 100644
--- a/activerecord/lib/active_record/railties/controller_runtime.rb
+++ b/activerecord/lib/active_record/railties/controller_runtime.rb
@@ -5,6 +5,8 @@ module ActiveRecord
     module ControllerRuntime
       extend ActiveSupport::Concern
 
+    protected
+
       attr_internal :db_runtime
 
       def cleanup_view_runtime
@@ -19,9 +21,14 @@ module ActiveRecord
         end
       end
 
+      def append_info_to_payload(payload)
+        super
+        payload[:db_runtime] = db_runtime
+      end
+
       module ClassMethods
-        def log_process_action(controller)
-          messages, db_runtime = super, controller.send(:db_runtime)
+        def log_process_action(payload)
+          messages, db_runtime = super, payload[:db_runtime]
           messages << ("ActiveRecord: %.1fms" % db_runtime.to_f) if db_runtime
           messages
         end