我们最近升级到 Play 2.7.0 并使用 play2-reactivemongo 版本 0.16.2 和 reactivemongo 0.16.3。我们使用reactivemongo-shaded-native
但也尝试不使用。
我们正在连接到具有 3 个节点的副本集,即 MongoDB Atlas 上的 MongoDB 3.6.10。
初始连接很好,服务运行了一段时间。
但最后我们遇到了这个错误:
[error] 2019-02-15 09:40:30,466 r.api.Failover2 - [Supervisor-1/Connection-2] Got an error, no more attempts to do. Completing with a failure...
reactivemongo.core.actors.Exceptions$PrimaryUnavailableException: MongoError['No primary node is available! (Supervisor-1/Connection-2)']
Caused by: reactivemongo.core.actors.Exceptions$InternalState: null
at reactivemongo.ConnectAll$IsMaster(400, {{NodeSet Some(PlayappDevelopment-shard-0) Node[playappdevelopment-shard-00-00-tedsb.mongodb.net:27017: Unknown (20/20 available connections), latency=9223372036854775807, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-01-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=135, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-02-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=140, authenticated={Authenticated(admin,playapp_rw)}] }})(<time:1550223615628>)
at reactivemongo.IsMaster(400, {{NodeSet Some(PlayappDevelopment-shard-0) Node[playappdevelopment-shard-00-00-tedsb.mongodb.net:27017: Unknown (20/20 available connections), latency=9223372036854775807, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-01-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=135, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-02-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=21, authenticated={Authenticated(admin,playapp_rw)}] }})(<time:1550223615626>)
at reactivemongo.ConnectAll$IsMaster(399, {{NodeSet Some(PlayappDevelopment-shard-0) Node[playappdevelopment-shard-00-00-tedsb.mongodb.net:27017: Unknown (20/20 available connections), latency=9223372036854775807, authenticated={}] | Node[playappdevelopment-shard-00-01-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=135, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-02-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=21, authenticated={Authenticated(admin,playapp_rw)}] }})(<time:1550223615623>)
at reactivemongo.IsMaster(399, {{NodeSet Some(PlayappDevelopment-shard-0) Node[playappdevelopment-shard-00-00-tedsb.mongodb.net:27017: Unknown (20/20 available connections), latency=9223372036854775807, authenticated={}] | Node[playappdevelopment-shard-00-01-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=17, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-02-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=21, authenticated={Authenticated(admin,playapp_rw)}] }})(<time:1550223615622>)
at reactivemongo.RefreshAll({{NodeSet Some(PlayappDevelopment-shard-0) Node[playappdevelopment-shard-00-00-tedsb.mongodb.net:27017: Primary (20/20 available connections), latency=30591, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-01-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=17, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-02-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=21, authenticated={Authenticated(admin,playapp_rw)}] }})(<time:1550223615486>)
at reactivemongo.PrimaryUnavailable(<time:1550223615485>)
at reactivemongo.ConnectAll({{NodeSet Some(PlayappDevelopment-shard-0) Node[playappdevelopment-shard-00-00-tedsb.mongodb.net:27017: Primary (20/20 available connections), latency=30591, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-01-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=17, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-02-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=21, authenticated={Authenticated(admin,playapp_rw)}] }})(<time:1550223615475>)
at reactivemongo.ConnectAll$IsMaster(397, {{NodeSet Some(PlayappDevelopment-shard-0) Node[playappdevelopment-shard-00-00-tedsb.mongodb.net:27017: Primary (20/20 available connections), latency=30591, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-01-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=17, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-02-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=21, authenticated={Authenticated(admin,playapp_rw)}] }})(<time:1550223605498>)
at reactivemongo.IsMaster(397, {{NodeSet Some(PlayappDevelopment-shard-0) Node[playappdevelopment-shard-00-00-tedsb.mongodb.net:27017: Primary (20/20 available connections), latency=30591, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-01-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=17, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-02-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=15, authenticated={Authenticated(admin,playapp_rw)}] }})(<time:1550223605498>)
at reactivemongo.ConnectAll$IsMaster(396, {{NodeSet Some(PlayappDevelopment-shard-0) Node[playappdevelopment-shard-00-00-tedsb.mongodb.net:27017: Primary (20/20 available connections), latency=30591, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-01-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=17, authenticated={Authenticated(admin,playapp_rw)}] | Node[playappdevelopment-shard-00-02-tedsb.mongodb.net:27017: Secondary (20/20 available connections), latency=15, authenticated={Authenticated(admin,playapp_rw)}] }})(<time:1550223605493>)
和这个:
[error] 2019-02-15 09:40:25,157 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] Oups. 80193 not found! complete message is Response(MessageHeader(16775938,220053,80193,1), Reply(8,0,0,1), ResponseInfo(b0706d7f))
[error] 2019-02-15 09:40:25,720 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] Oups. 79580 not found! complete message is Response(MessageHeader(16776408,220065,79580,1), Reply(8,0,0,1), ResponseInfo(5c65523c))
[error] 2019-02-15 09:40:26,616 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] Oups. 80346 not found! complete message is Response(MessageHeader(16776173,220060,80346,1), Reply(8,0,0,1), ResponseInfo(5613ea02))
[error] 2019-02-15 09:40:26,702 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] Oups. 80457 not found! complete message is Response(MessageHeader(16776643,220079,80457,1), Reply(8,0,0,1), ResponseInfo(2fa23bb9))
[error] 2019-02-15 09:40:29,612 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] Oups. 80174 not found! complete message is Response(MessageHeader(16776878,220102,80174,1), Reply(8,0,0,1), ResponseInfo(4faa6eec))
[error] 2019-02-15 09:40:30,257 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] Oups. 80191 not found! complete message is Response(MessageHeader(16776643,220111,80191,1), Reply(8,0,0,1), ResponseInfo(1fb6b5e0))
应用程序似乎无法(完全)恢复——20 个请求中有 1 个成功。
2019-02-15 09:59:45,476 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] Node[playappdevelopment-shard-00-00-tedsb.mongodb.net:27017: \
Unknown (20/20 available connections), latency=9223372036854775807, authenticated={Authenticated(admin,playapp_rw)}] \
hasn't answered in time to last ping! Please check its connectivity
有大量“没有请求渠道”消息:
2019-03-05 15:02:58,433 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] No channel for request: Request(48879, 0, Query(0,assets.$cmd,0,1), Primary, None)
2019-03-05 15:02:58,580 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] No channel for request: Request(48880, 0, Query(0,assets.$cmd,0,1), Primary, None)
2019-03-05 15:02:58,678 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] No channel for request: Request(48881, 0, Query(0,assets.$cmd,0,1), Primary, None)
2019-03-05 15:02:58,777 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] No channel for request: Request(48882, 0, Query(0,assets.$cmd,0,1), Primary, None)
2019-03-05 15:02:58,874 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] No channel for request: Request(48883, 0, Query(0,assets.$cmd,0,1), Primary, None)
2019-03-05 15:02:58,972 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] No channel for request: Request(48884, 0, Query(0,assets.$cmd,0,1), Primary, None)
2019-03-05 15:02:59,069 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] No channel for request: Request(48885, 0, Query(0,assets.$cmd,0,1), Primary, None)
2019-03-05 15:02:59,220 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] No channel for request: Request(48886, 0, Query(0,assets.$cmd,0,1), Primary, None)
2019-03-05 15:02:59,318 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] No channel for request: Request(48887, 0, Query(0,assets.$cmd,0,1), Primary, None)
2019-03-05 15:02:59,416 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] No channel for request: Request(48888, 0, Query(0,assets.$cmd,0,1), Primary, None)
2019-03-05 15:02:59,514 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] No channel for request: Request(48889, 0, Query(0,assets.$cmd,0,1), Primary, None)
2019-03-05 15:02:59,611 r.c.a.MongoDBSystem - [Supervisor-1/Connection-2] No channel for request: Request(48890, 0, Query(0,assets.$cmd,0,1), Primary, None)
这似乎与对 Play HTTP 服务器的大量并发请求有关,这可能会使主节点的所有可用通道饱和,从而导致主节点状态的任何刷新失败。
显然,当连接到只有一个节点的本地副本集时,我们没有这个问题。
问题是,我该如何解决这个问题?
任何人都可以理解提供的日志消息吗?
我的分析是否正确,即。ReactiveMongo 是否会因为通道只是“忙”而无法查询主要状态?
更新:我们从 ReactiveMongo(在过去 4 年中为我们服务得很好)切换到了官方的 mongo-scala-driver——这真的很痛苦,现在仍然是(主要是因为“Registry”-no-compile-time -type-safety 概念传递Class[T]
s,等等)但我们不再看到连接问题。