Merge pull request #17 from visits-works/feature/with_header_option

Add 'headers' option to log request headers

README.md

@@ -53,13 +53,17 @@ The middleware logger can be customized with the following options:
 
 * The `:logger` option can be any object that responds to `.info(String)`
 * The `:filter` option can be any object that responds to `.filter(Hash)` and returns a hash.
+* The `:headers` option can be either `:all` or array of strings.
+    + If `:all`, all request headers will be output.
+    + If array, output will be filtered by names in the array. (case-insensitive)
 
 For example:
 
 ```ruby
 insert_after Grape::Middleware::Formatter, Grape::Middleware::Logger, {
   logger: Logger.new(STDERR),
-  filter: Class.new { def filter(opts) opts.reject { |k, _| k.to_s == 'password' } end }.new
+  filter: Class.new { def filter(opts) opts.reject { |k, _| k.to_s == 'password' } end }.new,
+  headers: %w(version cache-control)
 }
 ```
 

lib/grape/middleware/logger.rb

@@ -7,7 +7,7 @@ class Grape::Middleware::Logger < Grape::Middleware::Globals
   attr_reader :logger
 
   class << self
-    attr_accessor :logger, :filter
+    attr_accessor :logger, :filter, :headers
 
     def default_logger
       default = Logger.new(STDOUT)
@@ -19,6 +19,7 @@ def default_logger
   def initialize(_, options = {})
     super
     @options[:filter] ||= self.class.filter
+    @options[:headers] ||= self.class.headers
     @logger = options[:logger] || self.class.logger || self.class.default_logger
   end
 
@@ -34,6 +35,7 @@ def before
     ]
     logger.info %Q(Processing by #{processed_by})
     logger.info %Q(  Parameters: #{parameters})
+    logger.info %Q(  Headers: #{headers}) if @options[:headers]
   end
 
   # @note Error and exception handling are required for the +after+ hooks
@@ -91,6 +93,18 @@ def parameters
     end
   end
 
+  def headers
+    request_headers = env[Grape::Env::GRAPE_REQUEST_HEADERS].to_hash
+    return Hash[request_headers.sort] if @options[:headers] == :all
+
+    headers_needed = Array(@options[:headers])
+    result = {}
+    headers_needed.each do |need|
+      result.merge!(request_headers.select { |key, value| need.to_s.casecmp(key).zero? })
+    end
+    Hash[result.sort]
+  end
+
   def start_time
     @start_time ||= Time.now
   end

spec/factories.rb

@@ -32,8 +32,10 @@ def call(_env)
     grape_request { build :grape_request }
     grape_endpoint { build(:grape_endpoint) }
     params { grape_request.params }
+    headers { grape_request.headers }
     post_params { { 'secret' => 'key', 'customer' => [] } }
     rails_post_params { { 'name' => 'foo', 'password' => 'access' } }
+    other_env_params { {} }
 
     initialize_with do
       new.merge(
@@ -42,10 +44,21 @@ def call(_env)
         'action_dispatch.request.request_parameters' => rails_post_params,
         Grape::Env::GRAPE_REQUEST => grape_request,
         Grape::Env::GRAPE_REQUEST_PARAMS => params,
+        Grape::Env::GRAPE_REQUEST_HEADERS => headers,
         Grape::Env::RACK_REQUEST_FORM_HASH => post_params,
         Grape::Env::API_ENDPOINT => grape_endpoint
-      )
+      ).merge(other_env_params)
     end
+
+    trait :prefixed_basic_headers do
+      other_env_params { {
+        'HTTP_VERSION' => 'HTTP/1.1',
+        'HTTP_CACHE_CONTROL' => 'max-age=0',
+        'HTTP_USER_AGENT' => 'Mozilla/5.0',
+        'HTTP_ACCEPT_LANGUAGE' => 'en-US'
+      } }
+    end
+
   end
 
   factory :grape_endpoint, class: Grape::Endpoint do
@@ -84,9 +97,20 @@ def call(_env)
   end
 
   factory :grape_request, class: OpenStruct do
+    headers { {} }
+
     initialize_with {
-      new(request_method: 'POST', path: '/api/1.0/users', headers: {}, params: { 'id' => '101001' })
+      new(request_method: 'POST', path: '/api/1.0/users', headers: headers, params: { 'id' => '101001' })
     }
+
+    trait :basic_headers do
+      headers { {
+        'Version' => 'HTTP/1.1',
+        'Cache-Control' => 'max-age=0',
+        'User-Agent' => 'Mozilla/5.0',
+        'Accept-Language' => 'en-US'
+      } }
+    end
   end
 
   factory :app do

spec/integration/lib/grape/middleware/headers_option_spec.rb

@@ -0,0 +1,65 @@
+require 'spec_helper'
+
+describe Grape::Middleware::Logger, type: :integration do
+  let(:app) { build :app }
+
+  subject { described_class.new(app, options) }
+
+  let(:grape_endpoint) { build(:grape_endpoint) }
+  let(:env) { build(:expected_env, :prefixed_basic_headers, grape_endpoint: grape_endpoint) }
+
+  context ':all option is set to option headers' do
+    let(:options) { {
+      filter: build(:param_filter),
+      headers: :all,
+      logger: Logger.new(Tempfile.new('logger'))
+    } }
+    it 'all headers will be shown, headers will be sorted by name' do
+      expect(subject.logger).to receive(:info).with ''
+      expect(subject.logger).to receive(:info).with %Q(Started POST "/api/1.0/users" at #{subject.start_time})
+      expect(subject.logger).to receive(:info).with %Q(Processing by TestAPI/users)
+      expect(subject.logger).to receive(:info).with %Q(  Parameters: {"id"=>"101001", "secret"=>"[FILTERED]", "customer"=>[], "name"=>"foo", "password"=>"[FILTERED]"})
+      expect(subject.logger).to receive(:info).with %Q(  Headers: {"Accept-Language"=>"en-US", "Cache-Control"=>"max-age=0", "User-Agent"=>"Mozilla/5.0", "Version"=>"HTTP/1.1"})
+      expect(subject.logger).to receive(:info).with /Completed 200 in \d+.\d+ms/
+      expect(subject.logger).to receive(:info).with ''
+      subject.call!(env)
+    end
+  end
+
+  context 'list of names ["User-Agent", "Cache-Control"] is set to option headers' do
+    let(:options) { {
+      filter: build(:param_filter),
+      headers: %w(User-Agent Cache-Control),
+      logger: Logger.new(Tempfile.new('logger'))
+    } }
+    it 'two headers will be shown' do
+      expect(subject.logger).to receive(:info).with ''
+      expect(subject.logger).to receive(:info).with %Q(Started POST "/api/1.0/users" at #{subject.start_time})
+      expect(subject.logger).to receive(:info).with %Q(Processing by TestAPI/users)
+      expect(subject.logger).to receive(:info).with %Q(  Parameters: {"id"=>"101001", "secret"=>"[FILTERED]", "customer"=>[], "name"=>"foo", "password"=>"[FILTERED]"})
+      expect(subject.logger).to receive(:info).with %Q(  Headers: {"Cache-Control"=>"max-age=0", "User-Agent"=>"Mozilla/5.0"})
+      expect(subject.logger).to receive(:info).with /Completed 200 in \d+.\d+ms/
+      expect(subject.logger).to receive(:info).with ''
+      subject.call!(env)
+    end
+  end
+
+  context 'a single string "Cache-Control" is set to option headers' do
+    let(:options) { {
+      filter: build(:param_filter),
+      headers: 'Cache-Control',
+      logger: Logger.new(Tempfile.new('logger'))
+    } }
+    it 'only Cache-Control header will be shown' do
+      expect(subject.logger).to receive(:info).with ''
+      expect(subject.logger).to receive(:info).with %Q(Started POST "/api/1.0/users" at #{subject.start_time})
+      expect(subject.logger).to receive(:info).with %Q(Processing by TestAPI/users)
+      expect(subject.logger).to receive(:info).with %Q(  Parameters: {"id"=>"101001", "secret"=>"[FILTERED]", "customer"=>[], "name"=>"foo", "password"=>"[FILTERED]"})
+      expect(subject.logger).to receive(:info).with %Q(  Headers: {"Cache-Control"=>"max-age=0"})
+      expect(subject.logger).to receive(:info).with /Completed 200 in \d+.\d+ms/
+      expect(subject.logger).to receive(:info).with ''
+      subject.call!(env)
+    end
+  end
+
+end

spec/lib/grape/middleware/headers_option_spec.rb

@@ -0,0 +1,57 @@
+require 'spec_helper'
+
+describe Grape::Middleware::Logger do
+  let(:app) { double('app') }
+
+  subject { described_class.new(app, options) }
+
+  describe '#headers' do
+    let(:grape_request) { build :grape_request, :basic_headers }
+    let(:env) { build :expected_env, grape_request: grape_request }
+
+    before { subject.instance_variable_set(:@env, env) }
+
+    context 'when @options[:headers] has a symbol :all' do
+      let(:options) { { headers: :all, logger: Object.new } }
+      it 'all request headers should be retrieved' do
+        expect(subject.headers.fetch('Accept-Language')).to eq('en-US')
+        expect(subject.headers.fetch('Cache-Control')).to eq('max-age=0')
+        expect(subject.headers.fetch('User-Agent')).to eq('Mozilla/5.0')
+        expect(subject.headers.fetch('Version')).to eq('HTTP/1.1')
+      end
+    end
+
+    context 'when @options[:headers] is a string "user-agent"' do
+      let(:options) { { headers: 'user-agent', logger: Object.new } }
+      it 'only "User-Agent" should be retrieved' do
+        expect(subject.headers.fetch('User-Agent')).to eq('Mozilla/5.0')
+        expect(subject.headers.length).to eq(1)
+      end
+    end
+
+    context 'when @options[:headers] is an array of ["user-agent", "Cache-Control", "Unknown"]' do
+      let(:options) { { headers: %w(user-agent Cache-Control Unknown), logger: Object.new } }
+      it '"User-Agent" and "Cache-Control" should be retrieved' do
+        expect(subject.headers.fetch('Cache-Control')).to eq('max-age=0')
+        expect(subject.headers.fetch('User-Agent')).to eq('Mozilla/5.0')
+      end
+      it '"Unknown" name does not make any effect' do
+        expect(subject.headers.length).to eq(2)
+      end
+    end
+  end
+
+  describe '#headers if no request header' do
+    let(:env) { build :expected_env }
+    before { subject.instance_variable_set(:@env, env) }
+
+    context 'when @options[:headers] is set, but no request header is there' do
+      let(:options) { { headers: %w(user-agent Cache-Control), logger: Object.new } }
+      it 'subject.headers should return empty hash' do
+        expect(subject.headers.length).to eq(0)
+      end
+    end
+  end
+
+end
+