Fibers not being purged when an EXPLAIN query is run in an ActiveSupport::Notification callback

[coderberry]

I have been working on an open source app AppMap. There is an issue (#349) that I have been trying to solve but am completely stumped. This only happens when the Rails app has graphql-ruby, appmap, and has the configuration Rails.applcation.config.active_support.isolation_level = :fiber.

AppMap is a gem that sets up hooks on ActiveSupport::Notification subscriptions [hook]. Essentially, when a graphql query is made, it triggers the ActiveSupport::Notification subscriber which runs a SQL EXPLAIN.

When the EXPLAIN query runs, it consumes a connection from the connection pool, but for some reason the terminated connections are not cleared out once the pool has been filled, which I believe is the way it's supposed to work.

Here's a video of the experience (6 requests with only 5 connections):

Here's the code that's performing the EXPLAIN query:

def execute_query(sql)

  execute_in_context { ActiveRecord::Base.connection.execute(sql).to_a }
end

private

# Rails 7.1 introduced ActiveSupport::IsolatedExecutionState which resolves issues related to Enumerator and
# Threads. The `graphql-ruby` gem uses the `async` gem to run queries in a separate fiber. When the Fiber
# executing the ActiveRecord query within AppMap, the `.transfer` is not handed back to the root Fiber. This
# causes the Fiber to remain in a "suspended" state instead of "terminated". By wrapping the execution with
# a Fiber, the transfer is handled and terminated correctly.
#
# @see Demonstration of Fibers not being transfered to the root Fiber
#      https://replit.com/@coderberry/Fiber-Transfer-Example
#
# Also, when a connection is manually checked out, Rails does not automatically release the connection. By
# wrapping the execution with `ActiveRecord::Base.connection_pool.with_connection`, we ensure the connection
# is properly released.
def execute_in_context
  if defined?(ActiveSupport::IsolatedExecutionState) && ActiveSupport::IsolatedExecutionState.context == :fiber
    Fiber.new do
      ActiveRecord::Base.connection_pool.with_connection { yield }
    end.resume
  else
    ActiveRecord::Base.connection_pool.with_connection { yield }
  end
end

Does anyone have any thoughts on why this might be happening?

[rmosolgo]

I reported this issue (that .transfer'd fibers don't terminate properly) on the Ruby bug tracker and, sadly, I was told it's a wont-fix (maybe even by design?): https://bugs.ruby-lang.org/issues/20081

As a result, I rolled back graphql-ruby's direct usage of Fiber#transfer. Instead, I added a document about how to achieve parallelism with dataloader sources: https://graphql-ruby.org/dataloader/parallelism

It's really too bad because if Fiber#transfer worked as I (we?) thought it was going to, you could get parallel-everything, basically for free, in graphql-ruby. But alas, it isn't so.

I reported the same bug to Async, too: socketry/async#295.

I left AsyncDataloader in GraphQL-Ruby, but greatly reduced its scope. Instead of running all GraphQL execution inside Async { ... }, it only resolves Dataloader sources inside Async. In that narrower scope, it runs a tight loop so I can track all fibers and make sure they terminate properly. But you don't get as much parallel awesomeness!

Are you able to replicate the AppMap-related issue on the latest graphql-ruby? Does the Fiber.new { ... }.resume work to address the issue?

[coderberry]

@rmosolgo first let me say thank you for all of your amazing contributions to the Ruby community!

I saw the ticket you submitted to Ruby core, but wasn't sure if anything had changed since. I really appreciate your additional context into why this is failing.

Are you able to replicate the AppMap-related issue on the latest graphql-ruby?

Yes. Here is the repo that replicates the issue (fork of your project): https://github.com/coderberry/appmap-test-app-fiber-graphql/blob/main/README.md. The README explains how to replicate the issue.

Does the Fiber.new { ... }.resume work to address the issue?

I had hoped it would based on the bug you reported to ruby. I even went as far as replicating these tests in a replit.

Here is the code within AppMap that takes from the connection pool:

def execute_query(sql)
  ActiveRecord::Base.connection.execute(sql).to_a
end

Here is the modification I tried expecting it to be resolved based on the your bug report and the replit above:

def execute_query(sql)
  if ActiveSupport::IsolatedExecutionState.context == :fiber
    Fiber.new do
      ActiveRecord::Base.connection_pool.with_connection do
        ActiveRecord::Base.connection.execute(sql).to_a
      end
    end.resume
  else  
    ActiveRecord::Base.connection_pool.with_connection do
      ActiveRecord::Base.connection.execute(sql).to_a
    end
  end
end

https://github.com/getappmap/appmap-ruby/blob/master/lib/appmap/handler/rails/sql_handler.rb#L134-L140.