MongoDB read retry timeout on Web App in container

Question

Hi all

I have a Web App which runs containers with Docker Compose. It embeds a Rails (v5.0.0) app and uses mongo driver 2.11 and mongoid 6.1 to talk with our DB on a DaaS platform.

After a few moments of idle time, if I make an action or reload my page I land on my Rails error page and the logs look like this :

2020-09-03T14:56:20.036576946Z F, [2020-09-03T14:56:20.036429 #1] FATAL -- :
2020-09-03T14:56:20.037180348Z F, [2020-09-03T14:56:20.036742 #1] FATAL -- : Mongo::Error::SocketTimeoutError (Errno::ETIMEDOUT: Connection timed out (for xxxx:10384 (no TLS)) (on xxxxx.com:10384) (on xxxx.com:10384)):
2020-09-03T14:56:20.037761050Z F, [2020-09-03T14:56:20.037270 #1] FATAL -- :
2020-09-03T14:56:20.038380451Z F, [2020-09-03T14:56:20.037850 #1] FATAL -- : mongo (2.11.4) lib/mongo/socket.rb:326:in `rescue in handle_errors'
2020-09-03T14:56:20.038954453Z F, [2020-09-03T14:56:20.038458 #1] FATAL -- : mongo (2.11.4) lib/mongo/socket.rb:322:in `handle_errors'
2020-09-03T14:56:20.039493755Z F, [2020-09-03T14:56:20.039036 #1] FATAL -- : mongo (2.11.4) lib/mongo/socket.rb:175:in `write'
2020-09-03T14:56:20.040059456Z F, [2020-09-03T14:56:20.039569 #1] FATAL -- : mongo (2.11.4) lib/mongo/server/connection_base.rb:107:in `block in deliver'

Seems to happen when the client tries to find a session :

2020-09-04T09:25:31.382173134Z D, [2020-09-04T09:25:31.381972 #1] DEBUG -- : MONGODB | [99] xxxxx.com:11326 #8 | Staging.find | STARTED | {"find"=>"sessions", "filter"=>{"_id"=>"7c0b85c69c8f3991ec2bdc1dfd570ee0"}, "sort"=>{"_id"=>1}, "limit"=>1, "singleBatch"=>true, "$clusterTime"=>{"clusterTime"=>#<BSON::Timestamp:0x0000561f5bd222d0 @seconds=1599210748, @increment=1>, "signature"=>{"ha...
2020-09-04T09:25:31.383251737Z D, [2020-09-04T09:25:31.383100 #1] DEBUG -- : MONGODB | [99] xxx.com:11326 | Staging.find | FAILED | Errno::ETIMEDOUT: Connection timed out (for 5xxxxx:11326 (no TLS)) | 0.000655402s
2020-09-04T09:25:31.385413643Z W, [2020-09-04T09:25:31.384479 #1]  WARN -- : Legacy read retry due to: Mongo::Error::SocketTimeoutError Errno::ETIMEDOUT: Connection timed out (for 5xxxx:11326 (no TLS)) (on xxxxx.com:11326, legacy retry, attempt 1) (on xxxxxx.com:11326, legacy retry, attempt 1)

The Always On options is activated. If I refresh after getting my error my app is up again. I don't really understand what's going on. The logs sometimes mentions Read retries that would fail.

I've tried playing with the socket_timeout option by setting it to an absurd value in my mongoid.yml but it doesn't seem to help much.

I knew about the Azure timeout but for HTTP requests, do you mean this applies to Socket too ?

This code was previously published to Heroku as is, and their timeout is about 30s and we never had problems with Mongo before.

Plus this is not about an ongoing requests that would take too long. I load the home page which does requests my DB. When it's done I just leave my app idle and after a few moments when I reload I have a read retry on my socket which fails.

Does someone have an idea where to look for ?

Thanks !

Answer 1

I think I've managed to pull a configuration that helps the app not to crash with following options on my mongoid.yml connection

    socket_timeout: 60
   heartbeat_frequency: 2
   max_idle_time: 1