influitive / apartment-sidekiq

Sidekiq support for the Apartment Gem
MIT License
126 stars 54 forks source link

Rails 5: ActiveRecord::ConnectionNotEstablished: No connection pool with 'primary' found. #30

Open AkshayGoyal022 opened 4 years ago

AkshayGoyal022 commented 4 years ago

We have 2 servers: master and a slave server. slave server is primarily being used to handle reports. All the long background running processes are pushed to the slave server. We are using sidekiq for background processing.

Now, whenever a report is ready we create a Download object in which the generated report is attached. As the process is running in slave we need to connect to master in order to create Download object. Code looks something like this:

def perform(tenant_name)
  Apartment::Tenant.switch(tenant_name) do
    # data processing code here....
    connection = MasterDbConnectionService.connect(tenant_name)
    Download.create!(time_taken: time_taken, file: file) # Pseudo code
    # Disconnect from the previously established connection
    MasterDbConnectionService.disconnect(connection)
  end
end

But we are intermittently facing the error especially for long running jobs most probably because of sidekiq retrying that job.

ActiveRecord::ConnectionNotEstablished) "No connection pool with 'primary' found.

MasterDbConnectionService code:

def connect(tenant_name)
  ActiveRecord::Base.establish_connection(master_config.merge(schema_search_path: "'#{tenant_name}',public,shared_extensions"))
end

Config: Nginx, Phusion Passenger, Postgres, ruby-2.3.1, rails 5.1.3

Full stack trace:

/home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activerecord-5.1.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:930:in `retrieve_connection'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activerecord-5.1.3/lib/active_record/connection_handling.rb:116:in `retrieve_connection'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activerecord-5.1.3/lib/active_record/connection_handling.rb:88:in `connection'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/apartment-2.1.0/lib/apartment/adapters/postgresql_adapter.rb:40:in `reset'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/apartment-2.1.0/lib/apartment/adapters/abstract_adapter.rb:88:in `rescue in ensure in switch'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/apartment-2.1.0/lib/apartment/adapters/abstract_adapter.rb:88:in `ensure in switch'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/apartment-2.1.0/lib/apartment/adapters/abstract_adapter.rb:88:in `switch'
  /home/deployer/workspace/rails/dms_webapp/app/jobs/report_download_job.rb:12:in `perform'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/execution.rb:37:in `block in perform_now'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/callbacks.rb:108:in `block in run_callbacks'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/i18n-0.9.5/lib/i18n.rb:268:in `with_locale'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/translation.rb:7:in `block (2 levels) in <module:Translation>'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/callbacks.rb:117:in `instance_exec'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/logging.rb:24:in `block (4 levels) in <module:Logging>'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/notifications.rb:166:in `block in instrument'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/notifications.rb:166:in `instrument'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/logging.rb:23:in `block (3 levels) in <module:Logging>'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/logging.rb:44:in `block in tag_logger'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/tagged_logging.rb:69:in `block in tagged'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/tagged_logging.rb:26:in `tagged'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/tagged_logging.rb:69:in `tagged'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/logging.rb:44:in `tag_logger'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/logging.rb:20:in `block (2 levels) in <module:Logging>'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/callbacks.rb:117:in `instance_exec'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/callbacks.rb:135:in `run_callbacks'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/execution.rb:33:in `perform_now'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/execution.rb:22:in `block in execute'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/callbacks.rb:108:in `block in run_callbacks'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/railtie.rb:26:in `block (4 levels) in <class:Railtie>'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/execution_wrapper.rb:85:in `wrap'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/reloader.rb:68:in `block in wrap'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/execution_wrapper.rb:81:in `wrap'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/reloader.rb:67:in `wrap'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/railtie.rb:25:in `block (3 levels) in <class:Railtie>'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/callbacks.rb:117:in `instance_exec'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/callbacks.rb:117:in `block in run_callbacks'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/callbacks.rb:135:in `run_callbacks'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/execution.rb:20:in `execute'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activejob-5.1.3/lib/active_job/queue_adapters/sidekiq_adapter.rb:40:in `perform'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:199:in `execute_job'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:170:in `block (2 levels) in process'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/middleware/chain.rb:128:in `block in invoke'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/middleware/chain.rb:133:in `invoke'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:169:in `block in process'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:141:in `block (6 levels) in dispatch'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/job_retry.rb:97:in `local'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:140:in `block (5 levels) in dispatch'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/rails.rb:42:in `block in call'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/execution_wrapper.rb:85:in `wrap'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/reloader.rb:68:in `block in wrap'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/execution_wrapper.rb:85:in `wrap'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/activesupport-5.1.3/lib/active_support/reloader.rb:67:in `wrap'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/rails.rb:41:in `call'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:136:in `block (4 levels) in dispatch'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:215:in `stats'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:131:in `block (3 levels) in dispatch'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/job_logger.rb:7:in `call'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:130:in `block (2 levels) in dispatch'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/job_retry.rb:72:in `global'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:129:in `block in dispatch'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/logging.rb:44:in `with_context'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/logging.rb:38:in `with_job_hash_context'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:128:in `dispatch'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:168:in `process'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:85:in `process_one'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/processor.rb:73:in `run'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/util.rb:16:in `watchdog'
  /home/deployer/.rvm/gems/ruby-2.3.1@rails513/gems/sidekiq-5.0.4/lib/sidekiq/util.rb:25:in `block in safe_thread'
cgratigny commented 4 years ago

@AkshayGoyal022 I ended up needing to follow the guidance here - https://fuzzyblog.io/blog/rails/2017/08/21/rails-apartment-tenancy-and-sidekiq.html

As the apartment-sidekiq gem hasn't been reliable for my setup. I have a database for each tenant, and as apartment isn't threadsafe, I had the same error you are experiencing.

krtschmr commented 3 years ago

@cgratigny can you please explain your thread safety issues?

i joined a codebase with heavy use of the apartment gem (almost everything in own schemas) and when sidekiq runs jobs, sometimes emails are sent from another clients domain and contain links to another clients url. this is obviously a threadsafe issue and my only solution is to destroy all software. i'm constantly pushing to revert the schema madness and do one shared database but i got pushed back a lot, so that ship has sailed i guess.

fernandomm commented 3 years ago

@krtschmr One "solution" is to run multiple sidekiq processes and use "-c 1" option.

You will loose the benefits of threads since each process will be using only one thread, but you should no longer experience these problems caused by Apartment + threads issues.

Depending on the type of job that you're running, the performance impact is low/none. In some cases you can achieve better results since you would be using multiple CPU cores ( https://medium.com/@zunaidahmed/sidekiq-and-scaling-dd6f1969b68e ).

krtschmr commented 3 years ago

Yes, it makes sense to have concurrency=1 to avoid a threading issue. we run 2 workers each 27 threads, so that 1 solution won't be possible right now. We also had class variables for the ClientSettings, so this might also cause an issue, i refactored this to instance variables now and hope no more wrong urls are included in emails. if it's still the case, i guess i need to destroy all software and restart.