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

Errors not being handled #376

Closed
mozcomp opened this issue Aug 17, 2021 · 8 comments
Closed

Errors not being handled #376

mozcomp opened this issue Aug 17, 2021 · 8 comments

Comments

@mozcomp
Copy link

mozcomp commented Aug 17, 2021

Registered errors like Graphiti::Errors::RecordNotFound aren't being handled as I'd expect.

The json formatted error is rendered, but still surfaces as an error on the server such that they're being reported by system-wide error handler HoneyBadger. Or is this as expected?

Running example Employee Directory the console reports a RecordNotFound ...

=== Graphiti Debug
Top Level Data Retrieval (+ sideloads):
EmployeeResource.all({})
Took: 2.86ms
Completed 404 Not Found in 79ms (ActiveRecord: 1.6ms)
Graphiti::Errors::RecordNotFound (Graphiti::Errors::RecordNotFound):

But in my app it returns what I would call an unhandled error ..

=== Graphiti Debug
Top Level Data Retrieval (+ sideloads):
Api::V2::CustomerResource.all({})
Took: 12.45ms
{:method=>"GET", :path=>"/api/v2/customers/10", :format=>"*/*", :controller=>"Api::V2::CustomersController", :action=>"show", :status=>500, :error=>"Graphiti::Errors::RecordNotFound: Specified Record Not Found", :duration=>465.86, :view=>0.0, :db=>373.51, :remote_ip=>nil, :user=>nil, :params=>{"id"=>"10"}}
Graphiti::Errors::RecordNotFound (Specified Record Not Found):
graphiti (1.2.44) lib/graphiti/resource_proxy.rb:70:in `data'
graphiti (1.2.44) lib/graphiti/renderer.rb:13:in `records'
graphiti (1.2.44) lib/graphiti/renderer.rb:58:in `render'
graphiti (1.2.44) lib/graphiti/renderer.rb:17:in `to_jsonapi'
graphiti (1.2.44) lib/graphiti/resource_proxy.rb:43:in `to_jsonapi'
graphiti-rails (0.3.0) lib/graphiti/rails/railtie.rb:94:in `block (2 levels) in register_renderers'
actionpack (5.1.7) lib/action_controller/metal/renderers.rb:149:in `block in _render_to_body_with_renderer'
/usr/local/var/rbenv/versions/2.6.6/lib/ruby/2.6.0/set.rb:338:in `each_key'
/usr/local/var/rbenv/versions/2.6.6/lib/ruby/2.6.0/set.rb:338:in `each'
actionpack (5.1.7) lib/action_controller/metal/renderers.rb:145:in `_render_to_body_with_renderer'
actionpack (5.1.7) lib/action_controller/metal/renderers.rb:141:in `render_to_body'
actionpack (5.1.7) lib/abstract_controller/rendering.rb:24:in `render'
actionpack (5.1.7) lib/action_controller/metal/rendering.rb:36:in `render'
actionpack (5.1.7) lib/action_controller/metal/instrumentation.rb:44:in `block (2 levels) in render'
activesupport (5.1.7) lib/active_support/core_ext/benchmark.rb:12:in `block in ms'
/usr/local/var/rbenv/versions/2.6.6/lib/ruby/2.6.0/benchmark.rb:308:in `realtime'
activesupport (5.1.7) lib/active_support/core_ext/benchmark.rb:12:in `ms'
actionpack (5.1.7) lib/action_controller/metal/instrumentation.rb:44:in `block in render'
actionpack (5.1.7) lib/action_controller/metal/instrumentation.rb:87:in `cleanup_view_runtime'
activerecord (5.1.7) lib/active_record/railties/controller_runtime.rb:29:in `cleanup_view_runtime'
elasticsearch-rails (6.1.1) lib/elasticsearch/rails/instrumentation/controller_runtime.rb:20:in `cleanup_view_runtime'
actionpack (5.1.7) lib/action_controller/metal/instrumentation.rb:43:in `render'
remotipart (1.4.4) lib/remotipart/render_overrides.rb:23:in `render'
modules/api/app/controllers/api/v2/resources_controller.rb:22:in `show'
actionpack (5.1.7) lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
actionpack (5.1.7) lib/abstract_controller/base.rb:186:in `process_action'
actionpack (5.1.7) lib/action_controller/metal/rendering.rb:30:in `process_action'
actionpack (5.1.7) lib/abstract_controller/callbacks.rb:20:in `block in process_action'
activesupport (5.1.7) lib/active_support/callbacks.rb:108:in `block in run_callbacks'
graphiti-rails (0.3.0) lib/graphiti/rails/debugging.rb:13:in `block in debug_graphiti'
graphiti (1.2.44) lib/graphiti/debugger.rb:110:in `debug'
graphiti-rails (0.3.0) lib/graphiti/rails/debugging.rb:12:in `debug_graphiti'
activesupport (5.1.7) lib/active_support/callbacks.rb:117:in `block in run_callbacks'
graphiti-rails (0.3.0) lib/graphiti/rails/context.rb:17:in `block in wrap_graphiti_context'
graphiti (1.2.44) lib/graphiti.rb:33:in `with_context'
graphiti-rails (0.3.0) lib/graphiti/rails/context.rb:16:in `wrap_graphiti_context'
activesupport (5.1.7) lib/active_support/callbacks.rb:117:in `block in run_callbacks'
activesupport (5.1.7) lib/active_support/callbacks.rb:135:in `run_callbacks'
actionpack (5.1.7) lib/abstract_controller/callbacks.rb:19:in `process_action'
actionpack (5.1.7) lib/action_controller/metal/rescue.rb:20:in `process_action'
actionpack (5.1.7) lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
activesupport (5.1.7) lib/active_support/notifications.rb:166:in `block in instrument'
activesupport (5.1.7) lib/active_support/notifications/instrumenter.rb:21:in `instrument'
activesupport (5.1.7) lib/active_support/notifications.rb:166:in `instrument'
actionpack (5.1.7) lib/action_controller/metal/instrumentation.rb:30:in `process_action'
actionpack (5.1.7) lib/action_controller/metal/params_wrapper.rb:252:in `process_action'
rescue_registry (0.3.0) lib/rescue_registry/controller.rb:24:in `process_action'
activerecord (5.1.7) lib/active_record/railties/controller_runtime.rb:22:in `process_action'
actionpack (5.1.7) lib/abstract_controller/base.rb:124:in `process'
actionview (5.1.7) lib/action_view/rendering.rb:30:in `process'
actionpack (5.1.7) lib/action_controller/metal.rb:189:in `dispatch'
actionpack (5.1.7) lib/action_controller/metal.rb:253:in `dispatch'
actionpack (5.1.7) lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
actionpack (5.1.7) lib/action_dispatch/routing/route_set.rb:31:in `serve'
actionpack (5.1.7) lib/action_dispatch/journey/router.rb:50:in `block in serve'
actionpack (5.1.7) lib/action_dispatch/journey/router.rb:33:in `each'
actionpack (5.1.7) lib/action_dispatch/journey/router.rb:33:in `serve'
actionpack (5.1.7) lib/action_dispatch/routing/route_set.rb:844:in `call'
railties (5.1.7) lib/rails/engine.rb:522:in `call'
railties (5.1.7) lib/rails/railtie.rb:185:in `public_send'
railties (5.1.7) lib/rails/railtie.rb:185:in `method_missing'
actionpack (5.1.7) lib/action_dispatch/routing/mapper.rb:17:in `block in <class:Constraints>'
actionpack (5.1.7) lib/action_dispatch/routing/mapper.rb:46:in `serve'
actionpack (5.1.7) lib/action_dispatch/journey/router.rb:50:in `block in serve'
actionpack (5.1.7) lib/action_dispatch/journey/router.rb:33:in `each'
actionpack (5.1.7) lib/action_dispatch/journey/router.rb:33:in `serve'
actionpack (5.1.7) lib/action_dispatch/routing/route_set.rb:844:in `call'
omniauth (2.0.3) lib/omniauth/strategy.rb:201:in `call!'
omniauth (2.0.3) lib/omniauth/strategy.rb:169:in `call'
omniauth (2.0.3) lib/omniauth/builder.rb:45:in `call'
omniauth (2.0.3) lib/omniauth/strategy.rb:201:in `call!'
omniauth (2.0.3) lib/omniauth/strategy.rb:169:in `call'
omniauth (2.0.3) lib/omniauth/builder.rb:45:in `call'
apartment (2.2.1) lib/apartment/elevators/generic.rb:23:in `call'
apartment (2.2.1) lib/apartment/reloader.rb:18:in `call'
remotipart (1.4.4) lib/remotipart/middleware.rb:32:in `call'
warden (1.2.9) lib/warden/manager.rb:36:in `block in call'
warden (1.2.9) lib/warden/manager.rb:34:in `catch'
warden (1.2.9) lib/warden/manager.rb:34:in `call'
aws-healthcheck (2.0.0) lib/healthcheck/middleware.rb:11:in `call'
rack (2.2.3) lib/rack/etag.rb:27:in `call'
rack (2.2.3) lib/rack/conditional_get.rb:27:in `call'
rack (2.2.3) lib/rack/head.rb:12:in `call'
rack (2.2.3) lib/rack/session/abstract/id.rb:266:in `context'
rack (2.2.3) lib/rack/session/abstract/id.rb:260:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/cookies.rb:613:in `call'
activerecord (5.1.7) lib/active_record/migration.rb:556:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/callbacks.rb:26:in `block in call'
activesupport (5.1.7) lib/active_support/callbacks.rb:97:in `run_callbacks'
actionpack (5.1.7) lib/action_dispatch/middleware/callbacks.rb:24:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/executor.rb:12:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/debug_exceptions.rb:59:in `call'
web-console (3.7.0) lib/web_console/middleware.rb:135:in `call_app'
web-console (3.7.0) lib/web_console/middleware.rb:30:in `block in call'
web-console (3.7.0) lib/web_console/middleware.rb:20:in `catch'
web-console (3.7.0) lib/web_console/middleware.rb:20:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
rescue_registry (0.3.0) lib/rescue_registry/action_dispatch/show_exceptions.rb:11:in `call'
rescue_registry (0.3.0) lib/rescue_registry/reset_context.rb:9:in `call'
lograge (0.11.2) lib/lograge/rails_ext/rack/logger.rb:15:in `call_app'
railties (5.1.7) lib/rails/rack/logger.rb:24:in `block in call'
activesupport (5.1.7) lib/active_support/tagged_logging.rb:69:in `block in tagged'
activesupport (5.1.7) lib/active_support/tagged_logging.rb:26:in `tagged'
activesupport (5.1.7) lib/active_support/tagged_logging.rb:69:in `tagged'
railties (5.1.7) lib/rails/rack/logger.rb:24:in `call'
sprockets-rails (3.2.2) lib/sprockets/rails/quiet_assets.rb:13:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
request_store (1.5.0) lib/request_store/middleware.rb:19:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/request_id.rb:25:in `call'
rack (2.2.3) lib/rack/method_override.rb:24:in `call'
rack (2.2.3) lib/rack/runtime.rb:22:in `call'
activesupport (5.1.7) lib/active_support/cache/strategy/local_cache_middleware.rb:27:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/executor.rb:12:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/static.rb:125:in `call'
rack (2.2.3) lib/rack/sendfile.rb:110:in `call'
honeybadger (4.8.0) lib/honeybadger/rack/error_notifier.rb:33:in `block in call'
honeybadger (4.8.0) lib/honeybadger/agent.rb:426:in `with_rack_env'
honeybadger (4.8.0) lib/honeybadger/rack/error_notifier.rb:30:in `call'
honeybadger (4.8.0) lib/honeybadger/rack/user_feedback.rb:31:in `call'
honeybadger (4.8.0) lib/honeybadger/rack/user_informer.rb:21:in `call'
railties (5.1.7) lib/rails/engine.rb:522:in `call'
puma (5.2.2) lib/puma/configuration.rb:248:in `call'
puma (5.2.2) lib/puma/request.rb:76:in `block in handle_request'
puma (5.2.2) lib/puma/thread_pool.rb:337:in `with_force_shutdown'
puma (5.2.2) lib/puma/request.rb:75:in `handle_request'
puma (5.2.2) lib/puma/server.rb:431:in `process_client'
puma (5.2.2) lib/puma/thread_pool.rb:145:in `block in spawn_thread'
** [Honeybadger] Reporting error id=f51ea61d-c87b-4e4b-afd1-c6a0857ab4e6 level=1 pid=73739
** [Honeybadger] Success ⚡ Development mode is enabled; this error will be reported if it occurs after you deploy your app. id=f51ea61d-c87b-4e4b-afd1-c6a0857ab4e6 level=1 pid=73739

My real problem is because it's handled "magically" in graphiti-rails, there's not a lot I can see to configure or change.

What should I be looking for?

The only "unusual" thing about the app is that it was created as a number of Rails Engines to provide a degree of modularity, and as such the API is an engine with an isolated namespace .. /api.

Admittedly, my app is still Rails 5.1, and the example is 5.2, but I can't see that being the difference.

Any suggestions would be appreciated.

@richmolj
Copy link
Contributor

Hey @mozcomp I think this is a (recently) known issue I've been meaning to speak to @wagenet about. Basically ActiveSupport::Notifications.instrument(“process_action.action_controller” fires before the DebugExceptions middleware (where our override of the status code/etc happens). Things like lograge or honeybadger are subscribing to that event, logging before we get to it. So the actual response is correct, but logged incorrectly.

@wagenet not sure if you'd be able to take a look at this? Otherwise it is on my radar but not sure exactly when I'll get to it.

@richmolj
Copy link
Contributor

@mozcomp this actually looks to be an error in the lograge gem. They are getting the status code this way:

status = ActionDispatch::ExceptionWrapper.rescue_responses[exception_class_name]

which is really a private interface...the public one (which we support) would be

status = ActionDispatch::ExceptionWrapper.status_code_for_exception(exception_class_name)

This is what Rails itself does. So the bug is really lograge using a private interface instead of the public one.

Until I can PR to lograge, you can monkey-patch to fix this:

Lograge::LogSubscribers::Base.class_eval do
  def get_error_status_code(exception_class_name)
    ActionDispatch::ExceptionWrapper.status_code_for_exception(exception_class_name)
  end
end

@richmolj
Copy link
Contributor

roidrage/lograge#334

@mozcomp
Copy link
Author

mozcomp commented Aug 18, 2021

Hi Lee,

Thanks for the prompt reply ...
I tried the monkey patch to lograge, no difference.
I removed lograge from the stack, no difference.
I removed honeybadger from the stack, no difference.

The backtrace on the error now looks like this

Processing by Api::V2::CustomersController#show as */*
  Parameters: {"id"=>"10"}
  Core::User Load (14.5ms)  SELECT  `core_users`.* FROM `core_users` WHERE `core_users`.`authentication_token` = '2uNhwKzQu8zAFNR72at4' LIMIT 1
  Core::Domain Load (10.5ms)  SELECT  `core_domains`.* FROM `core_domains` WHERE `core_domains`.`id` = 1 LIMIT 1
  Core::Party Load (14.7ms)  SELECT  `core_parties`.* FROM `core_parties` WHERE `core_parties`.`id` = 1 LIMIT 1
  Core::Customer Load (15.2ms)  SELECT  `core_customers`.* FROM `core_customers` WHERE `core_customers`.`id` = 10 LIMIT 20 OFFSET 0

=== Graphiti Debug
Top Level Data Retrieval (+ sideloads):
Api::V2::CustomerResource.all({})
Took: 16.01ms
Completed 404 Not Found in 233ms (ActiveRecord: 139.7ms | Elasticsearch: 0.0ms)



Graphiti::Errors::RecordNotFound (Specified Record Not Found):

graphiti (1.2.44) lib/graphiti/resource_proxy.rb:70:in `data'
graphiti (1.2.44) lib/graphiti/renderer.rb:13:in `records'
graphiti (1.2.44) lib/graphiti/renderer.rb:58:in `render'
graphiti (1.2.44) lib/graphiti/renderer.rb:17:in `to_jsonapi'
graphiti (1.2.44) lib/graphiti/resource_proxy.rb:43:in `to_jsonapi'
graphiti-rails (0.3.0) lib/graphiti/rails/railtie.rb:94:in `block (2 levels) in register_renderers'
actionpack (5.1.7) lib/action_controller/metal/renderers.rb:149:in `block in _render_to_body_with_renderer'
/usr/local/var/rbenv/versions/2.6.6/lib/ruby/2.6.0/set.rb:338:in `each_key'
/usr/local/var/rbenv/versions/2.6.6/lib/ruby/2.6.0/set.rb:338:in `each'
actionpack (5.1.7) lib/action_controller/metal/renderers.rb:145:in `_render_to_body_with_renderer'
actionpack (5.1.7) lib/action_controller/metal/renderers.rb:141:in `render_to_body'
actionpack (5.1.7) lib/abstract_controller/rendering.rb:24:in `render'
actionpack (5.1.7) lib/action_controller/metal/rendering.rb:36:in `render'
actionpack (5.1.7) lib/action_controller/metal/instrumentation.rb:44:in `block (2 levels) in render'
activesupport (5.1.7) lib/active_support/core_ext/benchmark.rb:12:in `block in ms'
/usr/local/var/rbenv/versions/2.6.6/lib/ruby/2.6.0/benchmark.rb:308:in `realtime'
activesupport (5.1.7) lib/active_support/core_ext/benchmark.rb:12:in `ms'
actionpack (5.1.7) lib/action_controller/metal/instrumentation.rb:44:in `block in render'
actionpack (5.1.7) lib/action_controller/metal/instrumentation.rb:87:in `cleanup_view_runtime'
activerecord (5.1.7) lib/active_record/railties/controller_runtime.rb:29:in `cleanup_view_runtime'
elasticsearch-rails (6.1.1) lib/elasticsearch/rails/instrumentation/controller_runtime.rb:20:in `cleanup_view_runtime'
actionpack (5.1.7) lib/action_controller/metal/instrumentation.rb:43:in `render'
remotipart (1.4.4) lib/remotipart/render_overrides.rb:23:in `render'
modules/api/app/controllers/api/v2/resources_controller.rb:22:in `show'
actionpack (5.1.7) lib/action_controller/metal/basic_implicit_render.rb:4:in `send_action'
actionpack (5.1.7) lib/abstract_controller/base.rb:186:in `process_action'
actionpack (5.1.7) lib/action_controller/metal/rendering.rb:30:in `process_action'
actionpack (5.1.7) lib/abstract_controller/callbacks.rb:20:in `block in process_action'
activesupport (5.1.7) lib/active_support/callbacks.rb:108:in `block in run_callbacks'
graphiti-rails (0.3.0) lib/graphiti/rails/debugging.rb:13:in `block in debug_graphiti'
graphiti (1.2.44) lib/graphiti/debugger.rb:110:in `debug'
graphiti-rails (0.3.0) lib/graphiti/rails/debugging.rb:12:in `debug_graphiti'
activesupport (5.1.7) lib/active_support/callbacks.rb:117:in `block in run_callbacks'
graphiti-rails (0.3.0) lib/graphiti/rails/context.rb:17:in `block in wrap_graphiti_context'
graphiti (1.2.44) lib/graphiti.rb:33:in `with_context'
graphiti-rails (0.3.0) lib/graphiti/rails/context.rb:16:in `wrap_graphiti_context'
activesupport (5.1.7) lib/active_support/callbacks.rb:117:in `block in run_callbacks'
activesupport (5.1.7) lib/active_support/callbacks.rb:135:in `run_callbacks'
actionpack (5.1.7) lib/abstract_controller/callbacks.rb:19:in `process_action'
actionpack (5.1.7) lib/action_controller/metal/rescue.rb:20:in `process_action'
actionpack (5.1.7) lib/action_controller/metal/instrumentation.rb:32:in `block in process_action'
activesupport (5.1.7) lib/active_support/notifications.rb:166:in `block in instrument'
activesupport (5.1.7) lib/active_support/notifications/instrumenter.rb:21:in `instrument'
activesupport (5.1.7) lib/active_support/notifications.rb:166:in `instrument'
actionpack (5.1.7) lib/action_controller/metal/instrumentation.rb:30:in `process_action'
actionpack (5.1.7) lib/action_controller/metal/params_wrapper.rb:252:in `process_action'
rescue_registry (0.3.0) lib/rescue_registry/controller.rb:24:in `process_action'
activerecord (5.1.7) lib/active_record/railties/controller_runtime.rb:22:in `process_action'
actionpack (5.1.7) lib/abstract_controller/base.rb:124:in `process'
actionview (5.1.7) lib/action_view/rendering.rb:30:in `process'
actionpack (5.1.7) lib/action_controller/metal.rb:189:in `dispatch'
actionpack (5.1.7) lib/action_controller/metal.rb:253:in `dispatch'
actionpack (5.1.7) lib/action_dispatch/routing/route_set.rb:49:in `dispatch'
actionpack (5.1.7) lib/action_dispatch/routing/route_set.rb:31:in `serve'
actionpack (5.1.7) lib/action_dispatch/journey/router.rb:50:in `block in serve'
actionpack (5.1.7) lib/action_dispatch/journey/router.rb:33:in `each'
actionpack (5.1.7) lib/action_dispatch/journey/router.rb:33:in `serve'
actionpack (5.1.7) lib/action_dispatch/routing/route_set.rb:844:in `call'
railties (5.1.7) lib/rails/engine.rb:522:in `call'
railties (5.1.7) lib/rails/railtie.rb:185:in `public_send'
railties (5.1.7) lib/rails/railtie.rb:185:in `method_missing'
actionpack (5.1.7) lib/action_dispatch/routing/mapper.rb:17:in `block in <class:Constraints>'
actionpack (5.1.7) lib/action_dispatch/routing/mapper.rb:46:in `serve'
actionpack (5.1.7) lib/action_dispatch/journey/router.rb:50:in `block in serve'
actionpack (5.1.7) lib/action_dispatch/journey/router.rb:33:in `each'
actionpack (5.1.7) lib/action_dispatch/journey/router.rb:33:in `serve'
actionpack (5.1.7) lib/action_dispatch/routing/route_set.rb:844:in `call'
omniauth (2.0.3) lib/omniauth/strategy.rb:201:in `call!'
omniauth (2.0.3) lib/omniauth/strategy.rb:169:in `call'
omniauth (2.0.3) lib/omniauth/builder.rb:45:in `call'
apartment (2.2.1) lib/apartment/elevators/generic.rb:23:in `call'
apartment (2.2.1) lib/apartment/reloader.rb:18:in `call'
remotipart (1.4.4) lib/remotipart/middleware.rb:32:in `call'
warden (1.2.9) lib/warden/manager.rb:36:in `block in call'
warden (1.2.9) lib/warden/manager.rb:34:in `catch'
warden (1.2.9) lib/warden/manager.rb:34:in `call'
aws-healthcheck (2.0.0) lib/healthcheck/middleware.rb:11:in `call'
rack (2.2.3) lib/rack/etag.rb:27:in `call'
rack (2.2.3) lib/rack/conditional_get.rb:27:in `call'
rack (2.2.3) lib/rack/head.rb:12:in `call'
rack (2.2.3) lib/rack/session/abstract/id.rb:266:in `context'
rack (2.2.3) lib/rack/session/abstract/id.rb:260:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/cookies.rb:613:in `call'
activerecord (5.1.7) lib/active_record/migration.rb:556:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/callbacks.rb:26:in `block in call'
activesupport (5.1.7) lib/active_support/callbacks.rb:97:in `run_callbacks'
actionpack (5.1.7) lib/action_dispatch/middleware/callbacks.rb:24:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/executor.rb:12:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/debug_exceptions.rb:59:in `call'
web-console (3.7.0) lib/web_console/middleware.rb:135:in `call_app'
web-console (3.7.0) lib/web_console/middleware.rb:30:in `block in call'
web-console (3.7.0) lib/web_console/middleware.rb:20:in `catch'
web-console (3.7.0) lib/web_console/middleware.rb:20:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
rescue_registry (0.3.0) lib/rescue_registry/action_dispatch/show_exceptions.rb:11:in `call'
rescue_registry (0.3.0) lib/rescue_registry/reset_context.rb:9:in `call'
railties (5.1.7) lib/rails/rack/logger.rb:36:in `call_app'
railties (5.1.7) lib/rails/rack/logger.rb:24:in `block in call'
activesupport (5.1.7) lib/active_support/tagged_logging.rb:69:in `block in tagged'
activesupport (5.1.7) lib/active_support/tagged_logging.rb:26:in `tagged'
activesupport (5.1.7) lib/active_support/tagged_logging.rb:69:in `tagged'
railties (5.1.7) lib/rails/rack/logger.rb:24:in `call'
sprockets-rails (3.2.2) lib/sprockets/rails/quiet_assets.rb:13:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
request_store (1.5.0) lib/request_store/middleware.rb:19:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/request_id.rb:25:in `call'
rack (2.2.3) lib/rack/method_override.rb:24:in `call'
rack (2.2.3) lib/rack/runtime.rb:22:in `call'
activesupport (5.1.7) lib/active_support/cache/strategy/local_cache_middleware.rb:27:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/executor.rb:12:in `call'
actionpack (5.1.7) lib/action_dispatch/middleware/static.rb:125:in `call'
rack (2.2.3) lib/rack/sendfile.rb:110:in `call'
railties (5.1.7) lib/rails/engine.rb:522:in `call'
puma (5.2.2) lib/puma/configuration.rb:248:in `call'
puma (5.2.2) lib/puma/request.rb:76:in `block in handle_request'
puma (5.2.2) lib/puma/thread_pool.rb:337:in `with_force_shutdown'
puma (5.2.2) lib/puma/request.rb:75:in `handle_request'
puma (5.2.2) lib/puma/server.rb:431:in `process_client'
puma (5.2.2) lib/puma/thread_pool.rb:145:in `block in spawn_thread'

I hope this helps, as you're delving into areas I have no idea about..

@richmolj
Copy link
Contributor

@mozcomp that actually looks correct to me - we raise the error Graphiti::Errors::RecordNotFound and the status code is 404. What should change?

@mozcomp
Copy link
Author

mozcomp commented Aug 18, 2021

I must admit I wasn't expecting the backtrace to be surfaced on the console, it wasn't in the employee_directory example.
That said, it did complete the request.

So, I then want back to the starting point to find which action allowed the completion of the request, and of course found your original fix - the monkey-patch to lograge did the job.

Many thanks

@richmolj
Copy link
Contributor

Fantastic, thanks @mozcomp 🎉 !

@stwr667
Copy link

stwr667 commented Nov 11, 2021

@mozcomp we have a very similar error to @richmolj. Although we tried the suggested monkey-patch for Lograge, but it still reports an error to Honeybadger.

We get this output in our logs, as expected:

2021-11-11T15:20:10+08:00|DEBUG| === Graphiti Debug
2021-11-11T15:20:10+08:00|DEBUG| Top Level Data Retrieval (+ sideloads):
2021-11-11T15:20:10+08:00|DEBUG| Api::FarmResource.all({})
2021-11-11T15:20:10+08:00|DEBUG| Took: 26.45ms
2021-11-11T15:20:10+08:00|INFO| Completed 403 Forbidden in 231ms (ActiveRecord: 31.3ms | SQL count: 7 | Allocations: 110328)

Our controller calls:

raise Permissions::AccessDenied

And our base controller registers the exception:

    register_exception Permissions::AccessDenied,
                       status: 403,
                       title: "Access denied",
                       handler: Graphiti::Rails::ExceptionHandler

Is there any way to prevent the Honeybadger from being raised when using register_exception? It seems that the only alternative is to use rescue_from which won't raise a Honeybadger exception by default, but then we lose the nice jsonapi response in that case.

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

No branches or pull requests

3 participants