Bug: sentry tracing - don't assume query.selected_operation is defined

[redterror]

I observed an error in my production application where query.selected_operation was nil. As best I can tell, this was due to a query that looks to me to be invalid, but was executed with some partial success. I recognize the details here are light.

A simplified version of the query that generated this is:

peopleSearch(filters: $filters) recordCount 
  records { 
    recordId 
    firstName 
    lastName
  }

The backtrace was:

NoMethodError: undefined method `operation_type' for nil (NoMethodError)

                span.set_data('graphql.operation.type', query.selected_operation.operation_type)
                                                                                ^^^^^^^^^^^^^^^
    from graphql/tracing/sentry_trace.rb:44:in 'block in instrument'
    from sentry/hub.rb:146:in 'block in with_child_span'
    from sentry/span.rb:238:in 'with_child_span'
    from sentry/hub.rb:144:in 'with_child_span'
    from sentry-ruby.rb:538:in 'with_child_span'
    from graphql/tracing/sentry_trace.rb:22:in 'instrument'
    from graphql/tracing/monitor_trace.rb:196:in 'execute_multiplex'
    from graphql/execution/interpreter.rb:42:in 'run_all'
    from graphql/schema.rb:1603:in 'multiplex'
    from graphql/schema.rb:1578:in 'execute'
    from app/controllers/graphql_controller.rb:25:in 'execute'
    from action_controller/metal/basic_implicit_render.rb:8:in 'send_action'
    from abstract_controller/base.rb:226:in 'process_action'
    from action_controller/metal/rendering.rb:193:in 'process_action'
    from abstract_controller/callbacks.rb:261:in 'block in process_action'
    from active_support/callbacks.rb:121:in 'block in run_callbacks'
    from turbo-rails.rb:24:in 'with_request_id'
    from /usr/local/bundle/ruby/3.3.0/gems/turbo-rails-2.0.11/app/controllers/concerns/turbo/request_id_tracking.rb:10:in 'turbo_tracking_request_id'
    from active_support/callbacks.rb:130:in 'block in run_callbacks'
    from sentry/rails/controller_transaction.rb:21:in 'block in sentry_around_action'
    from sentry/hub.rb:146:in 'block in with_child_span'
    from sentry/span.rb:238:in 'with_child_span'
    from sentry/hub.rb:144:in 'with_child_span'
    from sentry-ruby.rb:538:in 'with_child_span'
    from sentry/rails/controller_transaction.rb:18:in 'sentry_around_action'
    from active_support/callbacks.rb:130:in 'block in run_callbacks'
    from active_support/callbacks.rb:141:in 'run_callbacks'
    from abstract_controller/callbacks.rb:260:in 'process_action'
    from action_controller/metal/rescue.rb:27:in 'process_action'
    from action_controller/metal/instrumentation.rb:77:in 'block in process_action'
    from active_support/notifications.rb:210:in 'block in instrument'
    from active_support/notifications/instrumenter.rb:58:in 'instrument'
    from sentry/rails/tracing.rb:56:in 'instrument'
    from active_support/notifications.rb:210:in 'instrument'
    from action_controller/metal/instrumentation.rb:76:in 'process_action'
    from action_controller/metal/params_wrapper.rb:259:in 'process_action'
    from active_record/railties/controller_runtime.rb:39:in 'process_action'
    from abstract_controller/base.rb:163:in 'process'
    from action_controller/metal.rb:252:in 'dispatch'
    from action_controller/metal.rb:335:in 'dispatch'
    from action_dispatch/routing/route_set.rb:67:in 'dispatch'
    from action_dispatch/routing/route_set.rb:50:in 'serve'
    from action_dispatch/journey/router.rb:53:in 'block in serve'
    from action_dispatch/journey/router.rb:133:in 'block in find_routes'
    from action_dispatch/journey/router.rb:126:in 'each'
    from action_dispatch/journey/router.rb:126:in 'find_routes'
    from action_dispatch/journey/router.rb:34:in 'serve'
    from action_dispatch/routing/route_set.rb:896:in 'call'
    from omniauth/strategy.rb:202:in 'call!'
    from omniauth/strategy.rb:169:in 'call'
    from rack/session/abstract/id.rb:274:in 'context'
    from rack/session/abstract/id.rb:268:in 'call'
    from rack/method_override.rb:28:in 'call'
    from action_dispatch/middleware/cookies.rb:704:in 'call'
    from warden/manager.rb:36:in 'block in call'
    from warden/manager.rb:34:in 'catch'
    from warden/manager.rb:34:in 'call'
    from rack/etag.rb:29:in 'call'
    from rack/conditional_get.rb:43:in 'call'
    from rack/head.rb:15:in 'call'
    from action_dispatch/middleware/callbacks.rb:31:in 'block in call'
    from active_support/callbacks.rb:101:in 'run_callbacks'
    from action_dispatch/middleware/callbacks.rb:30:in 'call'
    from sentry/rails/rescued_exception_interceptor.rb:14:in 'call'
    from action_dispatch/middleware/debug_exceptions.rb:31:in 'call'
    from sentry/rack/capture_exceptions.rb:30:in 'block (2 levels) in call'
    from sentry/hub.rb:310:in 'with_session_tracking'
    from sentry-ruby.rb:432:in 'with_session_tracking'
    from sentry/rack/capture_exceptions.rb:21:in 'block in call'
    from sentry/hub.rb:89:in 'with_scope'
    from sentry-ruby.rb:412:in 'with_scope'
    from sentry/rack/capture_exceptions.rb:20:in 'call'
    from action_dispatch/middleware/show_exceptions.rb:32:in 'call'
    from rails_semantic_logger/rack/logger.rb:53:in 'call_app'
    from rails_semantic_logger/rack/logger.rb:26:in 'block in call'
    from semantic_logger/base.rb:189:in 'block in tagged'
    from semantic_logger/semantic_logger.rb:319:in 'fast_tag'
    from semantic_logger/semantic_logger.rb:351:in 'tagged'
    from semantic_logger/base.rb:201:in 'tagged'
    from rails_semantic_logger/rack/logger.rb:26:in 'call'
    from action_dispatch/middleware/remote_ip.rb:96:in 'call'
    from action_dispatch/middleware/request_id.rb:33:in 'call'
    from rack/runtime.rb:24:in 'call'
    from active_support/cache/strategy/local_cache_middleware.rb:29:in 'call'
    from action_dispatch/middleware/executor.rb:16:in 'call'
    from action_dispatch/middleware/static.rb:27:in 'call'
    from rack/sendfile.rb:114:in 'call'
    from action_dispatch/middleware/ssl.rb:82:in 'call'
    from action_dispatch/middleware/assume_ssl.rb:24:in 'call'
    from rack/cors.rb:102:in 'call'
    from rails/engine.rb:535:in 'call'
    from puma/configuration.rb:299:in 'call'
    from puma/request.rb:101:in 'block in handle_request'
    from puma/thread_pool.rb:346:in 'with_force_shutdown'
    from puma/request.rb:100:in 'handle_request'
    from puma/server.rb:497:in 'process_client'
    from puma/server.rb:266:in 'block in run'
    from puma/thread_pool.rb:173:in 'block in spawn_thread'

I am still surprised this query was not rejected, so I am not sure exactly how to write a test that would demonstrate this. Please advise on any other info I can provide.

[dilshod]

It happens when the request's Content-Type header is missing or is not application/json.