aserafin / grape_logging

Request logging for Grape!
MIT License
147 stars 76 forks source link

Use "insert 0" instead of "use" in README #60

Open abicky opened 5 years ago

abicky commented 5 years ago

The status code won't be correct when it is changed in rescue_from block, so use "insert 0" instead of "use" in README.

I describe more details below.

Before

class MyApi < Grape::API
  use GrapeLogging::Middleware::RequestLogger

  rescue_from :all do |e|
    error!('bad request', 400)
  end

  get do
    raise 'error'
  end
end
% curl -i localhost:3000
HTTP/1.1 400 Bad Request
Content-Type: text/plain
Cache-Control: no-cache
X-Request-Id: 8e5d48cf-c752-4e45-aaa0-ef9c2ac197ef
X-Runtime: 0.030238
Content-Length: 11

bad request

The server log is like below:

[2019-05-02 00:29:25 +0900] INFO -- 500 -- db=0 total=4.98 view=4.98 -- GET / host=localhost params={}

As you can see, the status code in the log is 500 in spite of the fact that the actual status code is 400.

After

class MyApi < Grape::API
  insert 0, GrapeLogging::Middleware::RequestLogger

  rescue_from :all do |e|
    error!('bad request', 400)
  end

  get do
    raise 'error'
  end
end
% curl -i localhost:3000
HTTP/1.1 400 Bad Request
Content-Type: text/plain
Cache-Control: no-cache
X-Request-Id: ba717065-72f3-4de1-8b6d-21b6258714bc
X-Runtime: 0.016160
Content-Length: 11

bad request

The server log is like below:

[2019-05-02 00:30:33 +0900] INFO -- 400 -- db=0 total=1.46 view=1.46 -- GET / host=localhost params={}

Why is the status code incorrect if we use "use"?

The block of rescue_from is called by a subclass of Grape::Middleware::Error but the middleware stack is like below if we use "use":

  1. Rack::Head
  2. A subclass of Grape::Middleware::Error
  3. GrapeLogging::Middleware::RequestLogger

cf. https://github.com/ruby-grape/grape/blob/v1.2.3/lib/grape/endpoint.rb#L282-L294

We can change the order by using "insert 0" and we can see the correct status code in our log.

  1. GrapeLogging::Middleware::RequestLogger
  2. Rack::Head
  3. A subclass of Grape::Middleware::Error
thedarkside commented 3 years ago

Thank you for the explanation. Ive already reported it in https://github.com/aserafin/grape_logging/issues/45, partially changed with https://github.com/aserafin/grape_logging/pull/74 and i have finalized it in the same way by opening the pr https://github.com/aserafin/grape_logging/pull/75

Haven't seen this pr up until now.