rails: 6.0.0.beta2: .connected_to() block throws "No connection pool with 'primary' found."

Steps to reproduce

I have several databases holding the same models. On a per-request basis, I use an around_action and ActiveRecord::Base.connected_to to make sure I’m connecting to the right database.

That around_action is implemented as:

ActiveRecord::Base.connected_to(database: {writing: current_instance.database_key}) do 
  yield
end

Expected behavior

I would expect connections to each database to be kept alive, and my around_action switches the connection that’s used for that request.

Actual behavior

Usually with no more than 25 refreshes - all with current_instance.database_key returning the same symbol - the first query inside my action will throw “No connection pool with ‘primary’ found.” I know it’s the first query because the first query does appear in my logs, like it would on a successful request.

Debugging so far

I’ve added logs above the block to determine the current process, current thread, and connection_pool.stat. Those look like:

[726575e0-5624-4f88-9a45-2eb52c4b6d52] {:size=>5, :connections=>1, :busy=>1, :dead=>0, :idle=>0, :waiting=>0, :checkout_timeout=>5}
[726575e0-5624-4f88-9a45-2eb52c4b6d52] Process 61 Thread 47375888360080

[1278a189-7bf2-466a-97b4-483ea39e3a26] {:size=>5, :connections=>1, :busy=>1, :dead=>0, :idle=>0, :waiting=>0, :checkout_timeout=>5}
[1278a189-7bf2-466a-97b4-483ea39e3a26] Process 61 Thread 47375888360220

[cf61ad32-4e4c-4a9b-a8e4-c770c72ccdb9] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[cf61ad32-4e4c-4a9b-a8e4-c770c72ccdb9] Process 61 Thread 47375888359800

[e58df749-f857-41c4-aead-8bf5141472ab] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[e58df749-f857-41c4-aead-8bf5141472ab] Process 61 Thread 47375888359660

[fe665c36-a2ea-4ce5-929e-a43cf19ce6dc] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[fe665c36-a2ea-4ce5-929e-a43cf19ce6dc] Process 61 Thread 47375888359940

[72338520-7871-4209-a89f-2e8e130a824c] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[72338520-7871-4209-a89f-2e8e130a824c] Process 61 Thread 47375888360080

[1de94e32-0bed-4cec-aa26-80687be54d92] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[1de94e32-0bed-4cec-aa26-80687be54d92] Process 61 Thread 47375888360080

[bd23d3ee-6c75-44e2-b43c-e31b3c6cf31f] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[bd23d3ee-6c75-44e2-b43c-e31b3c6cf31f] Process 61 Thread 47375888360220

[2371fd9d-c8b0-4810-a5d6-442c137a62e3] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[2371fd9d-c8b0-4810-a5d6-442c137a62e3] Process 61 Thread 47375888359660

[410f61bd-ea44-4c3c-af64-fc73bdd9f6b7] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[410f61bd-ea44-4c3c-af64-fc73bdd9f6b7] Process 61 Thread 47375888359940

[de4b597b-ed37-424f-b41f-f30d88e6ba63] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[de4b597b-ed37-424f-b41f-f30d88e6ba63] Process 61 Thread 47375888360080

[eff585ef-7684-435b-8d64-41f0c7f1c90d] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[eff585ef-7684-435b-8d64-41f0c7f1c90d] Process 61 Thread 47375888359800

[356a4a91-7c16-4186-9aa8-5dcd78d3d743] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[356a4a91-7c16-4186-9aa8-5dcd78d3d743] Process 61 Thread 47375888359800

[efd7569a-6f12-4620-a42d-57eeea357d4d] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[efd7569a-6f12-4620-a42d-57eeea357d4d] Process 61 Thread 47375888360220

[07c57d3a-9bab-4dcb-80d4-67105a6f381b] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[07c57d3a-9bab-4dcb-80d4-67105a6f381b] Process 61 Thread 47375888359660

[eaf6e12b-5e1c-4974-862a-b483e40e6cec] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[eaf6e12b-5e1c-4974-862a-b483e40e6cec] Process 61 Thread 47375888359940

[762fe85f-165f-425d-937a-477f822d20b0] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[762fe85f-165f-425d-937a-477f822d20b0] Process 61 Thread 47375888359940

# This is the request that failed. connected_to was called immediately following these logs
[ab4f3ed5-9d2a-4f68-aff4-60794b11521c] {:size=>5, :connections=>1, :busy=>0, :dead=>0, :idle=>1, :waiting=>0, :checkout_timeout=>5}
[ab4f3ed5-9d2a-4f68-aff4-60794b11521c] Process 61 Thread 47375888360080

# Note that connections are gone for the next request
[eda80c15-62ff-47a5-9950-0594dad0a139] {:size=>5, :connections=>0, :busy=>0, :dead=>0, :idle=>0, :waiting=>0, :checkout_timeout=>5}
[eda80c15-62ff-47a5-9950-0594dad0a139] Process 61 Thread 47375888359800

Additional information

The symbol that current_instance.database_key returns is added to ActiveRecord::Base.configurations dynamically. The code to do that is in the database_key method itself:

  def database_key
    if ActiveRecord::Base.configurations.configs_for(env_name: database_details["int_name"]).blank?
      Rails.logger.info "Adding configuration for #{database_details["int_name"]} Process: #{Process.pid} Thread: #{Thread.current.object_id}"
      new_config = {
        database_details["int_name"] => {
          "url" => internal_connection_string,
          "adapter"=>"postgresql", 
          "encoding"=>"unicode", 
          "pool"=>5
        }
      }
      new_db_config = ActiveRecord::DatabaseConfigurations.new(new_config)
      ActiveRecord::Base.configurations = (
        ActiveRecord::Base.configurations.configurations + new_db_config.configurations
      )
    end
    # configs_for only works with a string, while connected_to only takes a symbol
    database_details["int_name"].to_sym
  end

Note the debug statement there. I can confirm that the block was only run once for the logs I provided above. I have no reason to believe this is the problem area since other requests succeed, but think it’s worth sharing since I imagine it’s unique.

System configuration

Rails version: 6.0.0.beta2

Ruby version: 2.5.3

cc @eileencodes and @bogdanvlviv - perhaps you’ve seen this in development?