Subscription to Lacinia Pedestal back end: Getting just the first event

[lrosso]

Hi, first of all, thanks and congratulations for such a nice tool / project !

I am coding a pedagogical project, implementing a full stack GraphQL solution, porting to Clojure/script a full stack GraphQL Apollo tutorial, in order to get started both in Clojure/script and in GraphQL and, by the way, share the experience, assuming it might be useful for others as well.

I have already implemented all the articles there on server-side. Among them, and for this question, the most relevant shows how to implement a couple server-side subscriptions.

I have been able to port to Clojure both those subscriptions: either the one for new links, and the other one, for votes. Both seem to be working fine, and accesible by means of the GraphiQL tools supplied with Lacinia Pedestal.

I have just coded the corresponding front-end article.

The issue I am currently having is:

1. as I post a new link by means of the GraphiQL tool, it gets pushed right both to the subscription activated in a second instance of GraphiQL, and in the initial links list implemented in my application's front-end
2. however, as I create further links, although they are pushed right to GraphiQL, they are not reaching my front-end

I have detected an exception thrown on the server-side, in the context of Lacinia Pedestal, as soon as I post the second link creation by GraphiQL, and on, shown in the following attachment: exception.txt

I have also attached Lacinia Pedestal's logged events, with its log in DEBUG level: lacinia-pedestal-log-20190429T193306.txt

There, besides the loop corresponding to GraphiQL, identified by single-digit ids, I have detected another two ones:

1. one for the front-end's subscription, identified by subscribe-to-new-links id, and
2. another one, identified by ki1m2mj6: it doesn't correspond to any subscription, but to the GraphQL query which loads the links' list. It seems precisely this loop the only one reaching the context in which the exception is thrown:

19:34:57.485 [async-dispatch-29] DEBUG c.w.lacinia.pedestal.subscriptions - {:event :com.walmartlabs.lacinia.pedestal.subscriptions/cleanup-ch, :id "ki1m2mj6", :line 112}

According to the following print screens, re-graph's section in re-frame db seems fine:

I guess I am skipping some necessary config related with re-graph, but I have not been able to find out which one...

In the init function in core.cljs, I began with an empty map, {}, then I have added :resume-subscriptions?, set both to true and then false, and then :connection-init-payload {}, even though that is precisely a default value...

(defn ^:export init []
  (routes/app-routes)
  ;; initialise re-graph, including configuration options
  (re-frame/dispatch [::re-graph/init {:resume-subscriptions?   false
                                       :connection-init-payload {}}])
  (re-frame/dispatch-sync [::events/initialize-db])
  (re-frame/dispatch-sync [::events/subscribe-2-new-links])
  (dev-setup)
  (mount-root))

What am I doing wrong?

Thanks in advance and, again, congratulations !

Luis https://promesante.github.io/ https://github.com/promesante

[oliyh]

Hi,

From what I can tell, you are establishing two subscriptions on the articles and then posting in new articles, expecting them to be fed to both subscriptions. Lacinia is throwing an error on at least one of the subscriptions which is presumably then shutting down, and I'm guessing this is the one that your re-graph is connected to, because in your screenshots of re-frame-10x the re-graph websocket state is :ready? false. Have a look in the websockets section of the network tab - do you see the websocket being disconnected, and are there any errors?

I suggest you get to the bottom of the issue in lacinia - it sounds like your front end is working but when that error occurs on your server the websocket is being disconnected.

Hope this helps

[lrosso]

Hi Olivier,

Thanks for the quick reply !

I have reproduced the reported issue and, in every try, re-frame-10x reported [:ready? true] for re-graph websocket, as shown in the following print screen. Not sure why it had been set to false in previous print screen: perhaps I had shut down Lacinia beforehand.

Furthermore, I haven't detected any websocket error in the network section.

Regarding subscriptions, although I have declared two on server-side, in the front-end I have declared a single one. Hence, I am not able to follow why there would be a double subscription.

1. subscriptions declared on server-side:

  :subscriptions
 {
  :newLink
  {:type :Link
   :stream :subscription/new-link}

  :newVote
  {:type :Vote
   :stream :subscription/new-vote}
  }

2. single subscription declared on front-end, corresponding to the former declared above on server-side:

(re-frame/reg-event-db
  ::on-new-link
  (fn [db [_ {:keys [data errors] :as payload}]]
    (let [links-prev (:links db)
          link-new (:newLink data)
          links (conj links-prev link-new)]
      (-> db
          (assoc :loading? false)
          (assoc :links links)))))

(re-frame/reg-event-db
 ::subscribe-2-new-links
 (fn-traced
  [db  [_ _]]
  (re-frame/dispatch
   [::re-graph/subscribe
    :subscribe-to-new-links
    "{
      newLink {
        id
        url
        description
        created_at
        posted_by {
          id
          name
        }
      }
    }"
    {}
    [::on-new-link]])))

Links' list is loaded by means of the following GraphQL query, and not a subscription. During debugging sessions, I remember having noticed this query having been sent to Lacinia by means of websocket rather than http, as I'd expect: I will try to reproduce this and then share findings.

(re-frame/reg-event-db
  ::on-feed
  (fn [db [_ {:keys [data errors] :as payload}]]
    (let [links (get-in data [:feed :links])]
      (-> db
          (assoc :loading? false)
          (assoc :links links)))))

(re-frame/reg-event-db
 ::initialize-db
  (fn-traced [db  [_ _]]
    (re-frame/dispatch
      [::re-graph/query
       "{
          feed {
            count
            links {
              id
              created_at
              url
              description
              posted_by {
                id
                name
              }
              votes {
                id
                user {
                  id
                }
              }
            }
          }
       }"
       {}
       [::on-feed]])
     (-> db
         (assoc :loading? true)
         (assoc :error false))))

Both of them, the query and the subscription, are triggered from the core namespace, init function:

(defn ^:export init []
  (routes/app-routes)
  ;; initialise re-graph, including configuration options
  (re-frame/dispatch [::re-graph/init {:resume-subscriptions?   false
                                       :connection-init-payload {}}])
  (re-frame/dispatch-sync [::events/initialize-db])
  (re-frame/dispatch-sync [::events/subscribe-2-new-links])
  (dev-setup)
  (mount-root))

I will go on digging and debugging but, as I don't know how long it will take, I'd rather share this info and questions here beforehand.

Thank you very much !

Luis https://promesante.github.io/ https://github.com/promesante

[lrosso]

Hi Olivier,

I have kept on debugging:

1. my own application
2. re-graph
3. lacinia-pedestal
4. lacinia
5. pedestal
6. graphiql

Mainly, I have compared data flow between the two ways to access the subscription on the back-end:

1. through the GraphiQL tool supplied with lacinia-pedestal: as I have shared above, this way, subscription has always run successfully
2. from my application's front-end, through re-graph: this way, just the first link creation event gets pushed to front-end; subsequent ones fail to.

The single difference between them I have been able to find out takes place in lacinia-pedestal's subscriptions module.

In the connection-loop function, in how the alt! function in its go-loop handles ws-data-ch with messages of type "start"; that is, lines 142 though 151:

1. with subscriptions handled by means of GraphiQL: this code is invoked about once a second
2. on the other hand, with them handled by my front-end: it is invoked just once, matching the single event being pushed to this front-end mentioned above

As that channel, ws-data-ch, is closed in that same module, in function listener-fn-factory, in the function bound there to the on-close event, lines 496 through 499, assuming in the latter scenario might be taking place that channel being closed, and not in the former, I debugged that context as well. However, I have not found out any difference there between the two scenarios under analysis: in both of them, this code is invoked about once a second as well.

What am I doing or might be wrong here?

Thanks in advance !

Luis https://promesante.github.io/ https://github.com/promesante

[oliyh]

Hi,

Were you able to solve this problem? Apologies I've not been able to offer much help.

Regards

[promesante]

Hi Oliver,

I went on studying the implementation of re-graph, as well as lacinia, lacinia-pedestal, graphiql and websockets.

And finally realized how GraphQL subscripcions are implemented in graphiql. And ported that code into re-graph, and immediately got it working.

I forked re-graph and shared that addition there, in the following commit: https://github.com/promesante/re-graph/commit/6131bcafbe41ee6d133c31ee69f956ae68e30b71

In that fork I have shared another modification to re-graph, but I will depict it in another issue here.

Furthermore, I have just finished the sideproject for which I have been using re-graph: https://github.com/promesante/hn-clj-pedestal-re-frame

Its goal has been having a toy GraphQL solution fully implemented in Clojure/script, so that I could finally put Clojure/script and GraphQL into practice and, by the way, sharing the resulting/working code.

In the next couple weeks I plan to share an introductory post in my blog, followed by more specific ones.

Your comments and suggestions are more than welcome.

Thanks

Luis https://promesante.github.io/ https://github.com/promesante

[oliyh]

Hi,

I'm surprised - the "ka" is a keep-alive message to ensure that the websocket is still connected so that the server can more proactively remove connections when it is unable to write to them, or for the client to be able to detect dropped connections better.

I suppose it's possible that your server is expecting an acknowledgement, in which case you might find a better solution would be to send an ack message back rather than disconnecting and reconnecting the websocket.

I am using lacinia-pedestal too and have never had a problem with this - the "ka" is dropped without acknowledgement and this has not resulted in any issues.

[nimaai]

It seems I have the same or similar issue:

Upon subscribing the event handler (::on-message) is triggered only on receiving the first message, after that no more.

The connection seems to be fine. It keeps on receiving messages as expected.

And, I think it somehow concerns outgoing messages too. The unsubscribe dispatch works only if the subscribe dispatch was not fired before.

My example code is here.

[oliyh]

Hi,

Thanks for letting me know. I've spent quite a while trying to get both your projects to run locally.

@promesante I managed to get your app running but clicking on submit to create a new post did nothing. Navigating back to the "new" or "top" links did not update the UI. There were no errors in either console.

@nimaai I could not get the database into a state where I could start the repl, I have issues with glibc and cannot run the rake scripts

Would either of you be able to produce a minimal project that reproduces the error that I can ideally just run with lein or boot with no external dependencies?

Thanks

[nimaai]

@oliyh I have stripped the stuff with the database from the code base and now you should be able to get it running.

Steps to reproduce:

$ git clone --recursive https://github.com/leihs/leihs-borrow.git
$ cd leihs-borrow
$ git checkout origin/re-graph-issue
$ npm install react create-react-class react-dom
$ shadow-cljs release playground
$ boot dev run

Then visit http://localhost:3250/borrow/regraph-example and use the subscribe and unsubscribe buttons.

After subscribing the counter should be increasing from 1 upwards, but it isn't.

Unsubscribe does not work after subscribe (or at least I don't see the respective message in the websocket connection).

Maybe I have forgotten something. Let me know.

[promesante]

hi @oliyh

In order to submit a link, you have to be logged in.

Had you signed up a new user in the login section, and then logged in as that user?

Thanks

Luis https://promesante.github.io/ https://github.com/promesante

[oliyh]

Hi @nimaai

Thank you for the simple steps to reproduce, I found what your issue was. Your re-frame handler for the message was ignoring the existing value of the db (where the re-graph instance lives) and returning a new value, meaning that you lost your re-graph instance and it was unable to handle further messages.

  (re-frame/reg-event-db
    ::on-message
    [(when ^boolean goog.DEBUG re-frame/debug)]
    (fn [_ [_ payload]]
      {::result payload}))

I'm a bit surprised there are no errors arising from this.

Your handler should look like this:

  (re-frame/reg-event-db
    ::on-message
    [(when ^boolean goog.DEBUG re-frame/debug)]
    (fn [db [_ payload]]
      (assoc db ::result payload)))

I then saw the result ticking as the new values flowed in from the websocket.

Hope this helps Oliy

[oliyh]

Hi @promesante

I am unable to sign up or login. I had to override the :loading subscription to false so that I could submit the form and then my create account / login mutations were sent but no responses ever came back on the websocket, and there were no errors in the console or logs either. I don't know if this is related to the db or not, although I ran setup-db.sh with this output:

$ sudo -u postgres ./setup-db.sh 
create user hn_role password 'lacinia';
CREATE ROLE
psql:setup-db.sql:1: NOTICE:  table "link" does not exist, skipping
DROP TABLE
psql:setup-db.sql:2: NOTICE:  table "usr" does not exist, skipping
DROP TABLE
psql:setup-db.sql:3: NOTICE:  table "vote" does not exist, skipping
DROP TABLE
CREATE TABLE
INSERT 0 2
CREATE TABLE
INSERT 0 2
CREATE TABLE
INSERT 0 3

So I still can't reproduce. Are you able to reduce the problem to something I can run locally more easily?

Thanks

[promesante]

hi @oliyh

That output is ok: actually, it is exactly the same as the one shown in the repo's README.

Have you followed instructions given there, in the README, in the subsequent section, "Dependencies", regarding my own cloned version of re-graph with a couple of workarounds:

1. one depicted here, in a comment above
2. the other in another issue I opened here?

Thanks !

[nimaai]

Hi @nimaai

Thank you for the simple steps to reproduce, I found what your issue was. Your re-frame handler for the message was ignoring the existing value of the db (where the re-graph instance lives) and returning a new value, meaning that you lost your re-graph instance and it was unable to handle further messages.

  (re-frame/reg-event-db
    ::on-message
    [(when ^boolean goog.DEBUG re-frame/debug)]
    (fn [_ [_ payload]]
      {::result payload}))

I'm a bit surprised there are no errors arising from this.

Your handler should look like this:

  (re-frame/reg-event-db
    ::on-message
    [(when ^boolean goog.DEBUG re-frame/debug)]
    (fn [db [_ payload]]
      (assoc db ::result payload)))

I then saw the result ticking as the new values flowed in from the websocket.

Hope this helps Oliy

Thanks so much @oliyh for taking a look. Now it works, including unsubscribing. 👍

[oliyh]

Hi @promesante

I think your subscription issue is because you have not implemented your streamers properly in lacinia. The streamers should start a thread which calls the streamer-fn each time you want to send a new value for the subscription. Yours simply wait for the first event and then exit, which is why the reconnect works because re-graph automatically resumes your subscriptions and gets one more value until the next ka when you have made it reconnect again.

https://github.com/promesante/hn-clj-pedestal-re-frame/blob/master/src/clj/hn_clj_pedestal_re_frame/schema.clj#L144-L154

(defn new-link
  [db]
  (fn [context args source-stream]
    (let [new-link @link-events]
      (source-stream new-link))))

The documentation describes what you need to do. There's an example here.

I think your mutation over websocket issue is also related to your lacinia implementation, although I can't see an obvious cause. In graphiql the mutations are sent over HTTP, not via the websocket. I have non-public projects where queries and mutations work over the websocket. The Apollo documentation states that subscriptions, queries and mutations should be possible over the websocket. The lacinia docs state this too. I added some printlns to the mutation handlers that never got called when mutations were sent over websocket.

Hope all this helps. I still don't see any issues with re-graph here so I am going to close this issue as it has already gotten quite long and would be confusing for someone else to read. Feel free to open a new issue if you are still seeing strange behaviour once you have verified your server behaviour.

Thanks