[API] Database timeout error when deleting topics in bulk

dev
1

I’m trying to delete 8 topics with the API but I get the following error after 4 of them have been deleted:

W20170727-16:21:10.014(2)? (STDERR) Request: [DELETE http://forum.docuss.org/t/6
75.json ]
W20170727-16:21:10.018(2)? (STDERR) Response: status=500 content=ActiveRecord::C
onnectionTimeoutError at /t/675.json
W20170727-16:21:10.023(2)? (STDERR) ============================================
=======
W20170727-16:21:10.027(2)? (STDERR)
W20170727-16:21:10.029(2)? (STDERR) > could not obtain a database connection wit
hin 5.000 seconds (waited 5.000 seconds)
W20170727-16:21:10.033(2)? (STDERR)
W20170727-16:21:10.037(2)? (STDERR) config/initializers/100-quiet_logger.rb, lin
e 17
W20170727-16:21:10.040(2)? (STDERR) --------------------------------------------
----
W20170727-16:21:10.044(2)? (STDERR)
W20170727-16:21:10.047(2)? (STDERR) ``` ruby
W20170727-16:21:10.050(2)? (STDERR)    12           override = true
W20170727-16:21:10.053(2)? (STDERR)    13           Rails.logger.override_level
= Logger::ERROR
W20170727-16:21:10.056(2)? (STDERR)    14         end
W20170727-16:21:10.059(2)? (STDERR)    15       end
W20170727-16:21:10.062(2)? (STDERR)    16
W20170727-16:21:10.064(2)? (STDERR) >  17       call_without_quiet_assets(env).t
ap do
W20170727-16:21:10.068(2)? (STDERR)    18         if override
W20170727-16:21:10.070(2)? (STDERR)    19           Rails.logger.override_level
= nil
W20170727-16:21:10.074(2)? (STDERR)    20         end
W20170727-16:21:10.076(2)? (STDERR)    21       end
W20170727-16:21:10.079(2)? (STDERR)    22     end
W20170727-16:21:10.082(2)? (STDERR) ```
W20170727-16:21:10.085(2)? (STDERR)
W20170727-16:21:10.088(2)? (STDERR) App backtrace
W20170727-16:21:10.091(2)? (STDERR) -------------
W20170727-16:21:10.094(2)? (STDERR)
W20170727-16:21:10.097(2)? (STDERR)  - config/initializers/100-quiet_logger.rb:1
7:in `call_with_quiet_assets'
W20170727-16:21:10.101(2)? (STDERR)  - config/initializers/100-silence_logger.rb
:29:in `call'
W20170727-16:21:10.105(2)? (STDERR)  - lib/middleware/missing_avatars.rb:21:in `
call'
W20170727-16:21:10.109(2)? (STDERR)  - lib/middleware/turbo_dev.rb:34:in `call'
W20170727-16:21:10.112(2)? (STDERR)
W20170727-16:21:10.115(2)? (STDERR) Full backtrace
W20170727-16:21:10.119(2)? (STDERR) --------------
W20170727-16:21:10.122(2)? (STDERR)
W20170727-16:21:10.126(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_adapters/abstract/connection_pool.rb:189:in `block in wait_poll'
W20170727-16:21:10.130(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_adapters/abstract/connection_pool.rb:180:in `wait_poll'
W20170727-16:21:10.134(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_adapters/abstract/connection_pool.rb:135:in `block in poll'
W20170727-16:21:10.137(2)? (STDERR)  - /home/sylvain/.rbenv/versions/2.3.0/lib/r
uby/2.3.0/monitor.rb:214:in `mon_synchronize'
W20170727-16:21:10.142(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_adapters/abstract/connection_pool.rb:145:in `synchronize'
W20170727-16:21:10.145(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_adapters/abstract/connection_pool.rb:133:in `poll'
W20170727-16:21:10.149(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_adapters/abstract/connection_pool.rb:425:in `acquire_connection'
W20170727-16:21:10.153(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_adapters/abstract/connection_pool.rb:349:in `block in checkout'
W20170727-16:21:10.157(2)? (STDERR)  - /home/sylvain/.rbenv/versions/2.3.0/lib/r
uby/2.3.0/monitor.rb:214:in `mon_synchronize'
W20170727-16:21:10.161(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_adapters/abstract/connection_pool.rb:348:in `checkout'
W20170727-16:21:10.164(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_adapters/abstract/connection_pool.rb:263:in `block in connection'
W20170727-16:21:10.168(2)? (STDERR)  - /home/sylvain/.rbenv/versions/2.3.0/lib/r
uby/2.3.0/monitor.rb:214:in `mon_synchronize'
W20170727-16:21:10.172(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_adapters/abstract/connection_pool.rb:262:in `connection'
W20170727-16:21:10.176(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_adapters/abstract/connection_pool.rb:571:in `retrieve_connection'
W20170727-16:21:10.179(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_handling.rb:113:in `retrieve_connection'
W20170727-16:21:10.183(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/co
nnection_handling.rb:87:in `connection'
W20170727-16:21:10.187(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/mi
gration.rb:383:in `connection'
W20170727-16:21:10.191(2)? (STDERR)  - activerecord (4.2.8) lib/active_record/mi
gration.rb:370:in `call'
W20170727-16:21:10.195(2)? (STDERR)  - actionpack (4.2.8) lib/action_dispatch/mi
ddleware/callbacks.rb:29:in `block in call'
W20170727-16:21:10.199(2)? (STDERR)  - activesupport (4.2.8) lib/active_support/
callbacks.rb:88:in `__run_callbacks__'
W20170727-16:21:10.202(2)? (STDERR)  - activesupport (4.2.8) lib/active_support/
callbacks.rb:778:in `_run_call_callbacks'
W20170727-16:21:10.206(2)? (STDERR)  - activesupport (4.2.8) lib/active_support/
callbacks.rb:81:in `run_callbacks'
W20170727-16:21:10.210(2)? (STDERR)  - actionpack (4.2.8) lib/action_dispatch/mi
ddleware/callbacks.rb:27:in `call'
W20170727-16:21:10.216(2)? (STDERR)  - actionpack (4.2.8) lib/action_dispatch/mi
ddleware/reloader.rb:73:in `call'
W20170727-16:21:10.220(2)? (STDERR)  - actionpack (4.2.8) lib/action_dispatch/mi
ddleware/remote_ip.rb:78:in `call'
W20170727-16:21:10.225(2)? (STDERR)  - better_errors (2.1.1) lib/better_errors/m
iddleware.rb:84:in `protected_app_call'
W20170727-16:21:10.229(2)? (STDERR)  - better_errors (2.1.1) lib/better_errors/m
iddleware.rb:79:in `better_errors_call'
W20170727-16:21:10.234(2)? (STDERR)  - better_errors (2.1.1) lib/better_errors/m
iddleware.rb:57:in `call'
W20170727-16:21:10.237(2)? (STDERR)  - actionpack (4.2.8) lib/action_dispatch/mi
ddleware/debug_exceptions.rb:17:in `call'
W20170727-16:21:10.242(2)? (STDERR)  - actionpack (4.2.8) lib/action_dispatch/mi
ddleware/show_exceptions.rb:30:in `call'
W20170727-16:21:10.247(2)? (STDERR)  - logster (1.2.7) lib/logster/middleware/re
porter.rb:31:in `call'
W20170727-16:21:10.251(2)? (STDERR)  - railties (4.2.8) lib/rails/rack/logger.rb
:38:in `call_app'
W20170727-16:21:10.254(2)? (STDERR)  - railties (4.2.8) lib/rails/rack/logger.rb
:22:in `call'
W20170727-16:21:10.258(2)? (STDERR)  - config/initializers/100-quiet_logger.rb:1
7:in `call_with_quiet_assets'
W20170727-16:21:10.262(2)? (STDERR)  - config/initializers/100-silence_logger.rb
:29:in `call'
W20170727-16:21:10.266(2)? (STDERR)  - actionpack (4.2.8) lib/action_dispatch/mi
ddleware/request_id.rb:21:in `call'
W20170727-16:21:10.269(2)? (STDERR)  - rack (1.6.8) lib/rack/methodoverride.rb:2
2:in `call'
W20170727-16:21:10.273(2)? (STDERR)  - rack (1.6.8) lib/rack/runtime.rb:18:in `c
all'
W20170727-16:21:10.277(2)? (STDERR)  - actionpack (4.2.8) lib/action_dispatch/mi
ddleware/static.rb:120:in `call'
W20170727-16:21:10.280(2)? (STDERR)  - actionpack (4.2.8) lib/action_dispatch/mi
ddleware/static.rb:120:in `call'
W20170727-16:21:10.284(2)? (STDERR)  - rack (1.6.8) lib/rack/sendfile.rb:113:in
`call'
W20170727-16:21:10.288(2)? (STDERR)  - lib/middleware/missing_avatars.rb:21:in `
call'
W20170727-16:21:10.291(2)? (STDERR)  - lib/middleware/turbo_dev.rb:34:in `call'
W20170727-16:21:10.294(2)? (STDERR)  - rack-mini-profiler (0.10.5) lib/mini_prof
iler/profiler.rb:282:in `call'
W20170727-16:21:10.299(2)? (STDERR)  - message_bus (2.0.2) lib/message_bus/rack/
middleware.rb:62:in `call'
W20170727-16:21:10.302(2)? (STDERR)  - railties (4.2.8) lib/rails/engine.rb:518:
in `call'
W20170727-16:21:10.306(2)? (STDERR)  - railties (4.2.8) lib/rails/application.rb
:165:in `call'
W20170727-16:21:10.310(2)? (STDERR)  - railties (4.2.8) lib/rails/railtie.rb:194
:in `method_missing'
W20170727-16:21:10.314(2)? (STDERR)  - rack (1.6.8) lib/rack/urlmap.rb:66:in `bl
ock in call'
W20170727-16:21:10.317(2)? (STDERR)  - rack (1.6.8) lib/rack/urlmap.rb:50:in `ca
ll'
W20170727-16:21:10.321(2)? (STDERR)  - rack (1.6.8) lib/rack/content_length.rb:1
5:in `call'
W20170727-16:21:10.324(2)? (STDERR)  - puma (3.9.1) lib/puma/configuration.rb:22
4:in `call'
W20170727-16:21:10.328(2)? (STDERR)  - puma (3.9.1) lib/puma/server.rb:602:in `h
andle_request'
W20170727-16:21:10.332(2)? (STDERR)  - puma (3.9.1) lib/puma/server.rb:435:in `p
rocess_client'
W20170727-16:21:10.336(2)? (STDERR)  - puma (3.9.1) lib/puma/server.rb:299:in `b
lock in run'
W20170727-16:21:10.339(2)? (STDERR)  - puma (3.9.1) lib/puma/thread_pool.rb:120:
in `block in spawn_thread'
W20170727-16:21:10.343(2)? (STDERR)
W20170727-16:21:10.346(2)? (STDERR)
W20170727-16:21:10.349(2)? (STDERR)     at makeErrorByStatus (packages/http/http
call_common.js:13:10)
W20170727-16:21:10.352(2)? (STDERR)     at Request._callback (packages/http/http
call_server.js:113:17)
W20170727-16:21:10.358(2)? (STDERR)     at Request.self.callback (C:\Users\Sylva
in\AppData\Local\.meteor\packages\http\1.2.12\npm\node_modules\request\request.j
s:200:22)
W20170727-16:21:10.363(2)? (STDERR)     at emitTwo (events.js:87:13)
W20170727-16:21:10.366(2)? (STDERR)     at Request.emit (events.js:172:7)
W20170727-16:21:10.370(2)? (STDERR)     at Request.<anonymous> (C:\Users\Sylvain
\AppData\Local\.meteor\packages\http\1.2.12\npm\node_modules\request\request.js:
1067:10)
W20170727-16:21:10.375(2)? (STDERR)     at emitOne (events.js:82:20)
W20170727-16:21:10.378(2)? (STDERR)     at Request.emit (events.js:169:7)
W20170727-16:21:10.381(2)? (STDERR)     at IncomingMessage.<anonymous> (C:\Users
\Sylvain\AppData\Local\.meteor\packages\http\1.2.12\npm\node_modules\request\req
uest.js:988:12)
W20170727-16:21:10.387(2)? (STDERR)     at emitNone (events.js:72:20)

I get the error both when I run the queries in parallel and when I run them in sequence.

Any idea?

I use a dev Discourse instance.

2

Something doesn’t seem right with

Are you also running your database locally?

I’m not really sure how you are using the api, but are you some how using multiple database connections and are running out? If you are just making api calls to your local discourse instance rails should only be using 1 connection, so i doubt that is what is happening.

1 Like
3

My dev instance is remote (1GB DigitalOcean droplet).

I lack knowledge here, but my current feeling is that API calls respond before actually completing the task. Would this explain the current issue? (db overload) And this other one? (topic model not ready just after creation)

4

Is Sidekiq involved in API calls?
I’m asking because I have this message in the admin dashboard:

A check for updates has not been performed. Ensure sidekiq is running.

(even though Sidekiq is up and running, as I can see in http://myserver/sidekiq)

5

Nope, it will just queue things up if it isn’t running.

I still think something is weird with your dev install on digital ocean. I would spin up another digital droplet and follow the production cloud install guide and see if you can reproduce the same errors.

1 Like