ActiveRecord :: ConnectionTimeoutError: impossibile ottenere una connessione al database entro 5.000 secondi (atteso 5.000 secondi)

Question

Ho un'app rails in produzione che ho distribuito alcune modifiche all'altro giorno. Tutto ad un tratto ora ottengo l'errore ActiveRecord::ConnectionTimeoutError: could not obtain a database connection within 5.000 seconds (waited 5.000 seconds) più volte al giorno e devo riavviare puma per risolvere il problema.

Sono completamente perplesso su ciò che sta causando questo. Non ho modificato nulla sul mio server e le modifiche apportate sono state piuttosto semplici (aggiungi a una vista e aggiungi a un metodo controller).

Non vedo molto di nulla nei file di registro.

sto usando le rotaie 4.1.4 e rubino 2.0.0p481

Tutte le idee sul motivo per cui i miei collegamenti stanno riempiendo? Il mio pool di connessioni è impostato su 10 e sto utilizzando la configurazione puma predefinita.

Ecco una traccia dello stack:

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

#!/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

Penso di aver finalmente ristretto il problema di essere con il airbrake gem e utilizzando il metodo devisecurrent_user oppure user_signed_in? in application_controller.rb in un before_action.

Ecco il mio controller di applicazione:

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 

se rimuovere il blocco if, non ho problemi. Da quando ho introdotto quel codice, la mia app sembra non funzionare più. Se lascio il blocco if sul posto e rimuovo la gemma Airbrake, la mia app sembra funzionare correttamente con solo le 5 connessioni predefinite impostate sul mio pool nel mio file database.yml.

EDIT

ho finalmente capire che se io commento di questa linea nella mia config/environments/production.rb lima config.exceptions_app = self.routes che non ottengo l'errore. Sembra che le rotte personalizzate + escogitare nell'app controller prima_action siano la causa. Ho creato un problema e un progetto riproducibile su github.

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

Answer 1

Con l'aiuto dei ragazzi del progetto "Penso di aver finalmente capito questo problema. Sembrava che utilizzando le pagine di errore personalizzate con il proprio controller, non stavo saltando il before_action get_new_messages. Quindi la soluzione molto semplice è stata aggiungere:

skip_before_filter :get_new_messages 

al mio errore personalizzato controller.

Questo problema spiega in dettaglio il motivo alla base di questo: https://github.com/plataformatec/devise/issues/3422

Answer 2

ho avuto gli stessi problemi che sono stati causati da troppe connessioni aperte anche il database. Questo può accadere quando si hanno query di database al di fuori di un controller (in un modello, un mailer, un generatore di pdf, ...).

È possibile risolvere il problema racchiudendo le query in questo blocco che chiude automaticamente la connessione.

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

Dal momento che Puma funziona con il multithreading, anche la dimensione del pool (come indicato da eabraham) può essere un limite. Prova ad aumentarlo (un po ') ...

Spero che questo aiuti!

Answer 3

In definitiva questo problema ancora mi afflitto per un altro anno o giù di lì. Finalmente ho trovato una buona soluzione lavorando con i ragazzi puma.

Aggiorna il tuo puma almeno al 2.15.x.