容器中部署的Azure Web应用程序上的Mongo套接字超时

问题描述

我有一个Azure Web App，该Web App与docker-compose一起部署。它在v5.0.0上运行Rails应用程序，并且mongoid版本是6.1。

我打开了“ Always On”（具有讽刺意味的）。但是经过一会儿的空闲时间后，如果我在应用程序已经打开的情况下刷新了一个标签页，或者尝试在新标签页中访问它，那么我将进入我的Rails错误页面，并且日志如下所示：

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'
2020-09-03T14:56:20.040644158Z F,[2020-09-03T14:56:20.040140 #1] FATAL -- : mongo (2.11.4) lib/mongo/server/connectable.rb:83:in `ensure_connected'
2020-09-03T14:56:20.041233659Z F,[2020-09-03T14:56:20.040726 #1] FATAL -- : mongo (2.11.4) lib/mongo/server/connection_base.rb:100:in `deliver'
2020-09-03T14:56:20.042001062Z F,[2020-09-03T14:56:20.041308 #1] FATAL -- : mongo (2.11.4) lib/mongo/server/connection.rb:394:in `deliver'
2020-09-03T14:56:20.042766364Z F,[2020-09-03T14:56:20.042112 #1] FATAL -- : mongo (2.11.4) lib/mongo/server/connection_base.rb:93:in `dispatch'
2020-09-03T14:56:20.043390666Z F,[2020-09-03T14:56:20.042861 #1] FATAL -- : mongo (2.11.4) lib/mongo/operation/shared/executable.rb:56:in `block in dispatch_message'
2020-09-03T14:56:20.044017767Z F,[2020-09-03T14:56:20.043468 #1] FATAL -- : mongo (2.11.4) lib/mongo/server/connection_pool.rb:557:in `with_connection'
2020-09-03T14:56:20.048727981Z F,[2020-09-03T14:56:20.044099 #1] FATAL -- : mongo (2.11.4) lib/mongo/server.rb:417:in `with_connection'
2020-09-03T14:56:20.049537683Z F,[2020-09-03T14:56:20.048839 #1] FATAL -- : mongo (2.11.4) lib/mongo/operation/shared/executable.rb:55:in `dispatch_message'
2020-09-03T14:56:20.050187285Z F,[2020-09-03T14:56:20.049630 #1] FATAL -- : mongo (2.11.4) lib/mongo/operation/shared/executable.rb:50:in `get_result'
2020-09-03T14:56:20.050763786Z F,[2020-09-03T14:56:20.050602 #1] FATAL -- : mongo (2.11.4) lib/mongo/operation/shared/executable.rb:29:in `block (3 levels) in do_execute'
2020-09-03T14:56:20.051367688Z F,[2020-09-03T14:56:20.050853 #1] FATAL -- : mongo (2.11.4) lib/mongo/operation/shared/response_handling.rb:87:in `add_server_diagnostics'
2020-09-03T14:56:20.051939690Z F,[2020-09-03T14:56:20.051446 #1] FATAL -- : mongo (2.11.4) lib/mongo/operation/shared/executable.rb:28:in `block (2 levels) in do_execute'
2020-09-03T14:56:20.052551592Z F,[2020-09-03T14:56:20.052046 #1] FATAL -- : mongo (2.11.4) lib/mongo/operation/shared/response_handling.rb:43:in `add_error_labels'
2020-09-03T14:56:20.053126093Z F,[2020-09-03T14:56:20.052627 #1] FATAL -- : mongo (2.11.4) lib/mongo/operation/shared/executable.rb:27:in `block in do_execute'
2020-09-03T14:56:20.053708795Z F,[2020-09-03T14:56:20.053207 #1] FATAL -- : mongo (2.11.4) lib/mongo/operation/shared/response_handling.rb:73:in `unpin_maybe'
2020-09-03T14:56:20.058397008Z F,[2020-09-03T14:56:20.053784 #1] FATAL -- : mongo (2.11.4) lib/mongo/operation/shared/executable.rb:26:in `do_execute'
2020-09-03T14:56:20.058904510Z F,[2020-09-03T14:56:20.058556 #1] FATAL -- : mongo (2.11.4) lib/mongo/operation/shared/executable_no_validate.rb:25:in `execute'
2020-09-03T14:56:20.059321611Z F,[2020-09-03T14:56:20.058996 #1] FATAL -- : mongo (2.11.4) lib/mongo/operation/shared/write.rb:38:in `execute'
2020-09-03T14:56:20.059660912Z F,[2020-09-03T14:56:20.059406 #1] FATAL -- : mongo (2.11.4) lib/mongo/collection/view/writable.rb:344:in `block (2 levels) in update_one'
2020-09-03T14:56:20.060140113Z F,[2020-09-03T14:56:20.059739 #1] FATAL -- : mongo (2.11.4) lib/mongo/retryable.rb:293:in `legacy_write_with_retry'
2020-09-03T14:56:20.060993115Z F,[2020-09-03T14:56:20.060369 #1] FATAL -- : mongo (2.11.4) lib/mongo/retryable.rb:202:in `write_with_retry'
2020-09-03T14:56:20.061628817Z F,[2020-09-03T14:56:20.061089 #1] FATAL -- : mongo (2.11.4) lib/mongo/collection/view/writable.rb:332:in `block in update_one'
2020-09-03T14:56:20.062270919Z F,[2020-09-03T14:56:20.061720 #1] FATAL -- : mongo (2.11.4) lib/mongo/client.rb:844:in `with_session'
2020-09-03T14:56:20.062848521Z F,[2020-09-03T14:56:20.062350 #1] FATAL -- : mongo (2.11.4) lib/mongo/collection/view.rb:208:in `with_session'
2020-09-03T14:56:20.063438422Z F,[2020-09-03T14:56:20.062937 #1] FATAL -- : mongo (2.11.4) lib/mongo/collection/view/writable.rb:330:in `update_one'
2020-09-03T14:56:20.063762323Z F,[2020-09-03T14:56:20.063526 #1] FATAL -- : mongoid (6.1.1) lib/mongoid/query_cache.rb:182:in `update_one_with_clear_cache'
2020-09-03T14:56:20.068365936Z F,[2020-09-03T14:56:20.068198 #1] FATAL -- : mongoid (6.1.1) lib/mongoid/persistable/updatable.rb:137:in `block in update_document'
2020-09-03T14:56:20.068764737Z F,[2020-09-03T14:56:20.068464 #1] FATAL -- : mongoid (6.1.1) lib/mongoid/persistable/updatable.rb:112:in `block (2 levels) in prepare_update'
2020-09-03T14:56:20.069098738Z F,[2020-09-03T14:56:20.068837 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:126:in `call'
2020-09-03T14:56:20.069551040Z F,[2020-09-03T14:56:20.069185 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
2020-09-03T14:56:20.069922541Z F,[2020-09-03T14:56:20.069634 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:455:in `call'
2020-09-03T14:56:20.070301242Z F,[2020-09-03T14:56:20.069985 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:101:in `__run_callbacks__'
2020-09-03T14:56:20.071079344Z F,[2020-09-03T14:56:20.070762 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:750:in `_run_update_callbacks'
2020-09-03T14:56:20.071965547Z F,[2020-09-03T14:56:20.071321 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:90:in `run_callbacks'
2020-09-03T14:56:20.072571148Z F,[2020-09-03T14:56:20.072053 #1] FATAL -- : mongoid (6.1.1) lib/mongoid/interceptable.rb:132:in `run_callbacks'
2020-09-03T14:56:20.076978661Z F,[2020-09-03T14:56:20.072652 #1] FATAL -- : mongoid (6.1.1) lib/mongoid/persistable/updatable.rb:111:in `block in prepare_update'
2020-09-03T14:56:20.081686074Z F,[2020-09-03T14:56:20.077057 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:126:in `call'
2020-09-03T14:56:20.081744074Z F,[2020-09-03T14:56:20.077585 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:506:in `block (2 levels) in compile'
2020-09-03T14:56:20.082658577Z F,[2020-09-03T14:56:20.077653 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:455:in `call'
2020-09-03T14:56:20.083267779Z F,[2020-09-03T14:56:20.082740 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:101:in `__run_callbacks__'
2020-09-03T14:56:20.083847180Z F,[2020-09-03T14:56:20.083678 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:750:in `_run_save_callbacks'
2020-09-03T14:56:20.084433382Z F,[2020-09-03T14:56:20.084262 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:90:in `run_callbacks'
2020-09-03T14:56:20.085056384Z F,[2020-09-03T14:56:20.084519 #1] FATAL -- : mongoid (6.1.1) lib/mongoid/interceptable.rb:132:in `run_callbacks'
2020-09-03T14:56:20.085645385Z F,[2020-09-03T14:56:20.085135 #1] FATAL -- : mongoid (6.1.1) lib/mongoid/persistable/updatable.rb:110:in `prepare_update'
2020-09-03T14:56:20.086256487Z F,[2020-09-03T14:56:20.085728 #1] FATAL -- : mongoid (6.1.1) lib/mongoid/persistable/updatable.rb:132:in `update_document'
2020-09-03T14:56:20.086857389Z F,[2020-09-03T14:56:20.086334 #1] FATAL -- : mongoid (6.1.1) lib/mongoid/persistable/savable.rb:25:in `save'
2020-09-03T14:56:20.087490791Z F,[2020-09-03T14:56:20.086940 #1] FATAL -- : mongo_session_store (3.2.0) lib/mongo_session_store/mongo_store_base.rb:45:in `set_session'
2020-09-03T14:56:20.092810406Z F,[2020-09-03T14:56:20.091388 #1] FATAL -- : mongo_session_store (3.2.0) lib/mongo_session_store/mongo_store_base.rb:35:in `write_session'
2020-09-03T14:56:20.092929006Z F,[2020-09-03T14:56:20.091652 #1] FATAL -- : rack (2.2.2) lib/rack/session/abstract/id.rb:388:in `commit_session'
2020-09-03T14:56:20.093020206Z F,[2020-09-03T14:56:20.091799 #1] FATAL -- : rack (2.2.2) lib/rack/session/abstract/id.rb:268:in `context'
2020-09-03T14:56:20.093123606Z F,[2020-09-03T14:56:20.092404 #1] FATAL -- : rack (2.2.2) lib/rack/session/abstract/id.rb:260:in `call'
2020-09-03T14:56:20.093215807Z F,[2020-09-03T14:56:20.092578 #1] FATAL -- : actionpack (5.0.0) lib/action_dispatch/middleware/cookies.rb:613:in `call'
2020-09-03T14:56:20.093748708Z F,[2020-09-03T14:56:20.092976 #1] FATAL -- : actionpack (5.0.0) lib/action_dispatch/middleware/callbacks.rb:38:in `block in call'
2020-09-03T14:56:20.095283913Z F,[2020-09-03T14:56:20.094257 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:97:in `__run_callbacks__'
2020-09-03T14:56:20.096501516Z F,[2020-09-03T14:56:20.095665 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:750:in `_run_call_callbacks'
2020-09-03T14:56:20.097084918Z F,[2020-09-03T14:56:20.096889 #1] FATAL -- : activesupport (5.0.0) lib/active_support/callbacks.rb:90:in `run_callbacks'
2020-09-03T14:56:20.101606130Z F,[2020-09-03T14:56:20.097203 #1] FATAL -- : actionpack (5.0.0) lib/action_dispatch/middleware/callbacks.rb:36:in `call'
2020-09-03T14:56:20.102785134Z F,[2020-09-03T14:56:20.102628 #1] FATAL -- : actionpack (5.0.0) lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
2020-09-03T14:56:20.103434636Z F,[2020-09-03T14:56:20.102878 #1] FATAL -- : rollbar (2.24.0) lib/rollbar/middleware/rails/rollbar.rb:25:in `block in call'
2020-09-03T14:56:20.104009437Z F,[2020-09-03T14:56:20.103835 #1] FATAL -- : rollbar (2.24.0) lib/rollbar.rb:145:in `scoped'
2020-09-03T14:56:20.105016440Z F,[2020-09-03T14:56:20.104816 #1] FATAL -- : rollbar (2.24.0) lib/rollbar/middleware/rails/rollbar.rb:22:in `call'
2020-09-03T14:56:20.105651942Z F,[2020-09-03T14:56:20.105104 #1] FATAL -- : actionpack (5.0.0) lib/action_dispatch/middleware/debug_exceptions.rb:49:in `call'
2020-09-03T14:56:20.106241944Z F,[2020-09-03T14:56:20.106036 #1] FATAL -- : rollbar (2.24.0) lib/rollbar/middleware/rails/show_exceptions.rb:22:in `call_with_rollbar'
2020-09-03T14:56:20.106842145Z F,[2020-09-03T14:56:20.106678 #1] FATAL -- : actionpack (5.0.0) lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
2020-09-03T14:56:20.107500047Z F,[2020-09-03T14:56:20.106932 #1] FATAL -- : railties (5.0.0) lib/rails/rack/logger.rb:36:in `call_app'
2020-09-03T14:56:20.111858460Z F,[2020-09-03T14:56:20.107577 #1] FATAL -- : railties (5.0.0) lib/rails/rack/logger.rb:26:in `call'
2020-09-03T14:56:20.112389861Z F,[2020-09-03T14:56:20.111949 #1] FATAL -- : actionpack (5.0.0) lib/action_dispatch/middleware/request_id.rb:24:in `call'
2020-09-03T14:56:20.112855762Z F,[2020-09-03T14:56:20.112477 #1] FATAL -- : rack (2.2.2) lib/rack/method_override.rb:24:in `call'
2020-09-03T14:56:20.113393964Z F,[2020-09-03T14:56:20.112924 #1] FATAL -- : rack (2.2.2) lib/rack/runtime.rb:22:in `call'
2020-09-03T14:56:20.114051166Z F,[2020-09-03T14:56:20.113554 #1] FATAL -- : activesupport (5.0.0) lib/active_support/cache/strategy/local_cache_middleware.rb:28:in `call'
2020-09-03T14:56:20.114617467Z F,[2020-09-03T14:56:20.114166 #1] FATAL -- : actionpack (5.0.0) lib/action_dispatch/middleware/executor.rb:12:in `call'
2020-09-03T14:56:20.115553970Z F,[2020-09-03T14:56:20.115044 #1] FATAL -- : actionpack (5.0.0) lib/action_dispatch/middleware/static.rb:136:in `call'
2020-09-03T14:56:20.116156172Z F,[2020-09-03T14:56:20.115641 #1] FATAL -- : rack (2.2.2) lib/rack/sendfile.rb:110:in `call'
2020-09-03T14:56:20.116749973Z F,[2020-09-03T14:56:20.116233 #1] FATAL -- : actionpack (5.0.0) lib/action_dispatch/middleware/ssl.rb:83:in `call'
2020-09-03T14:56:20.117397175Z F,[2020-09-03T14:56:20.116843 #1] FATAL -- : railties (5.0.0) lib/rails/engine.rb:522:in `call'
2020-09-03T14:56:20.124842596Z F,[2020-09-03T14:56:20.117480 #1] FATAL -- : puma (3.12.4) lib/puma/configuration.rb:227:in `call'
2020-09-03T14:56:20.124911497Z F,[2020-09-03T14:56:20.121530 #1] FATAL -- : puma (3.12.4) lib/puma/server.rb:675:in `handle_request'
2020-09-03T14:56:20.125030397Z F,[2020-09-03T14:56:20.121722 #1] FATAL -- : puma (3.12.4) lib/puma/server.rb:476:in `process_client'
2020-09-03T14:56:20.125061897Z F,[2020-09-03T14:56:20.121895 #1] FATAL -- : puma (3.12.4) lib/puma/server.rb:334:in `block in run'
2020-09-03T14:56:20.125147297Z F,[2020-09-03T14:56:20.122061 #1] FATAL -- : puma (3.12.4) lib/puma/thread_pool.rb:135:in `block in spawn_thread'

如果刷新我的应用程序，一切将再次恢复。太酷了，但是从客户的角度来看这是不可接受的。

我尝试通过将 socket_timeout 选项设置为我的 mongoid.yml 中的荒谬值来尝试使用该选项，但这似乎并没有太大帮助。

看起来它可能来自Azure，它切断了闲置时间过长的连接，但是为什么我的Mongo套接字被认为是这样呢？我想念什么吗？

非常感谢您的帮助，谢谢！

解决方法

编辑：：红宝石驱动程序收到commit，可以解决此问题。升级ruby驱动程序版本应该可以解决该问题。感谢D. SM指出来。

如果您不能/不想升级您的版本，下面的代码似乎可行。

从mongoid和ruby驱动程序文档中提取所有内容后，我设法避免了在mongoid.yml上使用这些选项的Read retries闲置后崩溃的情况。

   socket_timeout: 60
   heartbeat_frequency: 2
   max_idle_time: 1