Странная ошибка MongoError (с ReactiveMongo) при перезагрузке приложения Play
Очень часто, когда Play перезагружает приложение после изменения кода, я получаю следующую ошибку:
MongoError ['Невозможно достичь набора узлов! Пожалуйста, проверьте подключение к сети.']
Журнал MongoDB выглядит так:
2016-09-06T18:51:22.609+0200 I NETWORK [initandlisten] waiting for connections on port 27017
2016-09-06T18:53:49.916+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60559 #1 (1 connection now open)
2016-09-06T18:53:51.185+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60561 #2 (2 connections now open)
2016-09-06T18:53:51.196+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60562 #3 (3 connections now open)
2016-09-06T18:53:51.206+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60563 #4 (4 connections now open)
2016-09-06T18:53:51.217+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60564 #5 (5 connections now open)
2016-09-06T18:53:51.227+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60565 #6 (6 connections now open)
2016-09-06T18:53:51.237+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60566 #7 (7 connections now open)
2016-09-06T18:53:51.248+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60567 #8 (8 connections now open)
2016-09-06T18:53:51.258+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60568 #9 (9 connections now open)
2016-09-06T18:53:51.269+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60569 #10 (10 connections now open)
2016-09-06T18:53:59.533+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60577 #11 (11 connections now open)
2016-09-06T18:53:59.546+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60578 #12 (12 connections now open)
2016-09-06T18:53:59.557+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60579 #13 (13 connections now open)
2016-09-06T18:53:59.568+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60580 #14 (14 connections now open)
2016-09-06T18:53:59.579+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60581 #15 (15 connections now open)
2016-09-06T18:53:59.589+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60582 #16 (16 connections now open)
2016-09-06T18:53:59.600+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60583 #17 (17 connections now open)
2016-09-06T18:53:59.610+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60584 #18 (18 connections now open)
2016-09-06T18:53:59.620+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:60585 #19 (19 connections now open)
2016-09-06T19:37:21.594+0200 I NETWORK [conn11] end connection 127.0.0.1:60577 (18 connections now open)
2016-09-06T19:37:21.596+0200 I NETWORK [conn1] end connection 127.0.0.1:60559 (17 connections now open)
2016-09-06T19:37:21.597+0200 I NETWORK [conn15] end connection 127.0.0.1:60581 (16 connections now open)
2016-09-06T19:37:21.597+0200 I NETWORK [conn13] end connection 127.0.0.1:60579 (15 connections now open)
2016-09-06T19:37:21.597+0200 I NETWORK [conn16] end connection 127.0.0.1:60582 (14 connections now open)
2016-09-06T19:37:21.598+0200 I NETWORK [conn12] end connection 127.0.0.1:60578 (13 connections now open)
2016-09-06T19:37:21.598+0200 I NETWORK [conn19] end connection 127.0.0.1:60585 (13 connections now open)
2016-09-06T19:37:21.599+0200 I NETWORK [conn17] end connection 127.0.0.1:60583 (11 connections now open)
2016-09-06T19:37:21.599+0200 I NETWORK [conn14] end connection 127.0.0.1:60580 (11 connections now open)
2016-09-06T19:37:21.600+0200 I NETWORK [conn18] end connection 127.0.0.1:60584 (9 connections now open)
2016-09-06T19:37:21.607+0200 I NETWORK [conn5] end connection 127.0.0.1:60564 (9 connections now open)
2016-09-06T19:37:21.607+0200 I NETWORK [conn9] end connection 127.0.0.1:60568 (9 connections now open)
2016-09-06T19:37:21.608+0200 I NETWORK [conn6] end connection 127.0.0.1:60565 (9 connections now open)
2016-09-06T19:37:21.608+0200 I NETWORK [conn10] end connection 127.0.0.1:60569 (9 connections now open)
2016-09-06T19:37:21.609+0200 I NETWORK [conn2] end connection 127.0.0.1:60561 (9 connections now open)
2016-09-06T19:37:21.609+0200 I NETWORK [conn7] end connection 127.0.0.1:60566 (9 connections now open)
2016-09-06T19:37:21.610+0200 I NETWORK [conn3] end connection 127.0.0.1:60562 (9 connections now open)
2016-09-06T19:37:21.611+0200 I NETWORK [conn4] end connection 127.0.0.1:60563 (4 connections now open)
2016-09-06T19:37:21.612+0200 I NETWORK [conn8] end connection 127.0.0.1:60567 (0 connections now open)
2016-09-06T19:37:22.326+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62077 #20 (1 connection now open)
2016-09-06T19:37:22.333+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62078 #21 (2 connections now open)
2016-09-06T19:37:22.333+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62079 #22 (3 connections now open)
2016-09-06T19:37:22.343+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62080 #23 (4 connections now open)
2016-09-06T19:37:22.344+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62081 #24 (5 connections now open)
2016-09-06T19:37:22.344+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62082 #25 (6 connections now open)
2016-09-06T19:37:22.344+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62083 #26 (7 connections now open)
2016-09-06T19:37:22.344+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62084 #27 (8 connections now open)
2016-09-06T19:37:22.354+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62085 #28 (9 connections now open)
2016-09-06T19:37:22.355+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62086 #29 (10 connections now open)
2016-09-06T19:37:32.348+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62105 #30 (11 connections now open)
2016-09-06T19:37:32.359+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62106 #31 (12 connections now open)
2016-09-06T19:37:32.393+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62107 #32 (13 connections now open)
2016-09-06T19:37:32.399+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62108 #33 (14 connections now open)
2016-09-06T19:37:32.399+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62109 #34 (15 connections now open)
2016-09-06T19:37:32.399+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62110 #35 (16 connections now open)
2016-09-06T19:37:32.399+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62111 #36 (17 connections now open)
2016-09-06T19:37:32.401+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62112 #37 (18 connections now open)
2016-09-06T19:37:32.401+0200 I NETWORK [initandlisten] connection accepted from 127.0.0.1:62113 #38 (19 connections now open)
Иногда есть и это исключение:
[warn] r.c.a.MongoDBSystem - The entire node set is unreachable, is there a network problem?
[warn] r.c.a.MongoDBSystem - The entire node set is unreachable, is there a network problem?
[error] r.api.Failover2 - Got an error, no more attempts to do. Completing with a failure...
reactivemongo.core.actors.Exceptions$PrimaryUnavailableException$: MongoError['No primary node is available!']
at reactivemongo.core.actors.Exceptions$PrimaryUnavailableException$.<clinit>(actors.scala)
at reactivemongo.core.actors.MongoDBSystem$$anonfun$reactivemongo$core$actors$MongoDBSystem$$pickChannel$4.apply(actors.scala:748)
at reactivemongo.core.actors.MongoDBSystem$$anonfun$reactivemongo$core$actors$MongoDBSystem$$pickChannel$4.apply(actors.scala:748)
at scala.Option.getOrElse(Option.scala:121)
at reactivemongo.core.actors.MongoDBSystem$class.reactivemongo$core$actors$MongoDBSystem$$pickChannel(actors.scala:748)
at reactivemongo.core.actors.MongoDBSystem$$anonfun$4.applyOrElse(actors.scala:340)
at scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:170)
at akka.actor.Actor$class.aroundReceive(Actor.scala:482)
at reactivemongo.core.actors.LegacyDBSystem.aroundReceive(actors.scala:896)
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:526)
[error] r.api.Failover2 - Got an error, no more attempts to do. Completing with a failure...
reactivemongo.core.actors.Exceptions$PrimaryUnavailableException$: MongoError['No primary node is available!']
at reactivemongo.core.actors.Exceptions$PrimaryUnavailableException$.<clinit>(actors.scala)
at reactivemongo.core.actors.MongoDBSystem$$anonfun$reactivemongo$core$actors$MongoDBSystem$$pickChannel$4.apply(actors.scala:748)
at reactivemongo.core.actors.MongoDBSystem$$anonfun$reactivemongo$core$actors$MongoDBSystem$$pickChannel$4.apply(actors.scala:748)
at scala.Option.getOrElse(Option.scala:121)
at reactivemongo.core.actors.MongoDBSystem$class.reactivemongo$core$actors$MongoDBSystem$$pickChannel(actors.scala:748)
at reactivemongo.core.actors.MongoDBSystem$$anonfun$4.applyOrElse(actors.scala:340)
at scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:170)
at akka.actor.Actor$class.aroundReceive(Actor.scala:482)
at reactivemongo.core.actors.LegacyDBSystem.aroundReceive(actors.scala:896)
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:526)
[error] r.api.Failover2 - Got an error, no more attempts to do. Completing with a failure...
reactivemongo.core.actors.Exceptions$PrimaryUnavailableException$: MongoError['No primary node is available!']
at reactivemongo.core.actors.Exceptions$PrimaryUnavailableException$.<clinit>(actors.scala)
at reactivemongo.core.actors.MongoDBSystem$$anonfun$reactivemongo$core$actors$MongoDBSystem$$pickChannel$4.apply(actors.scala:748)
at reactivemongo.core.actors.MongoDBSystem$$anonfun$reactivemongo$core$actors$MongoDBSystem$$pickChannel$4.apply(actors.scala:748)
at scala.Option.getOrElse(Option.scala:121)
at reactivemongo.core.actors.MongoDBSystem$class.reactivemongo$core$actors$MongoDBSystem$$pickChannel(actors.scala:748)
at reactivemongo.core.actors.MongoDBSystem$$anonfun$4.applyOrElse(actors.scala:340)
at scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:170)
at akka.actor.Actor$class.aroundReceive(Actor.scala:482)
at reactivemongo.core.actors.LegacyDBSystem.aroundReceive(actors.scala:896)
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:526)
Когда я полностью убью процесс и выполню activator run
опять все работает как раньше.
Вот как я использую ReactiveMongo:
val collection: Future[JSONCollection] = reactiveMongoApi.database.map(_.collection[JSONCollection](collectionName))
Используемые версии:
- MongoDB: v3.2.4
- Scala: 2.11.8
- Play 2.5
- play2-реактивный монго: 0.11.13
- реактивные деньги-игры-джон: 0.11.14
Поскольку такое развитие требует вечности, я был бы признателен за любую помощь, чтобы решить эту проблему!:-)
1 ответ
Я тоже столкнулся с этой проблемой; каждый раз, когда я перезагружал свое приложение Play (включая горячие перезагрузки), я получал сотни ошибок подключения. После нескольких попыток мое приложение будет работать нормально до следующей перезагрузки. Это начало происходить только после того, как я обновился с ReactiveMongo 0.x до 1.x. Я пробовал запускать MongoDB (версии с 3.2 по 4.0) локально, как в виде собственной установки, так и в контейнере Docker.
Я «решил» это, добавив следующие параметры подключения:
MongoConnectionOptions(maxIdleTimeMS = 100000, heartbeatFrequencyMS = 100)
Полное подключение выглядит так:
private val driver = new reactivemongo.api.AsyncDriver
val connection: Future[MongoConnection] = driver.connect(List("localhost"), MongoConnectionOptions(maxIdleTimeMS = 100000, heartbeatFrequencyMS = 100))
Я не знаю, почему эти значения работают и являются ли они оптимальными. И я, вероятно, не рекомендовал бы использовать пульсацию 100 мс в производственной среде. Тем не менее, он работает для моих потребностей в разработке, поэтому я решил поделиться.