search

graphiti-api / graphiti

Stylish Graph APIs
https://www.graphiti.dev/
MIT License
960 stars 138 forks source link

Errors not being handled #376

Closed mozcomp closed 2 years ago

mozcomp commented 2 years ago

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 commented 2 years ago

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 commented 2 years ago

@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 commented 2 years ago

https://github.com/roidrage/lograge/pull/334

mozcomp commented 2 years ago

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 commented 2 years ago

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

mozcomp commented 2 years ago

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 commented 2 years ago

Fantastic, thanks @mozcomp 🎉 !

stwr667 commented 2 years ago

@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.