rmosolgo / graphql-ruby

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

GraphQL subscription field with argument not receiving updates as expected #5153

Closed denisahearn closed 1 week ago

denisahearn commented 2 weeks ago

Describe the bug

Hello,

First off, I can't say for sure if what I'm about to describe is a bug, missing documentation, or misunderstood behavior on my part.

I am trying to get a GraphQL subscription working that uses an argument in much the same way as the room_id argument described in https://graphql-ruby.org/subscriptions/subscription_classes.html#arguments. In my case, I want to limit a subscription to receive updates only when an order is updated that belongs to an organization that was specified at subscription creation time (via a subscription argument), and I cannot for the life of me get my subscription to send updates once I introduce the use of an argument. I am however able to get the subscription to work just fine when it does not use an argument.

Here are the pertinent parts of my code for when the subscription class does not have any arguments:

// GraphQL subscription issued by the client app

subscription OnOrderUpdated {
  order_updated {
    order {
      status
    }
  }
}
# app/graphql/subscriptions/order_updated.rb

module Subscriptions
  class OrderUpdated < BaseSubscription
    description 'Order updated event'

    field :order, Types::Order,
          description: 'The order that was updated',
          null: false
  end
end
# app/models/order.rb

class Order < ApplicationRecord
  after_update :check_to_trigger_order_updated_event

  private def check_to_trigger_order_updated_event
    return unless saved_changes?

    # Trigger an order_updated event
    arguments = {}
    payload = { order: self }
    MySchema.subscriptions.trigger('order_updated', arguments, payload)
  end
end

Also, I have a GraphqlChannel class in my Rails app that matches the example in https://graphql-ruby.org/api-doc/2.4.2/GraphQL/Subscriptions/ActionCableSubscriptions.html

This works, the subscription in the React app receives an update whenever any order in the system is updated, however that's not what I really want. I want the client to provide the ID of an organization whose orders they want to monitor for updates, and only be notified when orders in that organization are updated.

Here are the changes I made to my code to accomplish this:

// GraphQL subscription issued by the client app

subscription OnOrderUpdated($organization_id: ID!) {
  order_updated(organization_id: $organization_id) {
    order {
      status
    }
  }
}

I provide an organization ID in the React App when creating a subscription

import { useSubscription } from '@apollo/client'
import { SUBSCRIPTION_ORDER_UPDATED } from '@src/api/orders'

useSubscription(
  SUBSCRIPTION_ORDER_UPDATED,
  {
    variables: {
      organization_id: 5   // currently hardcoded for testing purposes
    }
  }
)
# app/graphql/subscriptions/order_updated.rb

module Subscriptions
  class OrderUpdated < BaseSubscription
    description 'Order updated event'

    argument :organization_id, ID,
              loads: Types::Organization,
              description: 'The ID of the organization that owns the orders for which you are interested in receiving updates'

    field :order, Types::Order,
          description: 'The order that was updated',
          null: false
  end
end
# app/models/order.rb

class Order < ApplicationRecord
  after_update :check_to_trigger_order_updated_event

  private def check_to_trigger_order_updated_event
    return unless saved_changes?

    arguments = { organization_id: self.organization_id }
    payload = { order: self }
    MySchema.subscriptions.trigger('order_updated', arguments, payload)
  end
end

Once I do this, the subscription stops receiving updates, and specifically, it does not receive an update when the organization ID provided at subscription creation is the same as the ID of the organization of an order that gets updated.

This is what I see in the Rails log for ActionCable when the subscription class does not define an argument:

[ActionCable] Broadcasting to graphql-event::order_updated:: "{\"order\":{\"__gid__\":\"Z2lkOi8vY2xvdWQtdmF1bHQvT3JkZXIvNQ\"},\"__sym_keys__\":[\"order\"]}"

[ActionCable] Broadcasting to graphql-subscription:7c3e1cc0-093b-4530-9d5c-e9faf4152daa: {:result=>{"data"=>{"order_updated"=>{"order"=>{"id"=>"5...

This is what I see in the Rails log for ActionCable when the subscription class defines an organization_id argument:

ActionCable] Broadcasting to graphql-event::order_updated:organization_id:5: "{\"order\":{\"__gid__\":\"Z2lkOi8vY2xvdWQtdmF1bHQvT3JkZXIvNQ\"},\"__sym_keys__\":[\"order\"]}"

I have spent a bunch of time trying different things and reading code in the graphql-ruby and actioncable gems in an effort to piece together the difference in behavior when using subscription arguments and when not using them, but I haven't been able to figure out what's preventing subscription updates when using the organization_id argument.

Based on what I read here and here I feel like this should work. Am I using subscription class arguments correctly and should they work as I am expecting?

Any help you can provide to get me unstuck or pointed in the right direction would be very much appreciated.

Versions

graphql version: 2.3.19 rails version: 7.2.1.2 graphql-ruby-client version: 1.14.3 @rails/actioncable@ version: 7.2.200

GraphQL schema

Without a subscription argument

"""
The subscription root for the GraphQL schema
"""
type Subscription {
  """
  An order was updated
  """
  order_updated: OrderUpdatedPayload!
}

With a subscription argument

"""
The subscription root for the GraphQL schema
"""
type Subscription {
  """
  An order was updated
  """
  order_updated(
    """
    The ID of the organization that owns the orders for which you are interested in receiving updates
    """
    organization_id: ID!
  ): OrderUpdatedPayload!
}
"""
Autogenerated return type of OrderUpdated.
"""
type OrderUpdatedPayload {
  """
  The order that was updated
  """
  order: Order!
}

The rest of the code asked for is listed in my explanation of the issue above

Steps to reproduce

The scenario that produces the issue for me is described above. It involves adding an argument to the subscription class, and providing a value for the argument when triggering an event for that subscription field.

Expected behavior

When using an argument on a subscription class, and providing an argument value when triggering a subscription event, I expect a subscriber who provided the same argument at subscription creation to receive that event.

Actual behavior

The subscriber stops receives events once an argument is introduced into the subscription class.

rmosolgo commented 2 weeks ago

Hey, thanks for the detailed write-up. I'm not sure what's wrong either ... it sounds like it should work!

The ActionCable broadcast message in the logs looks right to me, so it seems like it's sending updates properly.

One thing that crossed my mind but I decided probably wasn't the problem was string IDs vs integer IDs. The GraphQL ID type uses a string, but order.organization_id probably returns a Ruby Integer. In some cases, that mismatch matters, but I don't think it should matter here since, in both cases, the value is .to_s'd to create the topic string that appears in the logs.

A couple of thoughts:

denisahearn commented 1 week ago

Thanks for the quick response.

Does ActionCable log anything in the initial subscription? If not, you could add a puts here and see if it prints a matching string to the broadcast that it logs later:

That's the odd thing. I was instrumenting code in the graphql-ruby gem with Rails.logger.info statements yesterday, including in the setup_stream method in lib/graphql/subscriptions/action_cable_subscriptions.rb, and in the case when my OrderUpdated subscription class does not have an argument, I would see this in the Rails log after the subscription is created:

[ActionCable] Broadcasting to graphql-subscription:8c978c22-b494-4c6f-8afc-2a48a7f8be4c: {:more=>false}
*** setup_stream: event_stream = graphql-event::order_updated:

and the subscription worked to send updates to the client.

However once I added the organization_id argument to the OrderUpdated class and restarted the Rails and React apps and created a new subscription, neither of those log statements appear in the Rails log, even though I can see in the log that the React app issued a GET request to the /subscriptions endpoint in my Rails app to create the subscription.

I instrumented code higher up in the call stack in the gem to find out why setup_stream wasn't getting called when using a subscription argument, but I wasn't able to nail it down.

If you go through the subscribe-and-update flow, is there any difference in the JavaScript log? (Maybe some error is raised there, or some request fails to go through?)

Unfortunately, there's nothing outputted to the JavaScript console in either scenario that would indicate there's an issue client-side.

I think my next step will be to try and reproduce this issue in a small sample Rails app and React app. If I'm able to reproduce the problem, then I'll attach the code for the apps to this GitHub issue in case you would like to look at it on your end.

rmosolgo commented 1 week ago

Ok, it sounds like we're on to something! If there's no setup_stream message, it's probably not setting up a subscription in the first place.

the React app issued a GET request to the /subscriptions endpoint

... Is that normal? If you're using ActionCable, shouldn't it have opened a websocket connection to the ActionCable server? (Does it do the same GET before you add the argument?)

After adding the argument, can you confirm that the initial subscription { ... } is successful? What's the initial GraphQL result for it? (I wonder if it's returning "errors" : ... for some reason, and therefore not actually setting up the subscription on the backend. You might be able to find that result in the browser's network tab or by adding a log line to the Rails server.)

denisahearn commented 1 week ago

I found the issue, and you were correct, the subscription was not getting set up correctly on the backend. I added a logger statement in the Rails app to output the results of the initial GraphQL subscription request, and lo and behold there was an error as you suspected:

result = #<GraphQL::Query::Result @query=... @to_h={"errors"=>[{"message"=>"Variable $organizationId of type ID! was provided invalid value", "locations"=>[{"line"=>77, "column"=>29}], "extensions"=>{"value"=>nil, "problems"=>[{"path"=>[], "explanation"=>"Expected value to not be null"}]}}]}>

It turns out that my React front end was sending organization_id in the variables, however I defined the subscription GQL request to use an $organizationId variable (as shown below):

export const SUBSCRIPTION_ORDER_UPDATED = gql`
  subscription OnOrderUpdated($organizationId: ID!) {
    order_updated(organization_id: $organizationId) {
      order {
        status
      }
    }
  }
`
  useSubscription(
    SUBSCRIPTION_ORDER_UPDATED,
    {
      variables: {
        organization_id: 5 
      }
    }
  )

You might wonder why I'm mixing snake case and camel case here? The GraphQL API was built by one team using snake case, and the React app (which came later on) was built by another team and uses camel case internally. Unfortunately this leads to a mismatch in casing at the point of issuing GraphQL requests. Once I changed the useSubscription hook in the React app to provide organizationId instead of organization_id the subscription started working as expected.

Thanks so much for taking your time to help me figure out the problem.

rmosolgo commented 1 week ago

Glad you got to the bottom of it! Thanks for sharing what you found.