Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

lograge doesn't handle 500 or 404 responses #27

Closed
thoughtafter opened this issue Feb 4, 2013 · 8 comments · May be fixed by #252
Closed

lograge doesn't handle 500 or 404 responses #27

thoughtafter opened this issue Feb 4, 2013 · 8 comments · May be fixed by #252
Labels

Comments

@thoughtafter
Copy link

I have an app, which maybe is doing something strange but it seems like 404 errors caused by missing routes and 500 errors get send to the log file as a stack trace not a single line entry. Am I missing something? In the code it certainly looks like it should be handling 500 errors but it doesn't seem to work.

@thoughtafter
Copy link
Author

Ok, so it looks like ActiveRecord::RecordNotFound is being reported as a 500 error by lograge which is clearly not what is being sent. I get that extract_status is making a guess but in this case it's guessing wrong. And this is the only 500 error in the logs. Other 500 errors show as a stack trace. 404 errors caused by missing routes (ActionController::RoutingError) are also logged as a stack trace.

@roidrage
Copy link
Owner

roidrage commented Feb 5, 2013

Does your application ignore RecordNotFound and turn them into a 404?

If lograge (currently) doesn't receive a status code from the controller, but finds an exception, it outputs that to the logs. With the RecordNotFound it doesn't seem to be getting a status code in your case.

@thoughtafter
Copy link
Author

This app is Rails 3.2.11 and uses exception_notification 2.6.1. Other than that there is no special handling of 404 or 500 errors.

There are 2 separate issues I've run into:

  1. Stack trace errors in logs with ActionController::RoutingError and any 500 exception. I've still not resolved this.
  2. RecordNotFound errors logged as 500 instead of 404. This can be fixed by changing the following in extract_status:
{ :status => 500, :error => "#{exception}:#{message}" }

to:

{
  :status => ActionDispatch::ExceptionWrapper.new({}, exception.constantize.new).status_code,
  :error => "#{exception}:#{message}"
}

@roidrage
Copy link
Owner

roidrage commented Feb 5, 2013

lograge doesn't concern itself with dumping the stacktrace to the logs, happy to be proven wrong, but dumping a stacktrace to the logs on a 500 error is common Rails behaviour.

I can look into using ExceptionWrapper to determine the status code.

@thoughtafter
Copy link
Author

Yes, the issue is not so much the stack trace but the fact that there is no log line for the request which caused it. I believe this is because those exceptions are not caught and logged until the debug_exceptions middleware which is outside the scope of ActiveSupport::LogSubscriber. It's worth mentioning because I assumed, incorrectly, that all 404 and 500 errors would be logged by lograge but they are not. So the behaviour was not what I expected and perhaps that may be the case for others. Still it's a great idea and I appreciate you putting it out there.

@bf4
Copy link

bf4 commented Apr 3, 2015

I do something like

      if event.payload[:exception] && strace = event.payload[:stacktrace]
        quoted_stacktrace = %('#{Array(strace).join("\n\t")}') # depending on if I'm logging as logstash or not
        opts[:stacktrace] = quoted_stacktrace
        # will output as e.g.
        #   "stacktrace":"'[\"/Users/somedev/.rvm/gems/ etc.
        # no need to include the :exception payload as it is already output
        # by the 'error' key, e.g.
        #   "error":"ActionView::Template::Error:bootstrap/carousel.js isn't precompiled"
      end
require "active_support/notifications/instrumenter"
# https://github.com/rails/rails/blob/4-2-stable/activesupport/lib/active_support/notifications/instrumenter.rb
# also see payload[:stacktrace] in config/application.rb
# below per Carl Lerche to preserve skylight patch and our patch
# https://gist.github.com/carllerche/acd5c34e284d90678ac0
class ActiveSupport::Notifications::Instrumenter
  # :nocov:
  alias_method :instrument_original, :instrument

  # rubocop:disable Lint/RescueException
  def instrument(name, payload = {})
    instrument_original(name, payload) do
      begin
        yield
      rescue Exception => e
        # BF added the below line to include backtrace in lograge
        payload[:stacktrace] = e.backtrace
        raise
      end
    end
  end
  # rubocop:enable Lint/RescueException
  # :nocov:
end
# look into adding an exception object via middleware that we can
# use in the :append_info_to_payload method
# e.g. see
# https://github.com/airbrake/airbrake/blob/master/lib/airbrake/rails/action_controller_catcher.rb#L7
#  and https://github.com/airbrake/airbrake/blob/master/lib/airbrake/rails/error_lookup.rb#L7
# https://github.com/airbrake/airbrake/blob/master/lib/airbrake/rails/middleware.rb#L13
#  and https://github.com/airbrake/airbrake/blob/master/lib/airbrake/railtie.rb
#  and https://github.com/airbrake/airbrake/blob/master/lib/airbrake/rack.rb#L44
# since there is a difference between what is available by a subscriber and a middleware
#  see https://github.com/roidrage/lograge/blob/master/lib/lograge.rb

@chongivan
Copy link

@bf4 , where do you put the above lines of code?

@aripollak
Copy link
Contributor

I think this is fixed as of #112?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

7 participants