Allow DebugExceptions interceptors to abort default backtrace error log

[wjordan]

Summary

DebugExceptions interceptors were recently added in #23868, which allow callbacks to be attached to errors returned by the middleware, to support adding extra error-logging hooks.

This PR extends these interceptors to support aborting the default error-logging implementation when desired by throwing :abort.

Prior to this PR, the only way to prevent backtrace logging of application exceptions and routing errors (which are converted to ActionController::RoutingError "No route matches [GET]" by this middleware), without affecting other aspects of the error-page rendering behavior, was to monkey-patch the DebugExceptions middleware directly (see roidrage/lograge#252 for my best effort at this).

This PR makes it easier to throw :abort from a registered interceptor to disable the default backtrace logger directly:

ActionDispatch::DebugExceptions.register_interceptor do |request, exception|
  [ ... custom error logging ... ]
  throw :abort # Disable default error logging
end

Other Information

• Fixes Rails 5.1 ActionDispatch::DebugExceptions inappropriate fatal logging for RoutingError #31502 (or at least provides an acceptable public-API workaround for the issue).

• My own use-case for this PR is a need to reduce the size of Rails application log by disabling the default backtrace logs written by application/routing errors.

• The implementation includes (ActiveSupport::Callbacks) and wraps the default error-logging in a log_exception callback, which is what supplies the :abort-catching logic.

• This PR also fixes a related bug where an exception thrown by an interceptor caused the original error backtrace to be logged multiple times (see the provided "bad interceptors doesn't duplicate log error" test which fails without this PR and passes with it).

[rails-bot]

Thanks for the pull request, and welcome! The Rails team is excited to review your changes, and you should hear from @sgrif (or someone else) soon.

If any changes to this PR are deemed necessary, please add them as extra commits. This ensures that the reviewer can see what has changed since they last reviewed the code. Due to the way GitHub handles out-of-date commits, this should also make it reasonably obvious what issues have or haven't been addressed. Large or tricky changes may require several passes of review and changes.

This repository is being automatically checked for code quality issues using Code Climate. You can see results for this analysis in the PR status below. Newly introduced issues should be fixed before a Pull Request is considered ready to review.

Please see the contribution instructions for more information.

[gsamokovarov]

@wjordan I don't think we should stop the interceptors. They are not logging hooks, but plugin hooks.

Say you have a custom interceptor running before the raven gem interceptor. If you are to stop the interceptors, no errors will be sent to the error tracker. Every interceptor should have a say and do what's it intended to do, otherwise, no plugin author will trust the interceptors API and we'll be back to monkey patching.

[lucaong]

One example of why this would be very useful is the following:

Currently, the error logging logic is handled by the private log_error method in ActionDispatch::DebugExceptions. The default implementation calls the logger several times:

logger.fatal "  "
logger.fatal "#{exception.class} (#{exception.message}):"
log_array logger, exception.annoted_source_code if exception.respond_to?(:annoted_source_code)
logger.fatal "  "
log_array logger, trace

In some applications, one might have a custom logger that formats and reports logs to some service, say as JSON objects. In this case it would be much better to log the error name and the stack trace as one single call to logger.fatal, so that the external service receives one error single event with all the information. One actual example of such services is Stackdriver, the default logger application on the Google Cloud: https://cloud.google.com/error-reporting/docs/formatting-error-messages

Currently (correct me if I am missing something), the only available option to achieve this is to patch ActionDispatch::DebugExceptions re-implementing the private method log_error, which is definitely not desirable.

Ideally, one should be able to configure how an unhandled exception gets logged, or to intercept the exception and prevent the default logging behavior.

[antoniobg]

Any update on this?

[maknahar]

Any plan to support this?

[gsamokovarov]

The interceptors shouldn't be stopped, because they are to be used by plugins which need to act on the exception and everyone should get their turn to dispatch their action. That's the contract.

As for the logging, I don't have a strong opinion, but if you need to override it, introducing the whole Active Support Callbacks machinery is an overkill.

[rafaelfranca]

Closing because like @gsamokovarov said we don't want the interceptors to be stoped. About the disabling of logging you can configure exceptions you want to silence now 238d367.