Don't nest Async primitives inside plain Ruby fibers

[rmosolgo]

Fixes #5463

This ended up being a significant rework of AsyncDataloader. Basically the goal was to remove all direct ::Fiber uses, instead relying on Async::... primitives. It was a long journey to get async control flow right but it turned out pretty elegant.

TODO:

• Unify the flow for running jobs tasks and running sources tasks. These are almost identical.
• Implement fiber limit, pass that test

[rmosolgo]

Sad, it seems like the test suite hangs now...

[rmosolgo]

Ok, I think the problem was that Fiber / Task nesting. I reworked it so that each pass over the set of pending dataloader fibers spins up a new job. This avoids any mixing between Async primitives and plain Ruby Fibers. It messed up some of the fiber counting tests though -- I'll sort them out in the morning.

@iyotov-havelock, could you try this branch in your app's test suite and development? You can bundle it with:

gem "graphql", github: "rmosolgo/graphql-ruby", ref: "async-dataloader-deadlock-fix"

please let me know how it goes!

[iyotov-havelock]

Hey @rmosolgo, thanks for checking this issue out.

Tested it with my 'real' app in development, sadly there's still an issue there:

Tested it with the demo app (https://github.com/iyotov-havelock/async-dataloader-issue), the No live threads left. Deadlock? error is no longer showing, but the GraphQL response is {"errors":[{"message":"undefined method 'nfields' for nil"}]}, which does not show up when using GraphQL::Dataloader instead of GraphQL::Dataloader::AsyncDataloader

[rmosolgo]

I saw that error, too, and assumed that GraphQL was "working," since it called code as expected. Inspecting the dataset, I see that it was passed the right values:

#<Sequel::Dataset::_Subclass: "SELECT * FROM \"foo_models\" WHERE (\"id\" IN (1, 2))">

My hunch is that Async + Sequel aren't playing nice here ... but do you have a reason to think that AsyncDataloader in particular is the cause of the issue?

Could you please share the full stack trace (NOT a screenshot) from the error in your application? Maybe some lines there will be a clue.

Also, if you can modify the replication app so that it deadlocks on this branch, I'd be happy to keep debugging on that.

---

UPDATE:

I got the example to run successfully by adding the fiber_concurrency extension:

diff --git a/config/database.rb b/config/database.rb
index 16f3b03..7ec45a8 100644
--- a/config/database.rb
+++ b/config/database.rb
@@ -1,4 +1,5 @@
 require 'sequel'
+Sequel.extension :fiber_concurrency

 DB = Sequel.connect(
   adapter: 'postgres',

Have you tried that extension in your app? I found it by searching randomly around the Sequel repo for the word "Fiber"...

With that addition, I get:

curl -X POST http://localhost:9292/graphql \
  -H "Content-Type: application/json" \
  -d '{"query": "{ getAllFoos { id name barModels { id name } } getAllBars { id name fooModel { id name } } }"}'

{"data":{"getAllFoos":[{"id":"1","name":"First Foo","barModels":[{"id":"1","name":"Bar 1 for Foo 1"},{"id":"2","name":"Bar 2 for Foo 1"},{"id":"3","name":"Bar 3 for Foo 1"}]},{"id":"2","name":"Second Foo","barModels":[{"id":"4","name":"Bar 1 for Foo 2"},{"id":"5","name":"Bar 2 for Foo 2"}]}],"getAllBars":[{"id":"1","name":"Bar 1 for Foo 1","fooModel":{"id":"1","name":"First Foo"}},{"id":"2","name":"Bar 2 for Foo 1","fooModel":{"id":"1","name":"First Foo"}},{"id":"3","name":"Bar 3 for Foo 1","fooModel":{"id":"1","name":"First Foo"}},{"id":"4","name":"Bar 1 for Foo 2","fooModel":{"id":"2","name":"Second Foo"}},{"id":"5","name":"Bar 2 for Foo 2","fooModel":{"id":"2","name":"Second Foo"}}]}}

[iyotov-havelock]

@rmosolgo I modified the replication app, check out this commit:
iyotov-havelock/async-dataloader-issue@6af81bf

To reproduce the issue, do the getAllFoos query again. It's quite possible to be an Async + Sequel issue

[rmosolgo]

Interesting -- a change like that puts Async primitives back inside a plain Ruby Fiber.new { ... }, further suggesting that's the origin of the issues here. It might be possible to rewrite that part of AsyncDataloader to use Async primitives entirely, rather than plain Ruby fibers, but it was really hard to do last time so I gave up. I'll try again...

[rmosolgo]

👋 I made time to dig back into this and refactor AsyncDataloader to use Async primitives for execution jobs too. After that, I pulled your updated example and updated the Gemfile to use this version of graphql-ruby. Then, when I curl'd, I got a correct response!

➜  ~ curl -X POST http://localhost:9292/graphql \
  -H "Content-Type: application/json" \
  -d '{"query": "{ getAllFoos { id name barModels { id name } } getAllBars { id name fooModel { id name } } }"}'
{"data":{"getAllFoos":[{"id":"1","name":"First Foo","barModels":[{"id":"1","name":"Bar 1 for Foo 1"},{"id":"2","name":"Bar 2 for Foo 1"},{"id":"3","name":"Bar 3 for Foo 1"}]},{"id":"2","name":"Second Foo","barModels":[{"id":"4","name":"Bar 1 for Foo 2"},{"id":"5","name":"Bar 2 for Foo 2"}]}],"getAllBars":[{"id":"1","name":"Bar 1 for Foo 1","fooModel":{"id":"1","name":"First Foo"}},{"id":"2","name":"Bar 2 for Foo 1","fooModel":{"id":"1","name":"First Foo"}},{"id":"3","name":"Bar 3 for Foo 1","fooModel":{"id":"1","name":"First Foo"}},{"id":"4","name":"Bar 1 for Foo 2","fooModel":{"id":"2","name":"Second Foo"}},{"id":"5","name":"Bar 2 for Foo 2","fooModel":{"id":"2","name":"Second Foo"}}]}}%

Could you give this branch a try in your app when you get a try please?

[rmosolgo]

(The handoff between sources and execution isn't quite right here yet ...)

Edit: I think the problem is that Dataloader#run_isolated can't be isolated in this case because Async uses a single (per- Thread maybe?) Reactor. Calling yield from inside #run_isolated may pass control to a task from the surrounding #run.

[iyotov-havelock]

👋 I made time to dig back into this and refactor AsyncDataloader to use Async primitives for execution jobs too. After that, I pulled your updated example and updated the Gemfile to use this version of graphql-ruby. Then, when I curl'd, I got a correct response!

➜  ~ curl -X POST http://localhost:9292/graphql \
  -H "Content-Type: application/json" \
  -d '{"query": "{ getAllFoos { id name barModels { id name } } getAllBars { id name fooModel { id name } } }"}'
{"data":{"getAllFoos":[{"id":"1","name":"First Foo","barModels":[{"id":"1","name":"Bar 1 for Foo 1"},{"id":"2","name":"Bar 2 for Foo 1"},{"id":"3","name":"Bar 3 for Foo 1"}]},{"id":"2","name":"Second Foo","barModels":[{"id":"4","name":"Bar 1 for Foo 2"},{"id":"5","name":"Bar 2 for Foo 2"}]}],"getAllBars":[{"id":"1","name":"Bar 1 for Foo 1","fooModel":{"id":"1","name":"First Foo"}},{"id":"2","name":"Bar 2 for Foo 1","fooModel":{"id":"1","name":"First Foo"}},{"id":"3","name":"Bar 3 for Foo 1","fooModel":{"id":"1","name":"First Foo"}},{"id":"4","name":"Bar 1 for Foo 2","fooModel":{"id":"2","name":"Second Foo"}},{"id":"5","name":"Bar 2 for Foo 2","fooModel":{"id":"2","name":"Second Foo"}}]}}%

Could you give this branch a try in your app when you get a try please?

Hi, thanks for addressing this. App is working fine with the branch 👍

[rmosolgo]

Awesome, glad to hear it. Today I'm going to try to address #5462 which I think will also address the failing specs here. But it sounds like migrating all usage from Fiber to Async::Task did the job 🎉

[rmosolgo]

👋 I am picking this up after a bit of a rabbit trail. I have a new, re-written execution module which I expect to make this easier to fix.

But I'm running into the same problem where I have a call to task.yield but Async doesn't necessarily run that task; instead, it calls any random task, including the task that called task.yield.

I have this feeling that I need to refactor the async control flow but I haven't figured it out yet.

[rmosolgo]

I've been thinking about this some more, and digging through the Async docs looking for inspiration. I think I have an idea which I'll try out in the next few days:

• When creating async tasks, put them in a "working" list
• The manager fiber waits for "working" list to be empty
  • Tasks must either put themselves on the "waiting" list
  • Or remove themselves from the "working" list (if the jobs queue is empty)
• When code calls dataloader.yield:
  • it moves Task.current from a "working" list to a "waiting" list
  • it waits for an Async::Condition to be triggered
• Then, after Dataloader sources have been run, it can rerun "waiting" tasks by:
  • moving all "waiting" tasks to the "working" list
  • triggering the condition so that they restart

[rmosolgo]

Ok, I think I finally worked out the actual async control flow here. Things are passing and the two job flows basically match. I still need to implement fiber_limit: ....

[thiennghv0201-freec]

any news here?

[rmosolgo]

This branch is completely working, with a rebuilt Async-based control flow, except for fiber_limit: .... Let me know how it goes if you give it a try in your app!

[rmosolgo]

Ok, I finally got fiber_limit: working. It's not as precise when using Async, though, because Async spins up its own fibers under the hood. So fiber_limit: ... applies to GraphQL-Ruby's own fibers, but not to some extras created (somewhere?) by Async.

If we needed a better understanding of this, we could patch Fiber#initialize to log its caller.

[rmosolgo]

@iyotov-havelock and @thiennghv0201-freec, if you give this a try on master (or 2.6.4+) and run into more trouble, please open a new issue describing the problem!