Job exception: timeout expired

ّI have so many of these errors in my log. I don’t know what’s exactly the problem.

/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/pg-0.21.0/lib/pg.rb:56:in `initialize'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/pg-0.21.0/lib/pg.rb:56:in `new'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/pg-0.21.0/lib/pg.rb:56:in `connect'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/postgresql_adapter.rb:684:in `connect'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/postgresql_adapter.rb:215:in `initialize'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/postgresql_adapter.rb:40:in `new'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/postgresql_adapter.rb:40:in `postgresql_connection'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:809:in `new_connection'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:853:in `checkout_new_connection'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:832:in `try_to_checkout_new_connection'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:793:in `acquire_connection'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:521:in `checkout'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:380:in `connection'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:1008:in `retrieve_connection'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_handling.rb:118:in `retrieve_connection'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/connection_handling.rb:90:in `connection'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/relation/delegation.rb:46:in `connection'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/relation.rb:525:in `alias_tracker'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/associations/association_scope.rb:26:in `scope'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/associations/association_scope.rb:7:in `scope'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/associations/association.rb:91:in `association_scope'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/associations/association.rb:80:in `scope'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/associations/collection_association.rb:288:in `scope'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/associations/collection_proxy.rb:960:in `scope'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/associations/collection_proxy.rb:1130:in `where'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/activerecord-5.2.0/lib/active_record/relation/finder_methods.rb:81:in `find_by'
/var/www/discourse/app/models/user.rb:558:in `visit_record_for'
/var/www/discourse/app/models/user.rb:562:in `update_visit_record!'
/var/www/discourse/app/models/user.rb:1230:in `update_previous_visit'
/var/www/discourse/app/models/user.rb:600:in `update_last_seen!'
/var/www/discourse/lib/auth/default_current_user_provider.rb:81:in `block in current_user'
/var/www/discourse/lib/scheduler/defer.rb:70:in `block in do_work'
/var/www/discourse/vendor/bundle/ruby/2.4.0/gems/rails_multisite-2.0.4/lib/rails_multisite/connection_management.rb:63:in `with_connection'
/var/www/discourse/lib/scheduler/defer.rb:68:in `do_work'
/var/www/discourse/lib/scheduler/defer.rb:59:in `block (2 levels) in start_thread'

Can you please try a rebuild?

cd /var/discourse
./launcher rebuild app
3 Likes

rebuild didnt fix the problem.

this is also another error that frequently is reported:

/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/pg-1.0.0/lib/pg.rb:56:in `initialize'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/pg-1.0.0/lib/pg.rb:56:in `new'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/pg-1.0.0/lib/pg.rb:56:in `connect'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/postgresql_adapter.rb:684:in `connect'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/postgresql_adapter.rb:215:in `initialize'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/postgresql_adapter.rb:40:in `new'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/postgresql_adapter.rb:40:in `postgresql_connection'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:809:in `new_connection'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:853:in `checkout_new_connection'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:832:in `try_to_checkout_new_connection'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:793:in `acquire_connection'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:521:in `checkout'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:380:in `connection'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_adapters/abstract/connection_pool.rb:1008:in `retrieve_connection'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_handling.rb:118:in `retrieve_connection'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/connection_handling.rb:90:in `connection'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/activerecord-5.2.0/lib/active_record/transactions.rb:212:in `transaction'
/var/www/discourse/app/models/topic_view_item.rb:22:in `add'
/var/www/discourse/app/controllers/topics_controller.rb:746:in `block in track_visit_to_topic'
/var/www/discourse/lib/scheduler/defer.rb:70:in `block in do_work'
/var/www/discourse/vendor/bundle/ruby/2.5.0/gems/rails_multisite-2.0.5/lib/rails_multisite/connection_management.rb:63:in `with_connection'
/var/www/discourse/lib/scheduler/defer.rb:68:in `do_work'
/var/www/discourse/lib/scheduler/defer.rb:59:in `block (2 levels) in start_thread'


Hi, sorry for the necro-bump… but I see the same error related to background jobs:

/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/pg-1.1.4/lib/pg.rb:56:in `initialize'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/pg-1.1.4/lib/pg.rb:56:in `new'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/pg-1.1.4/lib/pg.rb:56:in `connect'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:692:in `connect'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:223:in `initialize'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:48:in `new'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/postgresql_adapter.rb:48:in `postgresql_connection'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:811:in `new_connection'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:855:in `checkout_new_connection'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:834:in `try_to_checkout_new_connection'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:795:in `acquire_connection'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:523:in `checkout'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:382:in `connection'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_adapters/abstract/connection_pool.rb:1014:in `retrieve_connection'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_handling.rb:118:in `retrieve_connection'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/connection_handling.rb:90:in `connection'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/model_schema.rb:466:in `load_schema!'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/attributes.rb:234:in `load_schema!'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/attribute_decorators.rb:51:in `load_schema!'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/model_schema.rb:459:in `block in load_schema'
/usr/local/lib/ruby/2.6.0/monitor.rb:230:in `mon_synchronize'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/model_schema.rb:456:in `load_schema'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/model_schema.rb:346:in `attribute_types'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/attribute_methods.rb:230:in `has_attribute?'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/inheritance.rb:55:in `new'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/activerecord-5.2.3/lib/active_record/persistence.rb:52:in `create!'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/mini_scheduler-0.9.2/lib/mini_scheduler/manager.rb:73:in `process_queue'
/var/www/discourse/vendor/bundle/ruby/2.6.0/gems/mini_scheduler-0.9.2/lib/mini_scheduler/manager.rb:30:in `block in initialize'

I tried to rebuild the app several times with no luck. Any hint? Thanks!

EDIT: what I noticed is that there was a backup pg_dump stuck since days ago, I restarted the app, it went away but Sidekiq still seems not working.

EDIT2: I started the backup manually and I see pg stuck at the following query COPY public.email_logs (id, to_address, email_type, user_id, created_at, updated_at, post_id, bounce_key, bounced, message_id) TO stdout;. It can stay there for ever… probably that’s why Sidekiq cannot connect to the DB again and fails to retrieve new jobs…

More insights… it seems that Postgresql gets stuck even updating the post index:

query | UPDATE post_search_data                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                        +
      | SET                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                +
      |    raw_data = 'La copia de seguridad se completo exitosamente The backup was successful. Visit the //community.coopdevs.org/admin/backups community coopdevs org admin backups admin > backup section to download your new backup. Here
<E2><80><99>s the log: [2016-09-30 03:39:37] [STARTED] [2016-09-30 03:39:37] ''system'' has started the backup! [2016-09-30 03:39:37] Marking backup as running... [2016-09-30 03:39:37] Making sure ''/var/www/discourse/tmp/backups/default/2016-09-30-033937'' exists... [2016-09-30 03:39:37] Making sure ''/var/www/discour:

The fun fact is that I deleted the topic with that information and restarted the app (that triggers an index re-build) and it gets stuck again at UPDATE… for another topic related to backup… different date but similar content.

It seems that those topics contains something that the same Postgresql doesn’t like to parse again… :face_with_head_bandage: