Skip to content

Instantly share code, notes, and snippets.

@benoittgt
Last active March 2, 2025 17:48
Show Gist options
  • Save benoittgt/c9199eef1ab7a22f08a1e30fb0861ef2 to your computer and use it in GitHub Desktop.
Save benoittgt/c9199eef1ab7a22f08a1e30fb0861ef2 to your computer and use it in GitHub Desktop.
require "bundler/inline"
gemfile(true) do
source "https://rubygems.org"
gem "rails", "~> 7.2"
gem "pg"
end
require "active_record"
require "logger"
class ActiveRecord::ConnectionAdapters::ConnectionPool::ConnectionLeasingQueue
private
def internal_poll(timeout)
result = super
result
rescue ActiveRecord::ConnectionTimeoutError => e
puts "\n=== Connection Pool Timeout ==="
puts "\nPool size: #{ActiveRecord::Base.connection_pool.size}"
puts "Checked out connections: #{ActiveRecord::Base.connection_pool.connections.count}"
connection_owners = ActiveRecord::Base.connection_pool.connections.map(&:owner)
puts "\nThread list:"
Thread.list.each_with_index do |t, i|
connection_mark = connection_owners.include?(t) ? "[HAS CONNECTION]" : "[NO CONNECTION]"
connection_mark += "[CURRENT]" if t == Thread.current
connection_mark += "[MAIN]" if t == Thread.main
puts "---- #{connection_mark} : Thread #{i}, status: #{t.status.inspect}, thread_info: #{t.inspect.split(' ', 2)[1].chop}"
end
puts "\nCurrent thread: #{Thread.current.inspect}"
puts "\n=== End Debug Info ===\n"
raise e
end
end
# Configure a very small connection pool
ActiveRecord::Base.establish_connection(
adapter: "postgresql",
database: "playground", # create a database named "playground" in your local PostgreSQL
pool: 2,
checkout_timeout: 2
)
ActiveRecord::Base.logger = Logger.new(STDOUT)
# Create a simple table
ActiveRecord::Schema.define do
create_table :shipments, force: true do |t|
t.string :status
end
end
class Shipment < ActiveRecord::Base
end
def dangerous_threads
threads = []
# We duplicate code to report different lines in the stack trace
threads << Thread.new do
puts "Thread 1 starting..."
ActiveRecord::Base.connection.execute("select pg_sleep(5)")
end
threads << Thread.new do
puts "Thread 2 starting..."
ActiveRecord::Base.connection.execute("select pg_sleep(5)")
end
threads << Thread.new do
puts "Thread 2 starting..."
ActiveRecord::Base.connection.execute("select pg_sleep(5)")
end
threads.each(&:join)
end
puts "Connection pool size: #{ActiveRecord::Base.connection_pool.size}"
puts "Starting threads..."
dangerous_threads
@benoittgt
Copy link
Author

benoittgt commented Feb 26, 2025

ruby print_thread_pool_usage.rb                                                                                                                                                                    1 ↵
Fetching gem metadata from https://rubygems.org/...........
Resolving dependencies...
-- create_table(:shipments, {:force=>true})
D, [2025-02-26T11:52:09.001506 #9583] DEBUG -- :    (12.9ms)  DROP TABLE IF EXISTS "shipments"
D, [2025-02-26T11:52:09.054270 #9583] DEBUG -- :    (52.4ms)  CREATE TABLE "shipments" ("id" bigserial primary key, "status" character varying)
   -> 0.1101s
D, [2025-02-26T11:52:09.107704 #9583] DEBUG -- :   ActiveRecord::InternalMetadata Load (8.1ms)  SELECT * FROM "ar_internal_metadata" WHERE "ar_internal_metadata"."key" = $1 ORDER BY "ar_internal_metadata"."key" ASC LIMIT 1  [[nil, "environment"]]
Connection pool size: 2
Starting threads...
Thread 1 starting...
Thread 2 starting...
Thread 2 starting...

=== Connection Pool Timeout ===

Pool size: 2
Checked out connections: 2

Thread list:
---- [HAS CONNECTION][MAIN] : Thread 0, status: "sleep", thread_info: sleep_forever
---- [NO CONNECTION] : Thread 1, status: "sleep", thread_info: stdlib thread /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/3.3.0/rubygems/timeout/lib/timeout.rb:98 sleep
---- [NO CONNECTION] : Thread 2, status: "sleep", thread_info: Pool Reaper /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:42 sleep
---- [HAS CONNECTION] : Thread 3, status: "sleep", thread_info: print_thread_pool_usage.rb:58 sleep
---- [NO CONNECTION][CURRENT] : Thread 4, status: "run", thread_info: print_thread_pool_usage.rb:63 run
---- [NO CONNECTION] : Thread 5, status: "sleep", thread_info: print_thread_pool_usage.rb:68 sleep_forever

Current thread: #<Thread:0x0000000154fff618 print_thread_pool_usage.rb:63 run>

=== End Debug Info ===
#<Thread:0x0000000154fff618 print_thread_pool_usage.rb:63 run> terminated with exception (report_on_exception is true):
/Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:128:in `block in wait_poll': could not obtain a connection from the pool within 2.000 seconds (waited 2.005 seconds); all pooled connections were in use (ActiveRecord::ConnectionTimeoutError)
        from <internal:kernel>:187:in `loop'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:117:in `wait_poll'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:78:in `internal_poll'
        from print_thread_pool_usage.rb:14:in `internal_poll'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:73:in `block in poll'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/3.3.0/monitor.rb:201:in `synchronize'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/3.3.0/monitor.rb:201:in `mon_synchronize'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:82:in `synchronize'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:73:in `poll'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:868:in `acquire_connection'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:564:in `checkout'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:313:in `lease_connection'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_handling.rb:277:in `connection'
        from print_thread_pool_usage.rb:65:in `block in dangerous_threads'

=== Connection Pool Timeout ===

Pool size: 2
Checked out connections: 2

Thread list:
---- [HAS CONNECTION][MAIN] : Thread 0, status: "sleep", thread_info: sleep_forever
---- [NO CONNECTION] : Thread 1, status: "sleep", thread_info: stdlib thread /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/3.3.0/rubygems/timeout/lib/timeout.rb:98 sleep
---- [NO CONNECTION] : Thread 2, status: "sleep", thread_info: Pool Reaper /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/reaper.rb:42 sleep
---- [HAS CONNECTION] : Thread 3, status: "sleep", thread_info: print_thread_pool_usage.rb:58 sleep
---- [NO CONNECTION][CURRENT] : Thread 4, status: "run", thread_info: print_thread_pool_usage.rb:68 run

Current thread: #<Thread:0x0000000154fff4d8 print_thread_pool_usage.rb:68 run>

=== End Debug Info ===
#<Thread:0x0000000154fff4d8 print_thread_pool_usage.rb:68 run> terminated with exception (report_on_exception is true):
/Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:128:in `block in wait_poll': could not obtain a connection from the pool within 2.000 seconds (waited 2.006 seconds); all pooled connections were in use (ActiveRecord::ConnectionTimeoutError)
        from <internal:kernel>:187:in `loop'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:117:in `wait_poll'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:78:in `internal_poll'
        from print_thread_pool_usage.rb:14:in `internal_poll'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:73:in `block in poll'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/3.3.0/monitor.rb:201:in `synchronize'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/3.3.0/monitor.rb:201:in `mon_synchronize'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:82:in `synchronize'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:73:in `poll'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:868:in `acquire_connection'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:564:in `checkout'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:313:in `lease_connection'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_handling.rb:277:in `connection'
        from print_thread_pool_usage.rb:70:in `block in dangerous_threads'
D, [2025-02-26T11:52:14.127777 #9583] DEBUG -- :    (5012.0ms)  select pg_sleep(5)
/Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:128:in `block in wait_poll': could not obtain a connection from the pool within 2.000 seconds (waited 2.005 seconds); all pooled connections were in use (ActiveRecord::ConnectionTimeoutError)
        from <internal:kernel>:187:in `loop'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:117:in `wait_poll'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:78:in `internal_poll'
        from print_thread_pool_usage.rb:14:in `internal_poll'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:73:in `block in poll'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/3.3.0/monitor.rb:201:in `synchronize'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/3.3.0/monitor.rb:201:in `mon_synchronize'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:82:in `synchronize'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool/queue.rb:73:in `poll'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:868:in `acquire_connection'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:564:in `checkout'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_adapters/abstract/connection_pool.rb:313:in `lease_connection'
        from /Users/benoit.tigeot/.rbenv/versions/3.3.0/lib/ruby/gems/3.3.0/gems/activerecord-7.2.2.1/lib/active_record/connection_handling.rb:277:in `connection'
        from print_thread_pool_usage.rb:65:in `block in dangerous_threads'

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment