aserafin / grape_logging Goto Github PK

View Code? Open in Web Editor NEW

146.0 146.0 76.0 87 KB

Request logging for Grape!

License: MIT License

Ruby 99.65% Shell 0.35%

grape_logging's People

Stargazers

Watchers

grape_logging's Issues

Under the concurrent consumption of memory

Under the concurrent consumption of memory!!!!!

RequestHeaders class could be include Content-Type header?

In case of POST/PUT/PATCH methods, HTTP headers has Content-Type.

However, RequestHeaders class does not generate Content-Type.
Personally, I hope include Content-Type in RequestHeaders class.

Is not it necessary?

GrapeLogging is slow in production when running long time.

I'm using GrapeLogging version 1.8.1 (Latest release at this time) on my production environment. But If I running for long time it's consume many time of my process (Around 80~90% only for GrapeLogging).

I tracking time by New Relic. Segment of process is "GrapeLogging::Middleware::RequestLogger#call"

I'm not sure about these problem came from GrapeLogging but I want to know anyone face these problem like me? How to deal with it?

I'm using jruby:9.1-jre-alpine docker's base image.

undefined method `keys' + undefined method `clear_tags!'

Hi,

I'm using grape inside Rails. When using Rails.logger as logger and GrapeLogging::Formatters::Default as formatter, I receive these exceptions ( complete backtrace ) when grape tries to log the request.

This is my configuration:

module Foobar
  class Api < Grape::API
    logger Rails.logger

    use GrapeLogging::Middleware::RequestLogger,
      logger: logger,
      formatter: GrapeLogging::Formatters::Default.new,
      include: [ GrapeLogging::Loggers::Response.new,
                 GrapeLogging::Loggers::FilterParameters.new,
                 GrapeLogging::Loggers::ClientEnv.new,
                 GrapeLogging::Loggers::RequestHeaders.new ]

I noticed that if I change logger Rails.logger with logger Rails.logger.dup it works, without any exception. Why?

Thread-safety

I was looking into expanding our API logging when I stumbled upon this Gem. When exploring its inner workings I found an issue with your middleware, it is not thread-safe because instance variables are used and passed whilst the middleware is used in a concurrent manner. See:
https://github.com/aserafin/grape_logging/blob/6e562a278864a382bf5cf37cda7bad8924f0ad29/lib/grape_logging/middleware/request_logger.rb#L60C34-L60C38

The @env can be overwritten during the call! causing the request and responds to mismatch, effectively sending a response that was meant for another client.

You could add this disclaimer to the readme, patch it or yank the gem altogether as it seems to no longer be maintained. Since I am not a user I won't be submitting a PR to fix it, but thank you for creating the gem regardless, its a nice insight to see how you solved it.

Formatter setting doesn't seem to work

Hi, thanks you for making this great gem GrapeLogging.
I have a problem with formatter setting.

I'm trying to change log formatter from default one to GrapeLogging::Formatters::Lograge, but it doesn't seem to work.

For example, "time" key exists even after update.
Here is an actual response in localhost.

response (some params are masked)

{:status=>403, :time=>{:total=>189.43, :db=>3.74, :view=>185.69}, :method=>"POST", :path=>"/api/v1/users/login", :params=>{"xxx"=>"xxx", "xxx"=>"xxx"}, :host=>"localhost", :response=>{:xxx=>"xxx"}}

And here is my related gem versions and related codes.

versions

rails => 5.0.1
grape => 1.0.1
grape_logging => 1.7.0

codes

app/api/xxx/v1/base.rb

class XXX::V1
  class Base < Grape::API
    use GrapeLogging::Middleware::RequestLogger,
        instrumentation_key: 'grape_key',
        formatter: GrapeLogging::Formatters::Lograge.new,
        include: [
          GrapeLogging::Loggers::Response.new,
          GrapeLogging::Loggers::FilterParameters.new,
          GrapeLogging::Loggers::RequestHeaders.new,
        ]
  end
end

config/environments/development.rb

Rails.application.configure do
  ...
  config.logger = ActFluentLoggerRails::Logger.new
  config.lograge.enabled = true
  config.lograge.formatter = Lograge::Formatters::Raw.new
end

config/initializers/lograge.rb

Rails.application.configure do
  config.lograge.base_controller_class = 'Grape::API'
end

Could you tell me how to fix it?
Thanks.

Logging to file and not STDOUT

Hello, i used the logging to a file option and it works well.
I'm trying to remove logging to STDOUT and keep only logging to an external file.
Is that possible?

What units are the logged times in?

We're getting log entries like this:

time={:total=>40.79, :db=>1945.44}

Does this mean 40 seconds total and 1945 ms in the database?

Pass status code to loggers

Right now the loggers only have access to the request and response_body, but it would be nice to have access to the status code as well. For now, we're working around the problem by storing the intended status code in the request.env, but this is not ideal.

Not sure the best way to support this without breaking compatibility of the parameters call in

grape_logging/lib/grape_logging/middleware/request_logger.rb

Line 140 in fd8d2d4

params.merge! logger.parameters(request, response_body) do |_, oldval, newval|

. We could check if the signature accepts an optional 3rd argument?

Unnecessary line in grape_logger.rb

Can you please remove this line:
https://github.com/aserafin/grape_logging/blob/master/lib/grape_logging.rb#L11
It's a leftover from my PR and not needed.

NoMethodError: undefined method `+' for nil:NilClass

I have a Grape API in a Rails application, and I'm sub-classing GrapeLogging::Middleware::RequestLogger so I can sanitize the #parameters method. I'm getting an error in production that is originating at /gems/grape_logging-1.0.2/lib/grape_logging/middleware/request_logger.rb:11 in block in before. It looks like env[:db_duration] is returning nil. Details below.

Versions:

grape (0.10.1)
grape-entity (0.4.4)
grape_logging (1.0.2)
rails (4.2.1)

Sub-class:

module Api::Middleware
  class RequestLogger < GrapeLogging::Middleware::RequestLogger
    protected

    def parameters(response, duration)
      filters = Rails.application.config.filter_parameters
      ActionDispatch::Http::ParameterFilter.new(filters).filter(super)
    end
  end
end

Usage:

use Api::Middleware::RequestLogger, { logger: Rails.logger }

Stacktrace:

/gems/grape_logging-1.0.2/lib/grape_logging/middleware/request_logger.rb:11 in block in before
/gems/activesupport-4.2.1/lib/active_support/notifications/fanout.rb:127 in call
/gems/activesupport-4.2.1/lib/active_support/notifications/fanout.rb:127 in finish
/gems/activesupport-4.2.1/lib/active_support/notifications/fanout.rb:46 in block in finish
/gems/activesupport-4.2.1/lib/active_support/notifications/fanout.rb:46 in each
/gems/activesupport-4.2.1/lib/active_support/notifications/fanout.rb:46 in finish
/gems/activesupport-4.2.1/lib/active_support/notifications/instrumenter.rb:36 in finish
/gems/activesupport-4.2.1/lib/active_support/notifications/instrumenter.rb:25 in instrument
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/abstract_adapter.rb:467 in log
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/postgresql/database_statements.rb:154 in execute
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/postgresql/schema_statements.rb:275 in client_min_messages=
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/postgresql_adapter.rb:673 in configure_connection
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/postgresql_adapter.rb:658 in connect
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/postgresql_adapter.rb:242 in initialize
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/postgresql_adapter.rb:44 in new
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/postgresql_adapter.rb:44 in postgresql_connection
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:438 in new_connection
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:448 in checkout_new_connection
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:422 in acquire_connection
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:349 in block in checkout
/data/gdweb/.rbenv/versions/2.1.5/lib/ruby/2.1.0/monitor.rb:211 in mon_synchronize
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:348 in checkout
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:263 in block in connection
/data/gdweb/.rbenv/versions/2.1.5/lib/ruby/2.1.0/monitor.rb:211 in mon_synchronize
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:262 in connection
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:567 in retrieve_connection
/gems/activerecord-4.2.1/lib/active_record/connection_handling.rb:113 in retrieve_connection
/gems/activerecord-4.2.1/lib/active_record/connection_handling.rb:87 in connection
/gems/activerecord-4.2.1/lib/active_record/query_cache.rb:51 in restore_query_cache_settings
/gems/activerecord-4.2.1/lib/active_record/query_cache.rb:43 in rescue in call
/gems/activerecord-4.2.1/lib/active_record/query_cache.rb:31 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/activerecord-4.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:649 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/actionpack-4.2.1/lib/action_dispatch/middleware/callbacks.rb:29 in block in call
/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:88 in call
/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:88 in _run_callbacks
/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:776 in _run_call_callbacks
/gems/activesupport-4.2.1/lib/active_support/callbacks.rb:81 in run_callbacks
/gems/actionpack-4.2.1/lib/action_dispatch/middleware/callbacks.rb:27 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/actionpack-4.2.1/lib/action_dispatch/middleware/remote_ip.rb:78 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/actionpack-4.2.1/lib/action_dispatch/middleware/debug_exceptions.rb:17 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/actionpack-4.2.1/lib/action_dispatch/middleware/show_exceptions.rb:30 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/lograge-0.3.0/lib/lograge/rails_ext/rack/logger.rb:15 in call_app
/gems/railties-4.2.1/lib/rails/rack/logger.rb:20 in block in call
/gems/activesupport-4.2.1/lib/active_support/tagged_logging.rb:68 in block in tagged
/gems/activesupport-4.2.1/lib/active_support/tagged_logging.rb:26 in tagged
/gems/activesupport-4.2.1/lib/active_support/tagged_logging.rb:68 in tagged
/gems/railties-4.2.1/lib/rails/rack/logger.rb:20 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/actionpack-4.2.1/lib/action_dispatch/middleware/request_id.rb:21 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/rack-1.6.0/lib/rack/methodoverride.rb:22 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/rack-1.6.0/lib/rack/runtime.rb:18 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/activesupport-4.2.1/lib/active_support/cache/strategy/local_cache_middleware.rb:28 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/rack-1.6.0/lib/rack/sendfile.rb:113 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/railties-4.2.1/lib/rails/engine.rb:518 in call
/gems/railties-4.2.1/lib/rails/application.rb:164 in call
/gems/railties-4.2.1/lib/rails/railtie.rb:194 in public_send
/gems/railties-4.2.1/lib/rails/railtie.rb:194 in method_missing
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
lib/pulse.rb:11 in call
/gems/newrelic_rpm-3.9.9.275/lib/new_relic/agent/instrumentation/middleware_tracing.rb:57 in call
/gems/unicorn-4.8.3/lib/unicorn/http_server.rb:576 in process_client
/gems/unicorn-4.8.3/lib/unicorn/http_server.rb:670 in worker_loop
/gems/unicorn-4.8.3/lib/unicorn/http_server.rb:525 in spawn_missing_workers
/gems/unicorn-4.8.3/lib/unicorn/http_server.rb:536 in maintain_worker_count
/gems/unicorn-4.8.3/lib/unicorn/http_server.rb:294 in join
/gems/unicorn-4.8.3/bin/unicorn:126 in <top (required)>
/data/gdweb/app/current/bin/unicorn:16 in load
/data/gdweb/app/current/bin/unicorn:16 in <main>

Add support for Ruby 2.7?

Hi there,

The tests fails with Ruby 2.7. Here's the Debian bug report:
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=952025

Could you please add support for 2.7? :)

url params missing in params hash

when there is url parameters like

post "(:some_url)/test" do
 #some code here
end

there is no key "some_url" in the params hash.

Release with JSON newline fix

Would it be possible to get a release pushed for the JSON newline fix committed 2 months ago?

Problems using formatters with rails 5 logger

I ran into #48 and from what I can tell, formatters would not work when passing in the Rails.logger. Suppose we have this:

use GrapeLogging::Middleware::RequestLogger, { logger: Rails.logger, formatter: GrapeLogging::Formatters::Json.new }

It looks like log reporter would attempt to set the Rails.logger formatter globally

  class LoggerReporter
    def initialize(logger, formatter, log_level)
      @logger = logger || Logger.new(STDOUT)
      @log_level = log_level || :info
      if @logger.respond_to?(:formatter=)
        @logger.formatter = formatter || @logger.formatter || GrapeLogging::Formatters::Default.new
      end
    end

This won't work because Rails assumes the formatter is of type ActiveSupport::TaggedLogging::Formatter and we get the error mentioned in #48.

undefined method `clear_tags!

Either way I am not sure we would actually want to set the GrapeLogging Formatter globally on the Rails.logger as this seems a bit heavy handed.

To get around this issue, I used the instrumentation_key feature and avoid using Rails.logger and GrapeLogging formatters altogether.

use GrapeLogging::Middleware::RequestLogger, {
  instrumentation_key: 'grape_logging',
  include: [GrapeLogging::Loggers::FilterParameters.new]
}

ActiveSupport::Notifications.subscribe('grape_logging') do |_name, _starts, _ends, _notification_id, payload|
  Rails.logger.info("API request #{payload.to_json}")
end

This is fine for my purposes but I am not sure of the right way to use grape log formatters and Rails.logger together.

Rails 6.0.0.rc1 deprecation warning: ActionDispatch::Http::ParameterFilter

ParameterFilter inherits from ActionDispatch::Http::ParameterFilter which will be removed from Rails 6.1:

DEPRECATION WARNING: ActionDispatch::Http::ParameterFilter is deprecated and will be removed from Rails 6.1. Use ActiveSupport::ParameterFilter instead.

[question] Can I include multiple log levels instead of just one?

class API < Grape::API
  # ...
  logger.formatter = GrapeLogging::Formatters::Default.new
  log_file = File.open('./log/logfile.log', 'a')
  log_file.sync = true
  logger Logger.new GrapeLogging::MultiIO.new(STDOUT, log_file)
  insert_after Rack::Head, GrapeLogging::Middleware::RequestLogger, logger: logger, log_level: :info, include: [
    GrapeLogging::Loggers::ClientEnv.new,
    GrapeLogging::Loggers::RequestHeaders.new
  ]

  # ...
end

If I am understanding the readme file correctly, I am only able to specify one log log level, is there a way to specify multiple? And if there is, can it be added to the readme , that would be amazing :)

`ArgumentError` is raised if the keys of `parameters` include invalid byte sequence

We use GrapeLogging::Middleware::RequestLogger like below:

class MyApi < Grape::API
  use GrapeLogging::Middleware::RequestLogger, {
    include: [GrapeLogging::Loggers::FilterParameters.new],
  }
  post {}
end

If we send a request whose body includes invalid byte sequence, ArgumentError is raised.

echo -e '{"\xff":1}' | curl -X POST -H 'Content-Type: application/json' localhost:3000 --data-binary @-

Here is the server log:

ArgumentError (invalid byte sequence in UTF-8):

actionpack (5.2.1) lib/action_dispatch/http/parameter_filter.rb:63:in `=~'
actionpack (5.2.1) lib/action_dispatch/http/parameter_filter.rb:63:in `block (2 levels) in call'
actionpack (5.2.1) lib/action_dispatch/http/parameter_filter.rb:63:in `any?'
actionpack (5.2.1) lib/action_dispatch/http/parameter_filter.rb:63:in `block in call'
actionpack (5.2.1) lib/action_dispatch/http/parameter_filter.rb:61:in `each'
actionpack (5.2.1) lib/action_dispatch/http/parameter_filter.rb:61:in `call'
actionpack (5.2.1) lib/action_dispatch/http/parameter_filter.rb:15:in `filter'
grape_logging (1.7.0) lib/grape_logging/loggers/filter_parameters.rb:32:in `clean_parameters'
grape_logging (1.7.0) lib/grape_logging/loggers/filter_parameters.rb:27:in `safe_parameters'
grape_logging (1.7.0) lib/grape_logging/loggers/filter_parameters.rb:13:in `parameters'
grape_logging (1.7.0) lib/grape_logging/middleware/request_logger.rb:140:in `block (2 levels) in collect_parameters'
(snip)

Push update to rubygems

Is it possible to push an update version v1.4.0 to rubygems?
I would like to have it in my project.

Thanks!

Not working with grape 0.12

After upgrading I see:

NoMethodError (undefined method `downcase' for 2:Fixnum)

An issue that response method tries to get an array values from @app_response, but it can't because @app_response stores Rack::Response instead of an array.

Don't know yet how to fix that issue, any suggestion can be helpful and transformed into a PR.

Don't fail when response is `nil`

As of ruby-grape/grape#1240 the #after hook is called on even when exception is raised. This breaks grape_logging which assumes response, (@app_response) to be set see: https://github.com/aserafin/grape_logging/blob/master/lib/grape_logging/middleware/request_logger.rb#L36

See ruby-grape/grape#1265 for discussion

Request: Add logger definitions for the default included fields

As im going through and adding the log output to my ELK stack, i have to parse out the logged fields, but unfortunately there are no definitions for the order of fields being output, is it possible to have these added to the documentation, or to the wiki :)

Failing tests

Hi,

Whilst building this against Ruby2.7 and grape (1.3.1), I get the following failures:

Failures:

  1) GrapeLogging::Formatters::Rails#call exception data returns a string with a backtrace
     Failure/Error: expect(lines[1]).to include 'grape_logging'
       expected "\t/usr/share/rubygems-integration/all/gems/rspec-core-3.9.1/lib/rspec/core/example.rb:257:in `instance_exec'" to include "grape_logging"
     # ./spec/lib/grape_logging/formatters/rails_spec.rb:40:in `block (4 levels) in <top (required)>'

  2) GrapeLogging::Loggers::Response with a parseable JSON body returns an array of parseable JSON objects
     Failure/Error:
       expect(subject.parameters(nil, response)).to eq({
         response: [response.body.first.dup]
       })
     
       expected: {:response=>["{\"one\": \"two\", \"three\": {\"four\": 5}}"]}
            got: {:response=>[{"one"=>"two", "three"=>{"four"=>5}}]}
     
       (compared using ==)
     
       Diff:
       @@ -1,2 +1,2 @@
       -:response => ["{\"one\": \"two\", \"three\": {\"four\": 5}}"],
       +:response => [{"one"=>"two", "three"=>{"four"=>5}}],
       
     # ./spec/lib/grape_logging/loggers/response_spec.rb:11:in `block (3 levels) in <top (required)>'

Finished in 0.10391 seconds (files took 1.5 seconds to load)
34 examples, 2 failures

Failed examples:

rspec ./spec/lib/grape_logging/formatters/rails_spec.rb:33 # GrapeLogging::Formatters::Rails#call exception data returns a string with a backtrace
rspec ./spec/lib/grape_logging/loggers/response_spec.rb:10 # GrapeLogging::Loggers::Response with a parseable JSON body returns an array of parseable JSON objects

disable logging during tests

I use grape_logging in a rails app and I'd like to disable it when I run my test suite. What should I write in my rails_helper ?

NameError: uninitialized constant Grape::Middleware::Base::Helpers

Ref: ruby-grape/grape#1939 (comment)

Here is the complete stack:

NameError: uninitialized constant Grape::Middleware::Base::Helpers
  /Users/pboling/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/grape-1.3.1/lib/grape/middleware/base.rb:8:in `<class:Base>'
  /Users/pboling/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/grape-1.3.1/lib/grape/middleware/base.rb:7:in `<module:Middleware>'
  /Users/pboling/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/grape-1.3.1/lib/grape/middleware/base.rb:6:in `<module:Grape>'
  /Users/pboling/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/grape-1.3.1/lib/grape/middleware/base.rb:5:in `<top (required)>'
  /Users/pboling/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/grape_logging-1.8.3/lib/grape_logging/middleware/request_logger.rb:1:in `require'
  /Users/pboling/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/grape_logging-1.8.3/lib/grape_logging/middleware/request_logger.rb:1:in `<top (required)>'
  /Users/pboling/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/grape_logging-1.8.3/lib/grape_logging.rb:16:in `require'
  /Users/pboling/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/grape_logging-1.8.3/lib/grape_logging.rb:16:in `<top (required)>'
  config.ru:3:in `require'
  config.ru:3:in `block in <main>'
  /Users/pboling/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/rack-2.2.2/lib/rack/builder.rb:116:in `eval'

Removing grape_logging from the project fixes the issue. @dblock says:

If this fixes that feels like grape_logging should be doing a require 'grape'. Open an issue in that repo.

Seems like this repo needs to require 'grape' somewhere.

UPDATE: If I move require 'grape_logging' to spot in the load order after I am sure grape has been loaded, then this error goes away. This gem, as is, doesn't load grape properly on it's own, but allowing bundler to load grape works.

In other words, if I have a require 'grape_logging' early on, before bundler loads my environment, then I get this error with latest version of grape.

Hat tip to @robert-hromej who had the right idea.

uninitialized constant ActiveSupport::ParameterFilter in version 1.8.3 with rails 6

I am on Rails 6. Version 1.8.2 and 1.8.3 and throwing following error:

`block in load_missing_constant': uninitialized constant ActiveSupport::ParameterFilter (NameError)

however 1.8.1 is working. Disabling the gem makes the app work again:

Loading development environment (Rails 6.0.0)
irb(main):001:0> ActiveSupport::ParameterFilter
=> ActiveSupport::ParameterFilter

Feedback needed :)

Hi,

I've just merged almost all PR's for the grape_logging and I want to thank you all for your hard work! I will be running master version of gem in my projects during next week to make sure it's stable before pushing to rubygems and it would be really great if you could do the same and post your findings here :)

@diguliu @guizmaii @marshall-lee @987poiuytrewq @yalongzhang @jtmarmon @holstvoogd @scauglog @ayanko @rngtng

wrong status code 500 logged

I am using the newest gem versions. It looks like the logger is executed before the rescue_from which sets the statuscode.

  logger.formatter = GrapeLogging::Formatters::Default.new
  use GrapeLogging::Middleware::RequestLogger, logger: logger, include: [ GrapeLogging::Loggers::Response.new,
                                                                               GrapeLogging::Loggers::FilterParameters.new,
                                                                               GrapeLogging::Loggers::ClientEnv.new,
                                                                               GrapeLogging::Loggers::RequestHeaders.new ]

  rescue_from WineBouncer::Errors::OAuthUnauthorizedError do |e|
    error! e, 401
  end

Log fail status code

Is there a way to log the status code for a fail? So instead of getting :status=>"fail" I would like to see :status=>405 or whatever.

Using GrapeLogging::Formatters logs does not trigger Logstash file input

Hi there,

I was doing some tests with grape_logging and Logstash, using GrapeLogging::Formatters::Logstash, and i encountered a problem. My logs where been written into the log file but Logstash wasn't getting any of them.

That also happened when i used GrapeLogging::Formatters::Json.

Using the Default formatter doesn't cause this problem.

logstash.conf

input {
  file {
    type => "test"
    path =>"/tmp/log/*.log"
  }
}
filter {

}
output {
  elasticsearch {
    index => "logstash"
    hosts => ["localhost:9200"]
  }
  stdout { }
}

api.rb

class API < Grape::API
  format :json
  log_file = File.open('/tmp/log/test.log', 'a+')
  log_file.sync = true
  logger Logger.new GrapeLogging::MultiIO.new(STDOUT, log_file)
  logger.formatter = GrapeLogging::Formatters::Logstash.new
  use GrapeLogging::Middleware::RequestLogger, {
    logger: logger,
    include: [ GrapeLogging::Loggers::Response.new,
                    GrapeLogging::Loggers::FilterParameters.new,
                    GrapeLogging::Loggers::ClientEnv.new,
                    GrapeLogging::Loggers::RequestHeaders.new ]
   }
end

Filtering for all loggers

Currently only FilterParameters logger exists to filter sensitive information from request parameters, but similarly sensitive information can also be contained in Request Headers as well as Response (e.g. the Authorization header, which could contain access token).

I have subclassed the FilterParameters logger for now, to achieve such result, but probably it would be best to move the filtering to Logger::Base.

  class FilterResponseLogger < GrapeLogging::Loggers::FilterParameters
    def parameters(_, response)
      response && response.respond_to?(:body) ? { response: clean_response(response) } : {}
    end

    private
    def clean_response(response)
      case response.header['Content-Type']
      when 'application/json'
        body = JSON.parse(response.body.first) #it's stored inside an array
        parameter_filter.filter(body).reject{ |key, _value| @exceptions.include?(key) }
      else
        # Better to not log, than log with sensitive data
        "FilterResponseLogger: Don't know how to filter '#{response.header['Content-Type']}' response, skipping."
      end
    rescue
      # Can't really log the error message here, as that could itself contain sensitive data
      # e.g. JSON.parse with invalid data will put whole data into the error message.
      "FilterResponseLogger: Error filtering response, skipping."
    end
  end

  class FilterRequestHeaderLogger < GrapeLogging::Loggers::FilterParameters
    HTTP_PREFIX = 'HTTP_'.freeze

    def parameters(request, _)
      headers = {}

      request.env.each_pair do |k, v|
        next unless k.to_s.start_with? HTTP_PREFIX

        k = k[HTTP_PREFIX.size..-1].split('_').each(&:capitalize!).join('-')
        headers[k] = v
      end

      { headers: clean_headers(headers) }
    end

    private
    def clean_headers(headers)
      parameter_filter.filter(headers).reject{ |key, _value| @exceptions.include?(key) }
    rescue
      # Can't really log the error message here, as that could itself contain sensitive data
      # e.g. JSON.parse with invalid data will put whole data into the error message.
      "FilterRequestHeaderLogger: Error filtering request headers, skipping."
    end
  end

What do you think?

Failing GrapeLogging::Formatters::Rails#call test

I ran the test suite using ruby2.5 and I got one failure:

Failures:

  1) GrapeLogging::Formatters::Rails#call exception data returns a string with a backtrace
     Failure/Error: expect(lines[1]).to include 'grape_logging'
       expected "\t/usr/lib/ruby/vendor_ruby/rspec/core/example.rb:254:in `instance_exec'" to include "grape_logging"
     # ./spec/lib/grape_logging/formatters/rails_spec.rb:40:in `block (4 levels) in <top (required)>'

Have you ever faced this issue? I saw that the tests are passing in travis but with ruby2.3

how to append log file to log/development.log

logger Logger.new(GrapeLogging::MultiIO.new(STDOUT, File.open("#{Rails.root}/log/development.log"), 'a'))

But throw me

log writing failed. not opened for writing

Reporters::LoggerReporter should not modify the global logger

in Reports::LoggerReporter initialization it stores the original reference to the logger that is passed in instead of cloning the object. Thus if a custom formatter is provided as parameter this formatter is also applied to the global logger which is an undesirable behaviour.

ActiveSupport::ParameterFilter depends on Rails > 6.0

The most recent release of grape_logging depends on ActiveSupport::ParameterFilter, which is only compatible with Rails 6.

This broke my Rails 5.2 application upon upgrading. Please update the gemspec to prevent updating past 1.8.1 for Rails 5.2 or modify the code to handle both Rails versions.

Make formatter optional

There are logger implementations that don't expose `.formatter. Make grape-logging compatible with them!