rmosolgo / graphql-ruby

Ruby implementation of GraphQL
http://graphql-ruby.org
MIT License
5.36k stars 1.37k forks source link

[GRAPHQL-ENTERPRISE] Subscriptions Triggering Error with No Limiter Key Found #4535

Closed Nealsoni00 closed 9 months ago

Nealsoni00 commented 1 year ago

I have put a limiter_key in 2 places: graphql_channel and graphql_controller as so:

context = {
      limiter_key: "user:#{current_user&.id}",
}
result = SoccerSchema.execute(query:, context:, variables:, operation_name:)

I'm using both graphql enterprise limiters:

  use GraphQL::Enterprise::ActiveOperationLimiter, redis: Redis.new(url: ENV.fetch("REDIS")), limit: 5
  use GraphQL::Enterprise::RuntimeLimiter, redis: Redis.new(url: ENV.fetch("REDIS")), limit_ms: 90 * 1000

However, when I run a mutation that triggers a subscription, i get the following error:

No limiter key found (add `context: { limiter_key: ... }` to use GraphQL::Enterprise::RuntimeLimiter)

Code that causes error:

SoccerSchema.subscriptions.trigger(
        "game_list_updated",
        { training_game: game.training_game },
        { game: },
        scope: game.league_id,
)

Would love any help!

rmosolgo commented 1 year ago

Sorry for the trouble!

My first guess is that limiter_key: ... is getting left out when context is serialized for storage, then parsed to re-evaluate the subscription. What subscription backend are you using? (Ably, Pusher, ActionCable, something else?)

If you're using Pusher or Ably, the thing to check is dump_context and load_context: https://graphql-ruby.org/subscriptions/ably_implementation#serializing-context. Do those methods include limiter_key:?

If that doesn't help, could you please share the full backtrace of the error? That would give me some more clarity about what GraphQL-Ruby is doing when it encounters this problem. Maybe there's a spot I overlooked!

Nealsoni00 commented 1 year ago

Appreciate the help! I'm using ActionCable using AnyCable with the RPC bridge to connect between the two services. I am including the context value in both the graphql_channel and graphql_controller which are the only places we define context in the graph layer. How would I go about dumping context with the ActionCable implementation?

rmosolgo commented 1 year ago

The ActionCable implementation in GraphQL-Ruby doesn't require dumping context because it's stored in memory for the duration of the subscription -- it's never written to storage. But AnyCable writes subscription context to storage (see point 3: https://github.com/anycable/graphql-anycable/#data-model). It looks like it uses query.context.to_h, so I would certainly expect limiter_key: to be persisted if it was present in the query context (source.

Could you please share the full backtrace of the error? That would help me understand what GraphQL-Ruby is doing when it runs into this error. Maybe some other part of the system needs an update!

Nealsoni00 commented 1 year ago

It hasn't happened for a while but it just happened again and here is the trace:

Stack Trace ``` /usr/local/bundle/gems/graphql-enterprise-1.3.1/lib/graphql/enterprise/limiter.rb:29:in `limiter_key': No limiter key found (add `context: { limiter_key: ... }` to use GraphQL::Enterprise::RuntimeLimiter) (ArgumentError) from /usr/local/bundle/gems/graphql-enterprise-1.3.1/lib/graphql/enterprise/runtime_limiter.rb:120:in `initialize' from /usr/local/bundle/gems/graphql-enterprise-1.3.1/lib/graphql/enterprise/runtime_limiter.rb:185:in `new' from /usr/local/bundle/gems/graphql-enterprise-1.3.1/lib/graphql/enterprise/runtime_limiter.rb:185:in `block in trace' from /usr/local/bundle/gems/graphql-enterprise-1.3.1/lib/graphql/enterprise/runtime_limiter.rb:184:in `each' from /usr/local/bundle/gems/graphql-enterprise-1.3.1/lib/graphql/enterprise/runtime_limiter.rb:184:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/platform_tracing.rb:30:in `block in trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/data_dog_tracing.rb:50:in `block in platform_trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/trace_operation.rb:191:in `block in measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/span_operation.rb:151:in `measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/trace_operation.rb:191:in `measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:380:in `start_span' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:162:in `block in trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/context.rb:45:in `activate!' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:161:in `trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing.rb:18:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/data_dog_tracing.rb:18:in `platform_trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/platform_tracing.rb:29:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /usr/local/bundle/gems/activerecord-7.0.3.1/lib/active_record/connection_handling.rb:374:in `with_role_and_shard' from /usr/local/bundle/gems/activerecord-7.0.3.1/lib/active_record/connection_handling.rb:156:in `connected_to' from /app/app/graphql/tracers/database_reading_role_tracer.rb:22:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:67:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:60:in `run_queries' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:50:in `run_all' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema.rb:1768:in `multiplex' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema.rb:1739:in `execute' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/subscriptions.rb:120:in `execute_update' from /usr/local/bundle/gems/graphql-anycable-1.1.5/lib/graphql/subscriptions/anycable_subscriptions.rb:105:in `execute_grouped' from /usr/local/bundle/gems/graphql-anycable-1.1.5/lib/graphql/subscriptions/anycable_subscriptions.rb:90:in `block in execute_all' from /usr/local/bundle/gems/graphql-anycable-1.1.5/lib/graphql/subscriptions/anycable_subscriptions.rb:89:in `each' from /usr/local/bundle/gems/graphql-anycable-1.1.5/lib/graphql/subscriptions/anycable_subscriptions.rb:89:in `execute_all' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/subscriptions.rb:95:in `trigger' from /app/app/services/update/user.rb:13:in `call' from /app/app/services/service_tracer.rb:27:in `block in call' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/trace_operation.rb:191:in `block in measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/span_operation.rb:151:in `measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/trace_operation.rb:191:in `measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:380:in `start_span' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:162:in `block in trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/context.rb:45:in `activate!' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:161:in `trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing.rb:18:in `trace' from /app/app/services/service_tracer.rb:26:in `call' from /app/app/services/application_service.rb:17:in `call_now' from /app/app/services/users/update.rb:125:in `call' from /app/app/services/service_tracer.rb:27:in `block in call' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/trace_operation.rb:191:in `block in measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/span_operation.rb:151:in `measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/trace_operation.rb:191:in `measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:380:in `start_span' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:162:in `block in trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/context.rb:45:in `activate!' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:161:in `trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing.rb:18:in `trace' from /app/app/services/service_tracer.rb:26:in `call' from /app/app/services/application_service.rb:17:in `call_now' from /app/app/graphql/mutations/update_user.rb:40:in `resolve' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/resolver.rb:107:in `public_send' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/resolver.rb:107:in `block (3 levels) in resolve_with_support' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema.rb:118:in `after_lazy' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/resolver.rb:95:in `block (2 levels) in resolve_with_support' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema.rb:118:in `after_lazy' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/resolver.rb:86:in `block in resolve_with_support' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema.rb:118:in `after_lazy' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/resolver.rb:75:in `resolve_with_support' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/relay_classic_mutation.rb:64:in `resolve_with_support' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/field.rb:828:in `public_send' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/field.rb:828:in `block in public_send_field' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/field.rb:924:in `block in with_extensions' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/field.rb:960:in `block (2 levels) in run_extensions_before_resolve' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/field.rb:963:in `run_extensions_before_resolve' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/field.rb:960:in `block in run_extensions_before_resolve' from /usr/local/bundle/gems/graphql-batch-0.5.1/lib/graphql/batch/mutation_field_extension.rb:6:in `resolve' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/field.rb:947:in `run_extensions_before_resolve' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/field.rb:919:in `with_extensions' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/field.rb:805:in `public_send_field' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/field.rb:719:in `block in resolve' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema.rb:118:in `after_lazy' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/field.rb:717:in `resolve' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:511:in `block (4 levels) in evaluate_selection_with_args' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:81:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /usr/local/bundle/gems/graphql-pro-1.24.6/lib/graphql/pro/operation_store/query_instrumentation.rb:19:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /usr/local/bundle/gems/graphql-enterprise-1.3.1/lib/graphql/enterprise/runtime_limiter.rb:258:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/platform_tracing.rb:56:in `block in trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/data_dog_tracing.rb:50:in `block in platform_trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/trace_operation.rb:191:in `block in measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/span_operation.rb:151:in `measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/trace_operation.rb:191:in `measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:380:in `start_span' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:162:in `block in trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/context.rb:45:in `activate!' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:161:in `trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing.rb:18:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/data_dog_tracing.rb:18:in `platform_trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/platform_tracing.rb:55:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /app/app/graphql/tracers/database_reading_role_tracer.rb:24:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:67:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:510:in `block (3 levels) in evaluate_selection_with_args' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/query.rb:366:in `block in with_error_handling' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/errors.rb:107:in `with_error_handling' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/query.rb:365:in `with_error_handling' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:509:in `block (2 levels) in evaluate_selection_with_args' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:812:in `call_method_on_directives' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:506:in `block in evaluate_selection_with_args' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:915:in `after_lazy' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:440:in `evaluate_selection_with_args' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:432:in `block in evaluate_selection' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/member/has_arguments.rb:204:in `block (3 levels) in coerce_arguments' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/dataloader/null_dataloader.rb:17:in `append_job' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/member/has_arguments.rb:185:in `block (2 levels) in coerce_arguments' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/member/has_arguments.rb:184:in `each' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/member/has_arguments.rb:184:in `block in coerce_arguments' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema/member/has_arguments.rb:213:in `coerce_arguments' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/arguments_cache.rb:52:in `dataload_for' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:431:in `evaluate_selection' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:359:in `block (2 levels) in evaluate_selections' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/dataloader/null_dataloader.rb:17:in `append_job' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:358:in `block in evaluate_selections' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:357:in `each' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:357:in `evaluate_selections' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:231:in `block (4 levels) in run_eager' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:812:in `call_method_on_directives' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:230:in `block (3 levels) in run_eager' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/dataloader/null_dataloader.rb:17:in `append_job' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:228:in `block (2 levels) in run_eager' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:190:in `tap_or_each' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:219:in `block in run_eager' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:812:in `call_method_on_directives' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter/runtime.rb:210:in `run_eager' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter.rb:73:in `block in evaluate' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:81:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /usr/local/bundle/gems/graphql-pro-1.24.6/lib/graphql/pro/operation_store/query_instrumentation.rb:19:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /usr/local/bundle/gems/graphql-enterprise-1.3.1/lib/graphql/enterprise/runtime_limiter.rb:261:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/platform_tracing.rb:30:in `block in trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/data_dog_tracing.rb:50:in `block in platform_trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/trace_operation.rb:191:in `block in measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/span_operation.rb:151:in `measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/trace_operation.rb:191:in `measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:380:in `start_span' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:162:in `block in trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/context.rb:45:in `activate!' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:161:in `trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing.rb:18:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/data_dog_tracing.rb:18:in `platform_trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/platform_tracing.rb:29:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /app/app/graphql/tracers/database_reading_role_tracer.rb:24:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:67:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter.rb:72:in `evaluate' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/interpreter.rb:48:in `begin_query' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:85:in `begin_query' from /usr/local/bundle/gems/graphql-persisted_queries-1.5.0/lib/graphql/persisted_queries/compiled_queries/multiplex_patch.rb:10:in `begin_query' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:104:in `block (2 levels) in run_as_multiplex' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/dataloader/null_dataloader.rb:17:in `append_job' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:104:in `block in run_as_multiplex' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:103:in `each' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:103:in `each_with_index' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:103:in `run_as_multiplex' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:63:in `block (2 levels) in run_queries' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:211:in `block in instrument_and_analyze' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/instrumentation.rb:29:in `block (2 levels) in apply_instrumenters' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/instrumentation.rb:46:in `block (2 levels) in each_query_call_hooks' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/instrumentation.rb:41:in `each_query_call_hooks' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/instrumentation.rb:45:in `block in each_query_call_hooks' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/instrumentation.rb:72:in `call_hooks' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/instrumentation.rb:44:in `each_query_call_hooks' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/instrumentation.rb:27:in `block in apply_instrumenters' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/instrumentation.rb:72:in `call_hooks' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/instrumentation.rb:26:in `apply_instrumenters' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:190:in `instrument_and_analyze' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:62:in `block in run_queries' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:81:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /usr/local/bundle/gems/graphql-pro-1.24.6/lib/graphql/pro/operation_store/query_instrumentation.rb:19:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /usr/local/bundle/gems/graphql-enterprise-1.3.1/lib/graphql/enterprise/runtime_limiter.rb:201:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/platform_tracing.rb:30:in `block in trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/data_dog_tracing.rb:50:in `block in platform_trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/trace_operation.rb:191:in `block in measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/span_operation.rb:151:in `measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/trace_operation.rb:191:in `measure' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:380:in `start_span' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:162:in `block in trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/context.rb:45:in `activate!' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/tracer.rb:161:in `trace' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing.rb:18:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/data_dog_tracing.rb:18:in `platform_trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing/platform_tracing.rb:29:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `block in call_tracers' from /usr/local/bundle/gems/activerecord-7.0.3.1/lib/active_record/connection_handling.rb:374:in `with_role_and_shard' from /usr/local/bundle/gems/activerecord-7.0.3.1/lib/active_record/connection_handling.rb:156:in `connected_to' from /app/app/graphql/tracers/database_reading_role_tracer.rb:22:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:83:in `call_tracers' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/tracing.rb:67:in `trace' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:60:in `run_queries' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/execution/multiplex.rb:50:in `run_all' from /usr/local/bundle/gems/graphql-1.13.15/lib/graphql/schema.rb:1768:in `multiplex' from /app/app/controllers/graphql_controller.rb:36:in `execute' from /usr/local/bundle/gems/actionpack-7.0.3.1/lib/action_controller/metal/basic_implicit_render.rb:6:in `send_action' from /usr/local/bundle/gems/actionpack-7.0.3.1/lib/abstract_controller/base.rb:215:in `process_action' from /usr/local/bundle/gems/ddtrace-1.5.2/lib/datadog/tracing/contrib/action_pack/action_controller/instrumentation.rb:129:in `process_action' from /usr/local/bundle/gems/actionpack-7.0.3.1/lib/action_controller/metal/rendering.rb:53:in `process_action' from /usr/local/bundle/gems/actionpack-7.0.3.1/lib/abstract_controller/callbacks.rb:234:in `block in process_action' from /usr/local/bundle/gems/activesupport-7.0.3.1/lib/active_support/callbacks.rb:118:in `block in run_callbacks' from /app/app/controllers/application_controller.rb:42:in `store_current_context' from /usr/local/bundle/gems/activesupport-7.0.3.1/lib/active_support/callbacks.rb:127:in `block in run_callbacks' from /usr/local/bundle/gems/activesupport-7.0.3.1/lib/active_support/callbacks.rb:138:in `run_callbacks' from /usr/local/bundle/gems/actionpack-7.0.3.1/lib/abstract_controller/callbacks.rb:233:in `process_action' from /usr/local/bundle/gems/actionpack-7.0.3.1/lib/action_controller/metal/rescue.rb:22:in `process_action' from /usr/local/bundle/gems/actionpack-7.0.3.1/lib/action_controller/metal/instrumentation.rb:67:in `block in process_action' from /usr/local/bundle/gems/activesupport-7.0.3.1/lib/active_support/notifications.rb:206:in `block in instrument' from /usr/local/bundle/gems/activesupport-7.0.3.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument' from /usr/local/bundle/gems/activesupport-7.0.3.1/lib/active_support/notifications.rb:206:in `instrument' from /usr/local/bundle/gems/actionpack-7.0.3.1/lib/action_controller/metal/instrumentation.rb:66:in `process_action' from /usr/local/bundle/gems/actionpack-7.0.3.1/lib/action_controller/metal/params_wrapper.rb:259:in `process_action' from /usr/local/bundle/gems/activerecord-7.0.3.1/lib/active_record/railties/controller_runtime.rb:27:in `process_action' from /usr/local/bundle/gems/actionpack-7.0.3.1/lib/abstract_controller/base.rb:151:in `proce ```

It is incredibly inconsistent

rmosolgo commented 1 year ago

Thanks for sharing the stack trace. I went digging into several lines, but everything looks in order to me.

You mentioned it hasn't happened in a while -- has it gotten less frequent over time?

One possibility is that there are some long-running subscriptions which started before the limiter key was added to context, so even when updates happen properly, there isn't that key in context. That might explain why it's happening less often (if it is), because those long-running subscriptions are finally terminating, and fewer and fewer are left over time.

That said, I wouldn't expect that to be a problem. With ActionCable, redeploying the Rails app causes all connections to be disconnected and reconnected, which also re-establishes all GraphQL subscriptions. I don't know if AnyCable works the same way or not, though.

In any case, here's a work-around you might try:

class CustomRuntimeLimiter < GraphQL::Enterprise::RuntimeLimiter 
  def limiter_key(query)
    if query.subscription_update? && query.context[:limiter_key].nil?
      # Somehow log this to keep an eye on frequency or to help debug
      "mysterious-no-limiter-key-subscription-update"
    else 
      super 
    end 
  end 

  def limit_for(key, query)
    if key == "mysterious-no-limiter-key-subscription-update"
      nil # don't apply a limit here -- for some reason this happens from time to time but we should permit it 
    else 
      super 
    end 
  end 
end 

Then, update your schema class:

use CustomRuntimeLimiter, ... 

That would cause these updates to run without an error (doc: https://graphql-ruby.org/limiters/runtime#customization)

Would a work-around like that work in your case?

Nealsoni00 commented 1 year ago

This has all been in local development and on development environment (not released to production) and only happens on some users. We have destroyed the socket connection and restarted all servers multiple times and the issue persists randomly.

I'll implement ur suggestion and a temporary workaround and create an error in datadog when it happens. Appreciate it!

This has been the issue preventing me from implementing Graphql Enterprise into production.

Anycable does not reconnect all websockets on release, rather the RPC (which resolves all subscriptions) gets a rolling release and the wesockets are maintained. We've had limmiter_key set on both controllers for weeks in all environments so i'd be surprised if the cache was the issue.

rmosolgo commented 10 months ago

Hey, just curious -- did that patch help shed any light on what's going on here?

Nealsoni00 commented 9 months ago

I believe the issue was due to anycable graphql subscriptions not having a default expiry and it resolving really old subscriptions with old context values that did not include the limiter_key. Thus, we had to clear those old ghost subscriptions manually.

I don't believe I need to use this fix now as there should only be active subscriptions with the proper limiter_key set.

Though for other users that implement this limiter in the future they should verify all contexts in memory have this limiter_key set before the server requires it with the use GraphQL::Enterprise::ActiveOperationLimiter

rmosolgo commented 9 months ago

Ah, interesting ... thanks for sharing what you found! I'll keep this in mind in case I get any future reports of it.