Количество соединений Mongo является отрицательным (соединения не завершаются должным образом) - PullRequest
Новая
       78

Количество соединений Mongo является отрицательным (соединения не завершаются должным образом)

0 голосов
/ 10 июля 2019

У меня есть служба, которая подключается к кластеру Mongo, работающему в MongoAtlas. В настоящее время набор тестов подключается к кластеру, выполняет ряд тестов, уничтожает созданные данные и закрывает соединение, по крайней мере, так оно и должно быть.

Часть набора тестов: 

class BandFeatureTests extends FeatureTest with BeforeAndAfter{

  override val server = new EmbeddedHttpServer(
    new GorillaServer{
      override val overrideModules: Seq[TwitterModule] = Seq(
         new DatabaseProviderTestModule()
      )
      override def warmup(): Unit = {/*no op*/}
  },
  flags = Map(
    "dbscope" -> "testbands"
  )
)

val mockDBProvider: MongoTestSpec = server.injector
  .instance[MongoDataBaseConnector]
  .asInstanceOf[MongoTestSpec]

override def afterAll(): Unit = {
   mockDBProvider.close
}


test("Should Get Bands") {
 server.httpGet(
  path = "/bands",
  andExpect = Status.Ok)
}

Флаг dbscope будет использоваться для именования базы данных, так что разные наборы тестов могут загружать разные БД и работать параллельно без удаления данных друг друга

DatabaseTestProviderTestModule: 

object DatabaseProviderTestModule extends TwitterModule {

  flag(name="dbscope", default="KRONOSPROD", help = "Set The Database Scope")

  @Provides
  @Singleton
  def providesDbscope(@Flag("dbscope") dbscope: String) : MongoDataBaseConnector = {
    new MongoDataBaseConnector(dbscope)
  }
}

MongoDatabaseConnector: 

class MongoDataBaseConnector(dbscope: String) {

  System.setProperty("org.mongodb.async.type", "netty")

  val conf: Config = ConfigFactory.load()
  val dbConfig: Config = conf.getConfig("db")
  val user : String = dbConfig.getString("properties.username")
  val pwd: String = dbConfig.getString("properties.pwd")
  var url: String = s"mongodb+srv://$user:$pwd@cluster0-vrzo2.mongodb.net/test?retryWrites=true&w=majority"

  val mongoClient: MongoClient = MongoClient(url)
  val database: MongoDatabase =  mongoClient.getDatabase(DATA_BASE_NAME)

  def close = {
    mongoClient.close()
  }
  //FOLLOWED BY ALL THE DOC DEFINITIONS AND CODECS
}

Я заметил, что после того, как набор завершен и все тесты пройдены, кластер Mongo продолжал выводить на консоль sbt: 

23:41:43.182 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-01-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.protocol.command - Sending command '{ "ismaster" : 1, "$db" : "admin", "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1562715686, "i" : 2 } }, "signature" : { "hash" : { "$binary" : { "base64" : "fSDq9nBlwYNI+v2jd9bMV4HJzQI=", "subType" : "00" } }, "keyId" : 6709470559735906305 } } }' with request id 33 to database admin on connection [connectionId{localValue:1, serverValue:62629}] to server cluster0-shard-00-01-vrzo2.mongodb.net:27017
23:41:43.185 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-00-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.cluster - Checking status of cluster0-shard-00-00-vrzo2.mongodb.net:27017
23:41:43.187 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-00-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.protocol.command - Sending command '{ "ismaster" : 1, "$db" : "admin", "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1562715686, "i" : 2 } }, "signature" : { "hash" : { "$binary" : { "base64" : "fSDq9nBlwYNI+v2jd9bMV4HJzQI=", "subType" : "00" } }, "keyId" : 6709470559735906305 } } }' with request id 34 to database admin on connection [connectionId{localValue:3, serverValue:83104}] to server cluster0-shard-00-00-vrzo2.mongodb.net:27017
23:41:43.187 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-02-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.cluster - Checking status of cluster0-shard-00-02-vrzo2.mongodb.net:27017
23:41:43.189 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-02-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.protocol.command - Sending command '{ "ismaster" : 1, "$db" : "admin", "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1562715686, "i" : 2 } }, "signature" : { "hash" : { "$binary" : { "base64" : "fSDq9nBlwYNI+v2jd9bMV4HJzQI=", "subType" : "00" } }, "keyId" : 6709470559735906305 } } }' with request id 35 to database admin on connection [connectionId{localValue:4, serverValue:84492}] to server cluster0-shard-00-02-vrzo2.mongodb.net:27017
23:41:43.200 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-01-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.protocol.command - Execution of command with request id 33 completed successfully in 18.31 ms on connection [connectionId{localValue:1, serverValue:62629}] to server cluster0-shard-00-01-vrzo2.mongodb.net:27017
23:41:43.201 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-01-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.cluster - Updating cluster description to  {type=REPLICA_SET, servers=[{address=cluster0-shard-00-01-vrzo2.mongodb.net:27017, type=REPLICA_SET_SECONDARY, TagSet{[Tag{name='region', value='US_EAST_1'}, Tag{name='provider', value='AWS'}, Tag{name='nodeType', value='ELECTABLE'}]}, roundTripTime=58.6 ms, state=CONNECTED}, {address=cluster0-shard-00-02-vrzo2.mongodb.net:27017, type=REPLICA_SET_SECONDARY, TagSet{[Tag{name='region', value='US_EAST_1'}, Tag{name='provider', value='AWS'}, Tag{name='nodeType', value='ELECTABLE'}]}, roundTripTime=55.3 ms, state=CONNECTED}, {address=cluster0-shard-00-00-vrzo2.mongodb.net:27017, type=REPLICA_SET_PRIMARY, TagSet{[Tag{name='region', value='US_EAST_1'}, Tag{name='provider', value='AWS'}, Tag{name='nodeType', value='ELECTABLE'}]}, roundTripTime=69.8 ms, state=CONNECTED}]
23:41:43.208 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-00-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.protocol.command - Execution of command with request id 34 completed successfully in 21.74 ms on connection [connectionId{localValue:3, serverValue:83104}] to server cluster0-shard-00-00-vrzo2.mongodb.net:27017
23:41:43.209 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-00-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.cluster - Updating cluster description to  {type=REPLICA_SET, servers=[{address=cluster0-shard-00-01-vrzo2.mongodb.net:27017, type=REPLICA_SET_SECONDARY, TagSet{[Tag{name='region', value='US_EAST_1'}, Tag{name='provider', value='AWS'}, Tag{name='nodeType', value='ELECTABLE'}]}, roundTripTime=58.6 ms, state=CONNECTED}, {address=cluster0-shard-00-02-vrzo2.mongodb.net:27017, type=REPLICA_SET_SECONDARY, TagSet{[Tag{name='region', value='US_EAST_1'}, Tag{name='provider', value='AWS'}, Tag{name='nodeType', value='ELECTABLE'}]}, roundTripTime=55.3 ms, state=CONNECTED}, {address=cluster0-shard-00-00-vrzo2.mongodb.net:27017, type=REPLICA_SET_PRIMARY, TagSet{[Tag{name='region', value='US_EAST_1'}, Tag{name='provider', value='AWS'}, Tag{name='nodeType', value='ELECTABLE'}]}, roundTripTime=60.4 ms, state=CONNECTED}]
23:41:43.219 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-02-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.protocol.command - Execution of command with request id 35 completed successfully in 30.67 ms on connection [connectionId{localValue:4, serverValue:84492}] to server cluster0-shard-00-02-vrzo2.mongodb.net:27017
23:41:43.219 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-02-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.cluster - Updating cluster description to  {type=REPLICA_SET, servers=[{address=cluster0-shard-00-01-vrzo2.mongodb.net:27017, type=REPLICA_SET_SECONDARY, TagSet{[Tag{name='region', value='US_EAST_1'}, Tag{name='provider', value='AWS'}, Tag{name='nodeType', value='ELECTABLE'}]}, roundTripTime=58.6 ms, state=CONNECTED}, {address=cluster0-shard-00-02-vrzo2.mongodb.net:27017, type=REPLICA_SET_SECONDARY, TagSet{[Tag{name='region', value='US_EAST_1'}, Tag{name='provider', value='AWS'}, Tag{name='nodeType', value='ELECTABLE'}]}, roundTripTime=50.6 ms, state=CONNECTED}, {address=cluster0-shard-00-00-vrzo2.mongodb.net:27017, type=REPLICA_SET_PRIMARY, TagSet{[Tag{name='region', value='US_EAST_1'}, Tag{name='provider', value='AWS'}, Tag{name='nodeType', value='ELECTABLE'}]}, roundTripTime=60.4 ms, state=CONNECTED}]
23:41:53.203 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-01-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.cluster - Checking status of cluster0-shard-00-01-vrzo2.mongodb.net:27017
23:41:53.204 [cluster-ClusterId{value='5d25262bba2897b3082238a4', description='null'}-cluster0-shard-00-01-vrzo2.mongodb.net:27017] DEBUG org.mongodb.driver.protocol.command - Sending command '{ "ismaster" : 1, "$db" : "admin", "

Теперь, честно говоря, я не очень уверен, откуда возникла проблема, но я сделал несколько вещей, склоняя свое предположение к Монго в качестве источника.

  • В режиме отладки я подтвердил, что идентификатор объекта класса MongoDataBaseProvider , который попадает в код src, совпадает с идентификатором, который получает mockDbProvider.close Мне было интересно, создал ли по какой-то причине Finatra Injector отдельный экземпляр. Оказывается, это не тот случай.

  • Я добавил дополнительное падение .close () в функцию afterEach. 

         override def afterEach(): Unit = {
        mockDBProvider.close
     }

    Обычно добавление этого должно приводить к вызову afterAll () с ошибкой. Потому что не будет открытого соединения для закрытия. К моему удивлению, это не так. Поэтому я вошел в MongoAtlas, чтобы посмотреть, есть ли какие-либо показатели. Я понял, что количество соединений отрицательно, как показано ниже. Разумным объяснением этого является то, что второй вызов .close () был выполнен, в результате чего показатели при каждом запуске теста становятся ниже нуля.

enter image description here

Мне любопытно, если я прекращаю это неправильно или кто-то еще столкнулся с этой проблемой.

P.S. Об этом обратились в службу поддержки Mongo, ожидая ответа

1 Ответ

0 голосов
/ 10 июля 2019

глупо с моей стороны.Оказывается, проблема была в основном с Finatra (хотя я не уверен, почему Mongo не выдавал никаких ошибок).

Проблема была вызвана набором тестов запуска, а не тестами функций.Я предполагал, что тест запуска «изящно» отключит встроенный сервер и запустит очистку.Оказывается, не тот случай.Добавление этого решает проблему с тестом запуска 

  override protected def afterAll() = {
    server.close()
  }
...