filter_parameters的作用是(摘自rails 4 way):

When a request is made to your application, by default Rails logs details such as the request path, HTTP  method, IP Address, and parameters. If an attacker somehow gained access to your logs, they may be able to  view sensitive information, like passwords and credit card numbers

The filter_parameter_logging.rb initializer let’s you specify what request parameters should be filtered  from your log files. If Rails receives a request parameter included in the filter_parameters collection, it will  mark it as [FILTERED] in your logs

一般在自动生成的rails项目中的,config/initializers/filter_parameter_logging.rb中,都会预先提供这一行

Rails.application.config.filter_parameters += [:password]


看看filter_parameters定义在哪里

$ depot git:(master) rails c
irb(main):002:0> Rails.application.config.method(:filter_parameters).source_location
=> ["/home/z/.rbenv/versions/2.4.0/lib/ruby/gems/2.4.0/gems/railties-5.0.2/lib/rails/application/configuration.rb", 12]


到源码里看,可发现filter_parameters是attr_accessor,于是对@filter_parameters进行跟踪

module Rails
  class Application
    class Configuration < ::Rails::Engine::Configuration
      attr_accessor :allow_concurrency, :asset_host, :autoflush_log,
                    :cache_classes, :cache_store, :consider_all_requests_local, :console,
                    :eager_load, :exceptions_app, :file_watcher, :filter_parameters,
                    :force_ssl, :helpers_paths, :logger, :log_formatter, :log_tags,
                    :railties_order, :relative_url_root, :secret_key_base, :secret_token,
                    :ssl_options, :public_file_server,
                    :session_options, :time_zone, :reload_classes_only_on_change,
                    :beginning_of_week, :filter_redirect, :x, :enable_dependency_loading

      attr_writer :log_level
      attr_reader :encoding, :api_only, :static_cache_control

      def initialize(*)
        super
        self.encoding = "utf-8"
        @allow_concurrency               = nil
        @consider_all_requests_local     = false
        #@filter_parameters               = []
        @filter_parameters               = Called.on [], log: '/tmp/filter_parameters.html'


但唯一一处会调用它的,就是config/initializers/filter_parameter_logging.rb


于是直接搜索所有源码

$ gems git:(master) grep filter_parameters -rn *
actionpack-5.0.2/CHANGELOG.md:662:        config.filter_parameters += [ "credit_card.code" ]
actionpack-5.0.2/lib/action_dispatch/http/request.rb:10:require 'action_dispatch/http/filter_parameters'
railties-5.0.2/lib/rails/application.rb:22:  # "cache_classes", "consider_all_requests_local", "filter_parameters",
railties-5.0.2/lib/rails/application.rb:249:          "action_dispatch.parameter_filter" => config.filter_parameters,
railties-5.0.2/lib/rails/application/configuration.rb:14:                    :eager_load, :exceptions_app, :file_watcher, :filter_parameters,
railties-5.0.2/lib/rails/application/configuration.rb:29:        @filter_parameters               = Called.on [], log: '/tmp/filter_parameters.html'
railties-5.0.2/lib/rails/generators/rails/app/templates/config/initializers/filter_parameter_logging.rb:4:Rails.application.config.filter_parameters += [:password]


发现railties-5.0.2/lib/rails/application.rb有将它复制到hash中,源码如下,看上去像是一些全局环境设定什么的

def env_config
  @app_env_config ||= begin
    validate_secret_key_config!

    super.merge(
      "action_dispatch.parameter_filter" => config.filter_parameters,
      "action_dispatch.redirect_filter" => config.filter_redirect,
      "action_dispatch.secret_token" => secrets.secret_token,
      "action_dispatch.secret_key_base" => secrets.secret_key_base,
      "action_dispatch.show_exceptions" => config.action_dispatch.show_exceptions,
      "action_dispatch.show_detailed_exceptions" => config.consider_all_requests_local,
      "action_dispatch.logger" => Rails.logger,
      "action_dispatch.backtrace_cleaner" => Rails.backtrace_cleaner,
      "action_dispatch.key_generator" => key_generator,
      "action_dispatch.http_auth_salt" => config.action_dispatch.http_auth_salt,
      "action_dispatch.signed_cookie_salt" => config.action_dispatch.signed_cookie_salt,
      "action_dispatch.encrypted_cookie_salt" => config.action_dispatch.encrypted_cookie_salt,
      "action_dispatch.encrypted_signed_cookie_salt" => config.action_dispatch.encrypted_signed_cookie_salt,
      "action_dispatch.cookies_serializer" => config.action_dispatch.cookies_serializer,
      "action_dispatch.cookies_digest" => config.action_dispatch.cookies_digest
    )
  end
end


哪里会用到action_dispatch.parameter_filter 这个条目呢?搜索parameter_filter,得

$ gems git:(master) grep parameter_filter -rn *
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:1:require 'action_dispatch/http/parameter_filter'
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:13:    #   env["action_dispatch.parameter_filter"] = [:password]
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:16:    #   env["action_dispatch.parameter_filter"] = [:foo, "bar"]
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:19:    #   env["action_dispatch.parameter_filter"] = [ "credit_card.code" ]
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:23:    #   env["action_dispatch.parameter_filter"] = -> (k, v) do
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:41:        @filtered_parameters ||= parameter_filter.filter(parameters)
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:56:      def parameter_filter
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:57:        parameter_filter_for fetch_header("action_dispatch.parameter_filter") {
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:63:        user_key = fetch_header("action_dispatch.parameter_filter") {
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:66:        parameter_filter_for(Array(user_key) + ENV_MATCH)
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:69:      def parameter_filter_for(filters)
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:77:          parameter_filter.filter([[$1, $2]]).first.join("=")
railties-5.0.2/lib/rails/application.rb:249:          "action_dispatch.parameter_filter" => config.filter_parameters,


发现是ActionDispatch。actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb源码如下,似乎是用config所设定的action_dispatch.parameter_filter的那些key,来new一个ParameterFilter,然后用这个ParameterFilter来过滤请求参数

module ActionDispatch
  module Http
    # Allows you to specify sensitive parameters which will be replaced from
    # the request log by looking in the query string of the request and all
    # sub-hashes of the params hash to filter. Filtering only certain sub-keys
    # from a hash is possible by using the dot notation: 'credit_card.number'.
    # If a block is given, each key and value of the params hash and all
    # sub-hashes is passed to it, the value or key can be replaced using
    # String#replace or similar method.
    #
    #   env["action_dispatch.parameter_filter"] = [:password]
    #   => replaces the value to all keys matching /password/i with "[FILTERED]"
    #
    #   env["action_dispatch.parameter_filter"] = [:foo, "bar"]
    #   => replaces the value to all keys matching /foo|bar/i with "[FILTERED]"
    #
    #   env["action_dispatch.parameter_filter"] = [ "credit_card.code" ]
    #   => replaces { credit_card: {code: "xxxx"} } with "[FILTERED]", does not
    #   change { file: { code: "xxxx"} }
    #
    #   env["action_dispatch.parameter_filter"] = -> (k, v) do
    #     v.reverse! if k =~ /secret/i
    #   end
    #   => reverses the value to all keys matching /secret/i
    module FilterParameters
      ENV_MATCH = [/RAW_POST_DATA/, "rack.request.form_vars"] # :nodoc:
      NULL_PARAM_FILTER = ParameterFilter.new # :nodoc:
      NULL_ENV_FILTER   = ParameterFilter.new ENV_MATCH # :nodoc:

      def initialize
        super
        @filtered_parameters = nil
        @filtered_env        = nil
        @filtered_path       = nil
      end

      # Returns a hash of parameters with all sensitive data replaced.
      def filtered_parameters
        @filtered_parameters ||= parameter_filter.filter(parameters)
      end

      # Returns a hash of request.env with all sensitive data replaced.
      def filtered_env
        @filtered_env ||= env_filter.filter(@env)
      end

    protected

      def parameter_filter
        parameter_filter_for fetch_header("action_dispatch.parameter_filter") {
          return NULL_PARAM_FILTER
        }
      end

      def parameter_filter_for(filters)
        ParameterFilter.new(filters)
      end


那么filtered_parameters会被哪里调用呢?搜索得

$ gems git:(master) grep filtered_parameters -rn *
actionpack-5.0.2/lib/action_controller/metal/instrumentation.rb:21:        :params     => request.filtered_parameters,
actionpack-5.0.2/lib/action_controller/metal/params_wrapper.rb:239:        wrapped_filtered_hash = _wrap_parameters request.filtered_parameters.slice(*wrapped_keys)
actionpack-5.0.2/lib/action_controller/metal/params_wrapper.rb:246:        request.filtered_parameters.merge! wrapped_filtered_hash
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:34:        @filtered_parameters = nil
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:40:      def filtered_parameters
actionpack-5.0.2/lib/action_dispatch/http/filter_parameters.rb:41:        @filtered_parameters ||= parameter_filter.filter(parameters)
actionpack-5.0.2/lib/action_dispatch/middleware/templates/rescues/_request_and_response.html.erb:9:

Parameters:

<%= debug_params(@request.filtered_parameters) %>
actionpack-5.0.2/lib/action_dispatch/middleware/templates/rescues/_request_and_response.text.erb:2:  clean_params = @request.filtered_parameters.clone


发现了log常用的actionpack-5.0.2/lib/action_controller/metal/instrumentation.rb,它源码如下,被mixin到request上的filtered_parameters,会被赋值到raw_payload这个hash中,而raw_payload又被传给了ActiveSupport::Notifications.instrument,被使用了start_processing.action_controller这个hook

module ActionController
  module Instrumentation
    extend ActiveSupport::Concern

    include AbstractController::Logger

    attr_internal :view_runtime

    def process_action(*args)
      raw_payload = {
        :controller => self.class.name,
        :action     => self.action_name,
        :params     => request.filtered_parameters,
        :headers    => request.headers,
        :format     => request.format.ref,
        :method     => request.request_method,
        :path       => request.fullpath
      }

      ActiveSupport::Notifications.instrument("start_processing.action_controller", raw_payload.dup)

      ActiveSupport::Notifications.instrument("process_action.action_controller", raw_payload) do |payload|
        begin
          result = super
          payload[:status] = response.status
          result
        ensure
          append_info_to_payload(payload)
        end
      end
    end


于是搜索start_processing.action_controller这个hook在哪里定义,但无果

$ gems git:(master) grep 'start_processing\.action_controller' -rn *
actionpack-5.0.1/CHANGELOG.md:289:*   Add request headers in the payload of the `start_processing.action_controller`
actionpack-5.0.1/lib/action_controller/metal/instrumentation.rb:28:      ActiveSupport::Notifications.instrument("start_processing.action_controller", raw_payload.dup)
actionpack-5.0.2/CHANGELOG.md:296:*   Add request headers in the payload of the `start_processing.action_controller`
actionpack-5.0.2/lib/action_controller/metal/instrumentation.rb:28:      ActiveSupport::Notifications.instrument("start_processing.action_controller", raw_payload.dup)


若只搜start_processing,得

$ gems git:(master) grep 'start_processing' -rn *
actionpack-5.0.2/CHANGELOG.md:296:*   Add request headers in the payload of the `start_processing.action_controller`
actionpack-5.0.2/lib/action_controller/log_subscriber.rb:5:    def start_processing(event)
actionpack-5.0.2/lib/action_controller/metal/instrumentation.rb:28:      ActiveSupport::Notifications.instrument("start_processing.action_controller", raw_payload.dup)


看名字应该就是actionpack-5.0.2/lib/action_controller/log_subscriber.rb,其源码如下。它会打印Processing by XXX和Parameters XXX,这里就使用了payload[:params],而它正是刚才:params => request.filtered_parameters

module ActionController
  class LogSubscriber < ActiveSupport::LogSubscriber
    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]
      format  = format.to_s.upcase if format.is_a?(Symbol)

      info "Processing by #{payload[:controller]}##{payload[:action]} as #{format}"
      info "  Parameters: #{params.inspect}" unless params.empty?
    end


对比下log输出,可见是一致的

Started POST "/line_items?product_id=5" for 192.168.0.103 at 2017-06-03 21:33:22 +0800
Cannot render console from 192.168.0.103! Allowed networks: 127.0.0.1, ::1, 127.0.0.0/127.255.255.255
Processing by LineItemsController#create as JS
  Parameters: {"authenticity_token"=>"/Gyn4st3ZX5d7b8GhIPGTxLlWF8iE0DeqbNAm688ElTsahRZTnAqDSKHKXVnC4smf8WzKx5WuE5KXyntX5qP7w==", "product_id"=>"5"}
  Cart Load (0.3ms)  SELECT  "carts".* FROM "carts" WHERE "carts"."id" = ? LIMIT ?  [["id", 27], ["LIMIT", 1]]


再回过头来思考下ParameterFilter,如果简单设计的话,就是用config中所设的key来去将请求参数parameters的hash的对应key更新为[FILTERED]字样,但若真去看actionpack-5.0.2/lib/action_dispatch/http/parameter_filter.rb的话,会发现它功能还设计得更复杂更强大

小结:filter_parameters用于在log中屏蔽关键信息,以防泄露机密信息;log(一般都?)用ActiveSupport::Notifications.instrument钩子来输出