From d65714ffd8045bf0eb5e3287b9999724ce19a1fe Mon Sep 17 00:00:00 2001 From: Ryan Buckley Date: Tue, 5 May 2015 22:22:23 -0700 Subject: [PATCH] Specs and update to handle broken state of Grape Globals --- Rakefile | 7 +- grape-middleware-logger.gemspec | 20 ++-- lib/grape/middleware/logger.rb | 42 ++++---- lib/grape/middleware/logger/version.rb | 2 +- spec/lib/grape/middleware/logger_spec.rb | 132 +++++++++++++++++++++++ spec/spec_helper.rb | 8 ++ 6 files changed, 178 insertions(+), 33 deletions(-) create mode 100644 spec/lib/grape/middleware/logger_spec.rb create mode 100644 spec/spec_helper.rb diff --git a/Rakefile b/Rakefile index 809eb56..43c60f2 100644 --- a/Rakefile +++ b/Rakefile @@ -1,2 +1,7 @@ -require "bundler/gem_tasks" +require 'rspec/core/rake_task' +RSpec::Core::RakeTask.new(:spec) do |spec| + spec.pattern = 'spec/**/*_spec.rb' +end +desc 'Run specs' +task default: :spec diff --git a/grape-middleware-logger.gemspec b/grape-middleware-logger.gemspec index 51cf60f..b0d523d 100644 --- a/grape-middleware-logger.gemspec +++ b/grape-middleware-logger.gemspec @@ -1,25 +1,27 @@ # coding: utf-8 lib = File.expand_path('../lib', __FILE__) $LOAD_PATH.unshift(lib) unless $LOAD_PATH.include?(lib) -require 'grape/middleware/logger/version' +require 'grape/middleware/logger' Gem::Specification.new do |spec| - spec.name = "grape-middleware-logger" + spec.name = 'grape-middleware-logger' spec.version = Grape::Middleware::Logger::VERSION - spec.authors = ["Ryan Buckley"] - spec.email = ["arebuckley@gmail.com"] + spec.platform = Gem::Platform::RUBY + spec.authors = ['Ryan Buckley'] + spec.email = ['arebuckley@gmail.com'] spec.summary = %q{Logging middleware for Grape apps} spec.description = %q{Logging middleware for Grape apps, similar to what Rails offers} - spec.homepage = "" - spec.license = "MIT" + spec.homepage = '' + spec.license = 'MIT' spec.files = `git ls-files -z`.split("\x0") spec.executables = spec.files.grep(%r{^bin/}) { |f| File.basename(f) } spec.test_files = spec.files.grep(%r{^(test|spec|features)/}) - spec.require_paths = ["lib"] + spec.require_paths = ['lib'] spec.add_dependency 'grape' - spec.add_development_dependency "bundler", "~> 1.7" - spec.add_development_dependency "rake", "~> 10.0" + spec.add_development_dependency 'bundler', '~> 1.7' + spec.add_development_dependency 'rake', '~> 10.0' + spec.add_development_dependency 'rspec', '>= 3.0' end diff --git a/lib/grape/middleware/logger.rb b/lib/grape/middleware/logger.rb index 8a84cc2..0691219 100644 --- a/lib/grape/middleware/logger.rb +++ b/lib/grape/middleware/logger.rb @@ -1,5 +1,5 @@ -require 'grape/middleware/logger/version' require 'logger' +require 'grape/middleware/globals' module Grape module Middleware @@ -9,22 +9,9 @@ module Grape # Overrides # - def before - @start_time = Time.now - super - logger.info '' - logger.info %Q(Started #{env['grape.request'].request_method} "#{env['grape.request'].path}") - logger.info %Q( Parameters: #{parameters}) - end - - def after(status) - logger.info "Completed #{status} in #{((Time.now - @start_time) * 1000).round(2)}ms" - logger.info '' - end - def call!(env) @env = env - before + _before error = catch(:error) { @app_response = @app.call(@env); nil } if error after_failure(error) @@ -35,10 +22,23 @@ module Grape @app_response end + def after(status) + logger.info "Completed #{status} in #{((Time.now - @start_time) * 1000).round(2)}ms" + logger.info '' + end + # # Helpers # + # @todo rename to +before+ when Grape v0.12.0 is released + def _before + @start_time = Time.now + logger.info '' + logger.info %Q(Started #{env['grape.request'].request_method} "#{env['grape.request'].path}") + logger.info %Q( Parameters: #{parameters}) + end + def after_failure(error) logger.info %Q( Error: #{error[:message]}) if error[:message] after(error[:status]) @@ -47,20 +47,18 @@ module Grape def parameters request_params = env['grape.request.params'].to_hash request_params.merge!(env['action_dispatch.request.request_parameters'] || {}) - filter_params(request_params) - end - - def filter_params(params) if @options[:filter] - @options[:filter].filter(params) + @options[:filter].filter(request_params) else - params + request_params end end def logger - @logger ||= @options[:logger] || Logger.new(STDOUT) + @logger ||= @options[:logger] || ::Logger.new(STDOUT) end end end end + +require 'grape/middleware/logger/version' diff --git a/lib/grape/middleware/logger/version.rb b/lib/grape/middleware/logger/version.rb index ab95cd2..a13bf01 100644 --- a/lib/grape/middleware/logger/version.rb +++ b/lib/grape/middleware/logger/version.rb @@ -1,7 +1,7 @@ module Grape module Middleware class Logger - VERSION = '0.0.1' + VERSION = '0.1.0' end end end diff --git a/spec/lib/grape/middleware/logger_spec.rb b/spec/lib/grape/middleware/logger_spec.rb new file mode 100644 index 0000000..5aea01e --- /dev/null +++ b/spec/lib/grape/middleware/logger_spec.rb @@ -0,0 +1,132 @@ +require 'spec_helper' +require 'grape/middleware/logger' + +describe Grape::Middleware::Logger do + let(:app) { double('app') } + let(:options) { { filter: ParamFilter.new, logger: Object.new } } + + subject { described_class.new(app, options) } + + let(:app_response) { [200, {}, 'Hello World'] } + let(:env) { + { + 'grape.request' => OpenStruct.new(request_method: 'POST', path: '/api/1.0/users'), + 'grape.request.params' => { + 'id' => '101001' + }, + 'action_dispatch.request.request_parameters' => { + 'name' => 'foo', + 'password' => 'access' + } + } + } + describe '#call!' do + context 'when calling the app results in an error response' do + let(:error) { { status: 400 } } + + it 'calls +after_failure+ and rethrows the error' do + expect(app).to receive(:call).with(env).and_throw(:error, error) + expect(subject).to receive(:_before) + expect(subject).to receive(:after_failure).with(error) + expect(subject).to receive(:throw).with(:error, error) + subject.call!(env) + end + end + + context 'when there is no error' do + it 'calls +after+ with the correct status' do + expect(app).to receive(:call).with(env).and_return(app_response) + expect(subject).to receive(:_before) + expect(subject).to receive(:after).with(200) + subject.call!(env) + end + + it 'returns the @app_response' do + expect(app).to receive(:call).with(env).and_return(app_response) + allow(subject).to receive(:_before) + allow(subject).to receive(:after) + expect(subject.call!(env)).to eq app_response + end + end + + describe 'integration' do + it 'properly logs requests' do + expect(app).to receive(:call).with(env).and_return(app_response) + expect(subject.logger).to receive(:info).with('') + expect(subject.logger).to receive(:info).with(%Q(Started POST "/api/1.0/users")) + expect(subject.logger).to receive(:info).with(%Q( Parameters: {"id"=>"101001", "name"=>"foo", "password"=>"[FILTERED]"})) + 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 + + describe '#after_failure' do + let(:error) { { status: 403 } } + + it 'calls +after+ with the :status' do + expect(subject).to receive(:after).with(403) + subject.after_failure(error) + end + + context 'when :message is set in the error object' do + let(:error) { { message: 'Oops, not found' } } + + it 'logs the error message' do + allow(subject).to receive(:after) + expect(subject.logger).to receive(:info).with(Regexp.new(error[:message])) + subject.after_failure(error) + end + end + end + + describe '#parameters' do + before { subject.instance_variable_set(:@env, env) } + + context 'when @options[:filter] is set' do + it 'calls +filter+ with the raw parameters' do + expect(subject.options[:filter]).to receive(:filter).with({ "id" => '101001', "name" => "foo", "password" => "access" }) + subject.parameters + end + + it 'returns the filtered results' do + expect(subject.parameters).to eq({ "id" => '101001', "name" => "foo", "password" => "[FILTERED]" }) + end + end + + context 'when @options[:filter] is nil' do + let(:options) { {} } + + it 'returns the params extracted out of @env' do + expect(subject.parameters).to eq({ "id" => '101001', "name" => "foo", "password" => "access" }) + end + end + end + + describe '#logger' do + context 'when @options[:logger] is nil' do + let(:options) { {} } + + it 'defaults to the the standard Logger' do + expect(subject.logger).to be_a(Logger) + end + end + + context 'when @options[:logger] is set' do + it 'returns the logger object' do + expect(subject.logger).to eq options[:logger] + end + end + end + + # + # Test class + # + + ParamFilter = Class.new do + def filter(opts) + opts.each_pair { |key, val| val[0..-1] = '[FILTERED]' if key == 'password' } + end + end +end diff --git a/spec/spec_helper.rb b/spec/spec_helper.rb new file mode 100644 index 0000000..9e7d559 --- /dev/null +++ b/spec/spec_helper.rb @@ -0,0 +1,8 @@ +$LOAD_PATH.unshift(File.dirname(__FILE__)) +$LOAD_PATH.unshift(File.join(File.dirname(__FILE__), '..', 'lib')) + +require 'ostruct' + +RSpec.configure do |config| + config.raise_errors_for_deprecations! +end