ActiveRecord::ConnectionTimeoutError: could not obtain a database connection within 5.000 seconds (waited 5.000 seconds)

mysql ruby-on-rails nginx puma airbrake
Catfish picture Catfish · Jan 6, 2015 · Viewed 23.4k times · Source

I have a rails app in production that i deployed some changes to the other day. All of a sudden now I get the error ActiveRecord::ConnectionTimeoutError: could not obtain a database connection within 5.000 seconds (waited 5.000 seconds) multiple times a day and have to restart puma to fix the issue.

I'm completely stumped as to what is causing this. I didn't change anything on my server and the changes I made were pretty simple (add to a view and add to a controller method).

I'm not seeing much of anything in the log files.

I'm using rails 4.1.4 and ruby 2.0.0p481

Any ideas as to why my connections are filling up? My connection pool is set to 10 and i'm using the default puma configuration.

Here's a stack trace:

ActiveRecord::ConnectionTimeoutError (could not obtain a database connection within 5.000 seconds (waited 5.000 seconds)):
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:190:in `block in wait_poll'
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:181:in `loop'
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:181:in `wait_poll'
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:136:in `block in poll'
  /usr/local/rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/monitor.rb:211:in `mon_synchronize'
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:146:in `synchronize'
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:134:in `poll'
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:418:in `acquire_connection'
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:351:in `block in checkout'
  /usr/local/rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/monitor.rb:211:in `mon_synchronize'
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:350:in `checkout'
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:265:in `block in connection'
  /usr/local/rvm/rubies/ruby-2.0.0-p481/lib/ruby/2.0.0/monitor.rb:211:in `mon_synchronize'
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:264:in `connection'
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:541:in `retrieve_connection'
  activerecord (4.1.4) lib/active_record/connection_handling.rb:113:in `retrieve_connection'
  activerecord (4.1.4) lib/active_record/connection_handling.rb:87:in `connection'
  activerecord (4.1.4) lib/active_record/query_cache.rb:51:in `restore_query_cache_settings'
  activerecord (4.1.4) lib/active_record/query_cache.rb:43:in `rescue in call'
  activerecord (4.1.4) lib/active_record/query_cache.rb:32:in `call'
  activerecord (4.1.4) lib/active_record/connection_adapters/abstract/connection_pool.rb:621:in `call'
  actionpack (4.1.4) lib/action_dispatch/middleware/callbacks.rb:29:in `block in call'
  activesupport (4.1.4) lib/active_support/callbacks.rb:82:in `run_callbacks'
  actionpack (4.1.4) lib/action_dispatch/middleware/callbacks.rb:27:in `call'
  actionpack (4.1.4) lib/action_dispatch/middleware/remote_ip.rb:76:in `call'
  airbrake (4.1.0) lib/airbrake/rails/middleware.rb:13:in `call'
  actionpack (4.1.4) lib/action_dispatch/middleware/debug_exceptions.rb:17:in `call'
  actionpack (4.1.4) lib/action_dispatch/middleware/show_exceptions.rb:30:in `call'
  railties (4.1.4) lib/rails/rack/logger.rb:38:in `call_app'
  railties (4.1.4) lib/rails/rack/logger.rb:20:in `block in call'
  activesupport (4.1.4) lib/active_support/tagged_logging.rb:68:in `block in tagged'
  activesupport (4.1.4) lib/active_support/tagged_logging.rb:26:in `tagged'
  activesupport (4.1.4) lib/active_support/tagged_logging.rb:68:in `tagged'
  railties (4.1.4) lib/rails/rack/logger.rb:20:in `call'
  actionpack (4.1.4) lib/action_dispatch/middleware/request_id.rb:21:in `call'
  rack (1.5.2) lib/rack/methodoverride.rb:21:in `call'
  dragonfly (1.0.5) lib/dragonfly/cookie_monster.rb:9:in `call'
  rack (1.5.2) lib/rack/runtime.rb:17:in `call'
  activesupport (4.1.4) lib/active_support/cache/strategy/local_cache_middleware.rb:26:in `call'
  rack (1.5.2) lib/rack/sendfile.rb:112:in `call'
  airbrake (4.1.0) lib/airbrake/user_informer.rb:16:in `_call'
  airbrake (4.1.0) lib/airbrake/user_informer.rb:12:in `call'
  railties (4.1.4) lib/rails/engine.rb:514:in `call'
  railties (4.1.4) lib/rails/application.rb:144:in `call'
  railties (4.1.4) lib/rails/railtie.rb:194:in `public_send'
  railties (4.1.4) lib/rails/railtie.rb:194:in `method_missing'
  puma (2.9.0) lib/puma/configuration.rb:71:in `call'
  puma (2.9.0) lib/puma/server.rb:490:in `handle_request'
  puma (2.9.0) lib/puma/server.rb:361:in `process_client'
  puma (2.9.0) lib/puma/server.rb:254:in `block in run'
  puma (2.9.0) lib/puma/thread_pool.rb:92:in `call'
  puma (2.9.0) lib/puma/thread_pool.rb:92:in `block in spawn_thread'

Puma init.d script

#!/bin/sh
# Starts and stops puma
#


case "$1" in
        start)
                su myuser -c  "source /etc/profile && cd /var/www/myapp/current && rvm gemset use myapp && puma -d -e production -b unix:///var/www/myapp/myapp_app.sock -S /var/www/myapp/myapp_app.state"
        ;;

        stop)
                su myuser -c "source /etc/profile && cd /var/www/myapp/current &&  rvm gemset use myapp && RAILS_ENV=production bundle exec pumactl -S /var/www/myapp/myapp_app.state stop"
        ;;

        restart)
                $0 stop
                $0 start
        ;;

        *)
                echo "Usage: $0 {start|stop|restart}"
                exit 1
esac

EDIT

I think i've finally narrowed down the issue to be with the airbrake gem and using the devise method current_user or user_signed_in? in application_controller.rb in a before_action.

Here's my application controller:

class ApplicationController < ActionController::Base
  protect_from_forgery
  before_filter :authenticate_user!, :get_new_messages 

  # Gets the unread messages for the logged in user
  def get_new_messages
    @num_new_messages = 0 # Initially set to 0 so login page, etc works
    # If the user is signed in, fetch the new messages
    if user_signed_in? # I also tried !current_user.nil?
      @num_new_messages = Message.where(:created_for => current_user.id).where(:viewed => false).count
    end
  end

...
end

If i remove the if block, i have no problems. Since i introduced that code, my app seems to run out of connections. If i leave that if block in place and remove the airbrake gem, my app seems to run just fine with only the default 5 connections set on my pool in my database.yml file.

EDIT

I finally figure out that if I comment out this line in my config/environments/production.rb file config.exceptions_app = self.routes that I don't get the error. It seems that custom routes + devise in the app controller before_action are the cause. I've created an issue and a reproducable project on github.

https://github.com/plataformatec/devise/issues/3422 https://github.com/toymachiner62/devise-connection-failure/blob/master/config/environments/production.rb#L84

Answer

Railsana picture Railsana · Jan 14, 2015

I had the same problems which were caused by too many open connections to the database. This can happen when you have database queries outside of a controller (in a model, mailer, pdf generator, ...).

I could fix it by wrapping those queries in this block which closes the connection automatically.

ActiveRecord::Base.connection_pool.with_connection do
  # your code
end

Since Puma works multi-threaded, the pool size (as eabraham mentioned) can be a limitation, too. Try to increase it (a little)...

I hope this helps!

Related questions

Error installing mysql2: Failed to build gem native extension

I am having some problems when trying to install mysql2 gem for Rails. When I try to install it by running bundle install or gem install mysql2 it gives me the following error: Error installing mysql2: ERROR: Failed to build …

Read More
Change a column type from Date to DateTime during ROR migration

I need to change my column type from date to datetime for an app I am making. I don't care about the data as its still being developed. How can I do this?

Read More
Create a new Ruby on Rails application using MySQL instead of SQLite

I want to create my Rails application with MySQL, because I like it so much. How can I do that in the latest version of Rails instead of the default SQLite?

Read More