Merge pull request rails#41809 from bbuchalter/bb.improved_strong_params_logging

Provide context when logging unpermitted parameters

Author: rafaelfranca

actionpack/CHANGELOG.md

@@ -1,3 +1,8 @@
+*   Expand payload of `unpermitted_parameters.action_controller` instrumentation to allow subscribers to
+    know which controller action received unpermitted parameters.
+
+    *bbuchalter*
+
 *   Add `ActionController::Live#send_stream` that makes it more convenient to send generated streams:
 
     ```ruby

actionpack/lib/action_controller/log_subscriber.rb

@@ -56,7 +56,9 @@ def send_data(event)
     def unpermitted_parameters(event)
       debug do
         unpermitted_keys = event.payload[:keys]
-        color("Unpermitted parameter#{'s' if unpermitted_keys.size > 1}: #{unpermitted_keys.map { |e| ":#{e}" }.join(", ")}", RED)
+        display_unpermitted_keys = unpermitted_keys.map { |e| ":#{e}" }.join(", ")
+        context = event.payload[:context].map { |k, v| "#{k}: #{v}" }.join(", ")
+        color("Unpermitted parameter#{'s' if unpermitted_keys.size > 1}: #{display_unpermitted_keys}. Context: { #{context} }", RED)
       end
     end
 

actionpack/lib/action_controller/metal/strong_parameters.rb

@@ -106,11 +106,13 @@ def initialize # :nodoc:
   #
   # * +permit_all_parameters+ - If it's +true+, all the parameters will be
   #   permitted by default. The default is +false+.
-  # * +action_on_unpermitted_parameters+ - Allow to control the behavior when parameters
-  #   that are not explicitly permitted are found. The values can be +false+ to just filter them
-  #   out, <tt>:log</tt> to additionally write a message on the logger, or <tt>:raise</tt> to raise
-  #   ActionController::UnpermittedParameters exception. The default value is <tt>:log</tt>
-  #   in test and development environments, +false+ otherwise.
+  # * +action_on_unpermitted_parameters+ - Controls behavior when parameters that are not explicitly
+  #    permitted are found. The default value is <tt>:log</tt> in test and development environments,
+  #    +false+ otherwise. The values can be:
+  #   * +false+ to take no action.
+  #   * <tt>:log</tt> to emit an <tt>ActiveSupport::Notifications.instrument</tt> event on the
+  #     <tt>unpermitted_parameters.action_controller</tt> topic and log at the DEBUG level.
+  #   * <tt>:raise</tt> to raise a <tt>ActionController::UnpermittedParameters</tt> exception.
   #
   # Examples:
   #
@@ -277,8 +279,9 @@ def nested_attribute?(key, value) # :nodoc:
     #   params = ActionController::Parameters.new(name: "Francesco")
     #   params.permitted?  # => true
     #   Person.new(params) # => #<Person id: nil, name: "Francesco">
-    def initialize(parameters = {})
+    def initialize(parameters = {}, logging_context = {})
       @parameters = parameters.with_indifferent_access
+      @logging_context = logging_context
       @permitted = self.class.permit_all_parameters
     end
 
@@ -968,7 +971,7 @@ def unpermitted_parameters!(params)
           case self.class.action_on_unpermitted_parameters
           when :log
             name = "unpermitted_parameters.action_controller"
-            ActiveSupport::Notifications.instrument(name, keys: unpermitted_keys)
+            ActiveSupport::Notifications.instrument(name, keys: unpermitted_keys, context: @logging_context)
           when :raise
             raise ActionController::UnpermittedParameters.new(unpermitted_keys)
           end
@@ -1184,7 +1187,15 @@ module StrongParameters
     # Returns a new ActionController::Parameters object that
     # has been instantiated with the <tt>request.parameters</tt>.
     def params
-      @_params ||= Parameters.new(request.parameters)
+      @_params ||= begin
+        context = {
+          controller: self.class.name,
+          action: action_name,
+          request: request,
+          params: request.filtered_parameters
+        }
+        Parameters.new(request.parameters, context)
+      end
     end
 
     # Assigns the given +value+ to the +params+ hash. If +value+

actionpack/test/controller/parameters/log_on_unpermitted_params_test.rb

@@ -13,22 +13,21 @@ def teardown
   end
 
   test "logs on unexpected param" do
-    params = ActionController::Parameters.new(
-      book: { pages: 65 },
-      fishing: "Turnips")
+    request_params = { book: { pages: 65 }, fishing: "Turnips" }
+    context = { "action" => "my_action", "controller" => "my_controller" }
+    params = ActionController::Parameters.new(request_params, context)
 
-    assert_logged("Unpermitted parameter: :fishing") do
+    assert_logged("Unpermitted parameter: :fishing. Context: { action: my_action, controller: my_controller }") do
       params.permit(book: [:pages])
     end
   end
 
   test "logs on unexpected params" do
-    params = ActionController::Parameters.new(
-      book: { pages: 65 },
-      fishing: "Turnips",
-      car: "Mersedes")
+    request_params = { book: { pages: 65 }, fishing: "Turnips", car: "Mersedes" }
+    context = { "action" => "my_action", "controller" => "my_controller" }
+    params = ActionController::Parameters.new(request_params, context)
 
-    assert_logged("Unpermitted parameters: :fishing, :car") do
+    assert_logged("Unpermitted parameters: :fishing, :car. Context: { action: my_action, controller: my_controller }") do
       params.permit(book: [:pages])
     end
   end
@@ -37,7 +36,7 @@ def teardown
     params = ActionController::Parameters.new(
       book: { pages: 65, title: "Green Cats and where to find then." })
 
-    assert_logged("Unpermitted parameter: :title") do
+    assert_logged("Unpermitted parameter: :title. Context: {  }") do
       params.permit(book: [:pages])
     end
   end
@@ -46,7 +45,7 @@ def teardown
     params = ActionController::Parameters.new(
       book: { pages: 65, title: "Green Cats and where to find then.", author: "G. A. Dog" })
 
-    assert_logged("Unpermitted parameters: :title, :author") do
+    assert_logged("Unpermitted parameters: :title, :author. Context: {  }") do
       params.permit(book: [:pages])
     end
   end

guides/source/active_support_instrumentation.md

@@ -280,9 +280,10 @@ INFO. Additional keys may be added by the caller.
 
 ### unpermitted_parameters.action_controller
 
-| Key     | Value            |
-| ------- | ---------------- |
-| `:keys` | Unpermitted keys |
+| Key           | Value                                                                 |
+| ------------- | --------------------------------------------------------------------- |
+| `:key`        | The unpermitted keys                                                  |
+| `:context`    | Hash with the following keys: :controller, :action, :params, :request |
 
 Action Dispatch
 ---------------

guides/source/configuring.md

@@ -526,7 +526,10 @@ The schema dumper adds two additional configuration options:
 
 * `config.action_controller.permit_all_parameters` sets all the parameters for mass assignment to be permitted by default. The default value is `false`.
 
-* `config.action_controller.action_on_unpermitted_parameters` enables logging or raising an exception if parameters that are not explicitly permitted are found. Set to `:log` or `:raise` to enable. The default value is `:log` in development and test environments, and `false` in all other environments.
+* `config.action_controller.action_on_unpermitted_parameters` controls behavior when parameters that are not explicitly permitted are found. The default value is `:log` in test and development environments, `false` otherwise. The values can be:
+    * `false` to take no action
+    * `:log` to emit an `ActiveSupport::Notifications.instrument` event on the `unpermitted_parameters.action_controller` topic and log at the DEBUG level
+    * `:raise` to raise a `ActionController::UnpermittedParameters` exception
 
 * `config.action_controller.always_permitted_parameters` sets a list of permitted parameters that are permitted by default. The default values are `['controller', 'action']`.