From eb63aa03e14e8b0d5a0697684c418a3a2d087f50 Mon Sep 17 00:00:00 2001 From: Rodrigo Souto Date: Fri, 29 May 2015 18:35:13 -0300 Subject: [PATCH 1/5] add support for obfuscated parameters Now you may override the method 'sensitive_parameters' with a list of parameters that should be obfuscated on the log. If the lib is loaded on a Rails application, uses the 'filter_parameters' attribute as default value for 'sensitive_parameters'. --- lib/grape_logging/middleware/request_logger.rb | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-) diff --git a/lib/grape_logging/middleware/request_logger.rb b/lib/grape_logging/middleware/request_logger.rb index 121fe9c..424b640 100644 --- a/lib/grape_logging/middleware/request_logger.rb +++ b/lib/grape_logging/middleware/request_logger.rb @@ -23,7 +23,7 @@ module GrapeLogging def parameters(request, response) { path: request.path, - params: request.params.to_hash, + params: obfuscate_parameters(request.params), method: request.request_method, total: total_runtime, db: @db_duration.round(2), @@ -51,6 +51,18 @@ module GrapeLogging def stop_time @stop_time ||= Time.now end + + def obfuscate_parameters(request_parameters) + filtered_parameters = request_parameters.clone.to_hash + sensitive_parameters.each do |param| + filtered_parameters[param.to_s] = '***' + end + filtered_parameters + end + + def sensitive_parameters + defined?(Rails.application) ? Rails.application.config.filter_parameters : [] + end end end end \ No newline at end of file From 7ba9b5b83a4c719290c409c07c7a036166923546 Mon Sep 17 00:00:00 2001 From: Duncan Williams Date: Mon, 13 Jul 2015 14:31:50 +0100 Subject: [PATCH 2/5] using pluggable loggers separating out the base logger behaviour and logging of specific parts of request / response into pluggable components also setting the defualt formatter for the logger --- lib/grape_logging.rb | 6 +- lib/grape_logging/formatters/default.rb | 4 +- lib/grape_logging/loggers/base.rb | 12 ++++ lib/grape_logging/loggers/database_time.rb | 21 +++++++ .../loggers/filter_parameters.rb | 23 ++++++++ lib/grape_logging/loggers/response.rb | 11 ++++ .../middleware/request_logger.rb | 55 +++++++++---------- 7 files changed, 100 insertions(+), 32 deletions(-) create mode 100644 lib/grape_logging/loggers/base.rb create mode 100644 lib/grape_logging/loggers/database_time.rb create mode 100644 lib/grape_logging/loggers/filter_parameters.rb create mode 100644 lib/grape_logging/loggers/response.rb diff --git a/lib/grape_logging.rb b/lib/grape_logging.rb index 282ad3e..10dee2b 100644 --- a/lib/grape_logging.rb +++ b/lib/grape_logging.rb @@ -1,4 +1,8 @@ require 'grape_logging/multi_io' require 'grape_logging/version' require 'grape_logging/formatters/default' -require 'grape_logging/middleware/request_logger' \ No newline at end of file +require 'grape_logging/middleware/request_logger' +require 'grape_logging/loggers/base' +require 'grape_logging/loggers/database_time' +require 'grape_logging/loggers/response' +require 'grape_logging/loggers/filter_parameters' diff --git a/lib/grape_logging/formatters/default.rb b/lib/grape_logging/formatters/default.rb index dda10bb..54c1344 100644 --- a/lib/grape_logging/formatters/default.rb +++ b/lib/grape_logging/formatters/default.rb @@ -11,7 +11,7 @@ module GrapeLogging elsif data.is_a?(Exception) format_exception(data) elsif data.is_a?(Hash) - "#{data.delete(:status)} -- total=#{data.delete(:total)} db=#{data.delete(:db)} -- #{data.delete(:method)} #{data.delete(:path)} #{format_hash(data)}" + "#{data.delete(:status)} -- #{format_hash(data.delete(:time))} -- #{data.delete(:method)} #{data.delete(:path)} #{format_hash(data)}" else data.inspect end @@ -28,4 +28,4 @@ module GrapeLogging end end end -end \ No newline at end of file +end diff --git a/lib/grape_logging/loggers/base.rb b/lib/grape_logging/loggers/base.rb new file mode 100644 index 0000000..e0e65e1 --- /dev/null +++ b/lib/grape_logging/loggers/base.rb @@ -0,0 +1,12 @@ +module GrapeLogging + module Logger + class Base + def before + end + + def parameters(request, response) + {} + end + end + end +end diff --git a/lib/grape_logging/loggers/database_time.rb b/lib/grape_logging/loggers/database_time.rb new file mode 100644 index 0000000..ab84a45 --- /dev/null +++ b/lib/grape_logging/loggers/database_time.rb @@ -0,0 +1,21 @@ +module GrapeLogging + module Logger + class DatabaseTime < GrapeLogging::Logger::Base + def before + @duration = 0 + ActiveSupport::Notifications.subscribe('sql.active_record') do |*args| + event = ActiveSupport::Notifications::Event.new(*args) + @duration += event.duration + end + end + + def parameters(request, response) + { + time: { + db: @duration.round(2) + } + } + end + end + end +end diff --git a/lib/grape_logging/loggers/filter_parameters.rb b/lib/grape_logging/loggers/filter_parameters.rb new file mode 100644 index 0000000..a3cfe05 --- /dev/null +++ b/lib/grape_logging/loggers/filter_parameters.rb @@ -0,0 +1,23 @@ +module GrapeLogging + module Logger + class FilterParameters < GrapeLogging::Logger::Base + def initialize(filter_parameters = nil, replacement = '[FILTERED]') + @filter_parameters = filter_parameters || (defined?(Rails.application) ? Rails.application.config.filter_parameters : []) + @replacement = replacement + end + + def parameters(request, response) + filtered_parameters = request.params.clone + @filter_parameters.each do |param| + if filtered_parameters[param.to_s] + filtered_parameters[param.to_s] = @replacement + end + end + + { + params: filtered_parameters + } + end + end + end +end diff --git a/lib/grape_logging/loggers/response.rb b/lib/grape_logging/loggers/response.rb new file mode 100644 index 0000000..04f8980 --- /dev/null +++ b/lib/grape_logging/loggers/response.rb @@ -0,0 +1,11 @@ +module GrapeLogging + module Logger + class Response < GrapeLogging::Logger::Base + def parameters(request, response) + { + response: response.body + } + end + end + end +end diff --git a/lib/grape_logging/middleware/request_logger.rb b/lib/grape_logging/middleware/request_logger.rb index 424b640..3621a12 100644 --- a/lib/grape_logging/middleware/request_logger.rb +++ b/lib/grape_logging/middleware/request_logger.rb @@ -3,39 +3,47 @@ require 'grape/middleware/base' module GrapeLogging module Middleware class RequestLogger < Grape::Middleware::Base + def initialize(app, options = {}) + super + @logger = @options[:logger] || Logger.new(STDOUT) + @logger.formatter = @options[:formatter] || GrapeLogging::Formatters::Default.new + @included_loggers = @options[:include] || [] + end + def before start_time - - @db_duration = 0 - ActiveSupport::Notifications.subscribe('sql.active_record') do |*args| - event = ActiveSupport::Notifications::Event.new(*args) - @db_duration += event.duration - end if defined?(ActiveRecord) + included_loggers.each do |included_logger| + included_logger.before + end end def after stop_time - logger.info parameters(request, response) + + parameters = parameters(request, response) + included_loggers.each do |included_logger| + parameters.merge! included_logger.parameters(request, response) do |key, oldval, newval| + oldval.respond_to?(:merge) ? oldval.merge(newval) : newval + end + end + @logger.info parameters nil end protected def parameters(request, response) { - path: request.path, - params: obfuscate_parameters(request.params), - method: request.request_method, - total: total_runtime, - db: @db_duration.round(2), - status: response.status + status: response.status, + time: { + total: total_runtime + }, + method: request.request_method, + path: request.path, + params: obfuscate_parameters(request.params) } end private - def logger - @logger ||= @options[:logger] || Logger.new(STDOUT) - end - def request @request ||= ::Rack::Request.new(env) end @@ -52,17 +60,6 @@ module GrapeLogging @stop_time ||= Time.now end - def obfuscate_parameters(request_parameters) - filtered_parameters = request_parameters.clone.to_hash - sensitive_parameters.each do |param| - filtered_parameters[param.to_s] = '***' - end - filtered_parameters - end - - def sensitive_parameters - defined?(Rails.application) ? Rails.application.config.filter_parameters : [] - end end end -end \ No newline at end of file +end From 2c208bd5c5f21c3b4f3b413e15e8d0a47de0424b Mon Sep 17 00:00:00 2001 From: Duncan Williams Date: Mon, 13 Jul 2015 16:38:35 +0100 Subject: [PATCH 3/5] updating README with usage examples --- README.md | 30 +++++++++++++++++++++++++----- 1 file changed, 25 insertions(+), 5 deletions(-) diff --git a/README.md b/README.md index 93b07c2..14c8095 100644 --- a/README.md +++ b/README.md @@ -10,7 +10,7 @@ Add this line to your application's Gemfile: And then execute: - $ bundle + $ bundle install Or install it yourself as: @@ -18,11 +18,11 @@ Or install it yourself as: ## Basic Usage -In your api file (somewhere on the top) - - logger.formatter = GrapeLogging::Formatters::Default.new - use GrapeLogging::Middleware::RequestLogger, { logger: logger } +Include the middleware in your api + class MyAPI < Grape::API + use GrapeLogging::Middleware::RequestLogger, logger: logger + end ## Features @@ -34,6 +34,26 @@ With the default configuration you will get nice log message If you prefer some other format I strongly encourage you to do pull request with new formatter class ;) +You can change the formatter like so + + class MyAPI < Grape::API + use GrapeLogging::Middleware::RequestLogger, logger: logger, format: MyFormatter.new + end + +### Customising What Is Logged + +You can include logging of other parts of the request / response cycle by including subclasses of `GrapeLogging::Loggers::Base` + + class MyAPI < Grape::API + use GrapeLogging::Middleware::RequestLogger, + logger: logger, + include: [ GrapeLogging::Loggers::Response.new, + GrapeLogging::Loggers::DatabaseTime.new, + GrapeLogging::Loggers::FilterParameters.new ] + end + +The `FilterParameters` logger will filter out sensitive parameters from your logs. If mounted inside rails, will use the `Rails.application.config.filter_parameters` by default. Otherwise, you must specify a list of keys to filter out. + ### Logging to file and STDOUT You can to file and STDOUT at the same time, you just need to assign new logger From 82eab4cc917b13034d4b1b82b636577c44ca8d5c Mon Sep 17 00:00:00 2001 From: Duncan Williams Date: Mon, 13 Jul 2015 17:24:29 +0100 Subject: [PATCH 4/5] fixing some small bugs --- lib/grape_logging/middleware/request_logger.rb | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/lib/grape_logging/middleware/request_logger.rb b/lib/grape_logging/middleware/request_logger.rb index 3621a12..32c7349 100644 --- a/lib/grape_logging/middleware/request_logger.rb +++ b/lib/grape_logging/middleware/request_logger.rb @@ -12,7 +12,7 @@ module GrapeLogging def before start_time - included_loggers.each do |included_logger| + @included_loggers.each do |included_logger| included_logger.before end end @@ -21,7 +21,7 @@ module GrapeLogging stop_time parameters = parameters(request, response) - included_loggers.each do |included_logger| + @included_loggers.each do |included_logger| parameters.merge! included_logger.parameters(request, response) do |key, oldval, newval| oldval.respond_to?(:merge) ? oldval.merge(newval) : newval end @@ -39,7 +39,7 @@ module GrapeLogging }, method: request.request_method, path: request.path, - params: obfuscate_parameters(request.params) + params: request.params } end From a05e0181019b22220f37485c64f58983c49171f6 Mon Sep 17 00:00:00 2001 From: Duncan Williams Date: Mon, 10 Aug 2015 11:09:49 +0100 Subject: [PATCH 5/5] using module name of Loggers rather than Logger also explicit to_s on response body --- lib/grape_logging/loggers/base.rb | 2 +- lib/grape_logging/loggers/database_time.rb | 4 ++-- lib/grape_logging/loggers/filter_parameters.rb | 4 ++-- lib/grape_logging/loggers/response.rb | 6 +++--- 4 files changed, 8 insertions(+), 8 deletions(-) diff --git a/lib/grape_logging/loggers/base.rb b/lib/grape_logging/loggers/base.rb index e0e65e1..c098eae 100644 --- a/lib/grape_logging/loggers/base.rb +++ b/lib/grape_logging/loggers/base.rb @@ -1,5 +1,5 @@ module GrapeLogging - module Logger + module Loggers class Base def before end diff --git a/lib/grape_logging/loggers/database_time.rb b/lib/grape_logging/loggers/database_time.rb index ab84a45..ec754fc 100644 --- a/lib/grape_logging/loggers/database_time.rb +++ b/lib/grape_logging/loggers/database_time.rb @@ -1,6 +1,6 @@ module GrapeLogging - module Logger - class DatabaseTime < GrapeLogging::Logger::Base + module Loggers + class DatabaseTime < GrapeLogging::Loggers::Base def before @duration = 0 ActiveSupport::Notifications.subscribe('sql.active_record') do |*args| diff --git a/lib/grape_logging/loggers/filter_parameters.rb b/lib/grape_logging/loggers/filter_parameters.rb index a3cfe05..2559310 100644 --- a/lib/grape_logging/loggers/filter_parameters.rb +++ b/lib/grape_logging/loggers/filter_parameters.rb @@ -1,6 +1,6 @@ module GrapeLogging - module Logger - class FilterParameters < GrapeLogging::Logger::Base + module Loggers + class FilterParameters < GrapeLogging::Loggers::Base def initialize(filter_parameters = nil, replacement = '[FILTERED]') @filter_parameters = filter_parameters || (defined?(Rails.application) ? Rails.application.config.filter_parameters : []) @replacement = replacement diff --git a/lib/grape_logging/loggers/response.rb b/lib/grape_logging/loggers/response.rb index 04f8980..31f7ca7 100644 --- a/lib/grape_logging/loggers/response.rb +++ b/lib/grape_logging/loggers/response.rb @@ -1,9 +1,9 @@ module GrapeLogging - module Logger - class Response < GrapeLogging::Logger::Base + module Loggers + class Response < GrapeLogging::Loggers::Base def parameters(request, response) { - response: response.body + response: response.body.to_s } end end