No data inserted during start of Play application (using Play 2.4 and reactivemongo 11.11)

[Romain Chivot]

Original post : http://stackoverflow.com/questions/37275861/no-data-inserted-during-start-of-play-application-using-play-2-4-and-reactivemo

We're using Play Framework 2.4 with mongodb 2.6. But since we migrated reactivemongo from 0.11.10 to 0.11.11-play24, something is wrong.

We're loading some data into mongodb during the start of the application. Everything looks fine, the application started, no errors occurred in the logs but no data were inserted in database.

Here is the code for the start of the application in Global.scala :

override def onStart(app: Application) {
   Logger.info("creating object in database...")
   someProducts.foreach{ product =>
     ProductDB.insertOrUpdate(product._id, product)
   }
}

To inject reactivemongo, we decided to not use the @Inject() for the moment, so we're using current.injector instead (according to the Reactivemongo documentation). NB : we totally removed every trace of ReactiveMongoPlugin since it's deprecated in play-reactivemongo 0.11.11-play24.

Here we define our model and we inject ReactiveMongo :

abstract class MongoDB[T: Format, ID: Format] {
   def collection: JSONCollection

   def insertOrUpdate( _id: ID, o: T) = collection.update(Json.obj("_id" -> _id), o, upsert = true)
}

object ProductDB extends MongoDB[Product, String] {
  override def collection = current.injector.instanceOf[ReactiveMongoApi].db.collection("products")
}

In application.conf, ReactiveMongoModule is enabled with this line : play.modules.enabled += "play.modules.reactivemongo.ReactiveMongoModule"




Logs of the app :

[debug] p.a.l.c.ActorSystemProvider - Starting application default Akka system: application
[info] application - starting coruscant, build at: 2016-05-17T13:00:18+0200
[info] application - creating object in database...
[info] application - ReactiveMongoApi starting...
[info] application - ReactiveMongoApi successfully configured with DB 'coruscant'! Servers:
[localhost:27017]
[info] play.api.Play - Application started (Dev)

And here is the logs from mongodb :

2016-05-17T13:00:27.774+0200 [initandlisten] connection accepted from 127.0.0.1:65478 #3 (1 connection now open)
2016-05-17T13:00:27.833+0200 [conn3] run command admin.$cmd { ismaster: 1 }
2016-05-17T13:00:27.833+0200 [conn3] command admin.$cmd command: isMaster { ismaster: 1 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:178 0ms
2016-05-17T13:00:27.880+0200 [initandlisten] connection accepted from 127.0.0.1:65479 #4 (2 connections now open)
2016-05-17T13:00:27.880+0200 [initandlisten] connection accepted from 127.0.0.1:65480 #5 (3 connections now open)
2016-05-17T13:00:27.880+0200 [initandlisten] connection accepted from 127.0.0.1:65481 #6 (4 connections now open)
2016-05-17T13:00:27.880+0200 [initandlisten] connection accepted from 127.0.0.1:65482 #7 (5 connections now open)
2016-05-17T13:00:27.880+0200 [initandlisten] connection accepted from 127.0.0.1:65483 #8 (6 connections now open)
2016-05-17T13:00:27.881+0200 [initandlisten] connection accepted from 127.0.0.1:65484 #9 (7 connections now open)
2016-05-17T13:00:27.881+0200 [initandlisten] connection accepted from 127.0.0.1:65485 #10 (8 connections now open)
2016-05-17T13:00:27.881+0200 [initandlisten] connection accepted from 127.0.0.1:65486 #11 (9 connections now open)
2016-05-17T13:00:27.882+0200 [initandlisten] connection accepted from 127.0.0.1:65487 #12 (10 connections now open)
2016-05-17T13:00:27.888+0200 [conn3] run command admin.$cmd { ismaster: 1 }
2016-05-17T13:00:27.888+0200 [conn3] command admin.$cmd command: isMaster { ismaster: 1 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:178 0ms
2016-05-17T13:00:27.888+0200 [conn3] run command admin.$cmd { ismaster: 1 }
2016-05-17T13:00:27.889+0200 [conn3] command admin.$cmd command: isMaster { ismaster: 1 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:178 0ms
2016-05-17T13:00:27.889+0200 [conn3] run command admin.$cmd { ismaster: 1 }
2016-05-17T13:00:27.889+0200 [conn3] command admin.$cmd command: isMaster { ismaster: 1 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:178 0ms
2016-05-17T13:00:27.889+0200 [conn3] run command admin.$cmd { ismaster: 1 }
2016-05-17T13:00:27.889+0200 [conn3] command admin.$cmd command: isMaster { ismaster: 1 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:178 0ms
2016-05-17T13:00:27.889+0200 [conn3] run command admin.$cmd { ismaster: 1 }
2016-05-17T13:00:27.889+0200 [conn3] command admin.$cmd command: isMaster { ismaster: 1 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:178 0ms
2016-05-17T13:00:27.890+0200 [conn3] run command admin.$cmd { ismaster: 1 }
2016-05-17T13:00:27.890+0200 [conn3] command admin.$cmd command: isMaster { ismaster: 1 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:178 0ms
2016-05-17T13:00:27.890+0200 [conn3] run command admin.$cmd { ismaster: 1 }
2016-05-17T13:00:27.890+0200 [conn3] command admin.$cmd command: isMaster { ismaster: 1 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:178 0ms
2016-05-17T13:00:27.891+0200 [conn3] run command admin.$cmd { ismaster: 1 }
2016-05-17T13:00:27.891+0200 [conn3] command admin.$cmd command: isMaster { ismaster: 1 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:178 0ms
2016-05-17T13:00:27.891+0200 [conn3] run command admin.$cmd { ismaster: 1 }
2016-05-17T13:00:27.891+0200 [conn3] command admin.$cmd command: isMaster { ismaster: 1 } ntoreturn:1 keyUpdates:0 numYields:0  reslen:178 0ms

[Cédric Chantepie]

If there is no error, either your function is not called as you expect, or there is no matching doc to be updated. You should add some debug to check that.

[Romain Chivot]

I've added some logs inside this function.
Looks like one insert is performed before the real launch of the app, which doesn't sound good at all :/
What I do not understand is that my method is called, and since I'm using upsert=true, my Json should be inserted into database, but nothing happened, no call to mongodb...

def insertOrUpdate( _id: ID, o: T) = {
  println("* Will insert...")

  collection.update(Json.obj("_id" -> _id), o, upsert = true)
}

[info] application - creating objects in database...
* Will insert...

[info] application - ReactiveMongoApi starting...
[info] application - ReactiveMongoApi successfully configured with DB 'coruscant'! Servers:
[localhost:27017]

* Will insert...
* Will insert...
* Will insert...
* Will insert...

[info] play.api.Play - Application started (Dev)

Romain Chivot 2016-05-18 9:09 GMT+02:00 Cédric Chantepie : > If there is no error, either your function is not called as you expect, or there is no matching doc to be updated. You should add some debug to check that. > > -- > You received this message because you are subscribed to a topic in the Google Groups "ReactiveMongo - http://reactivemongo.org" group. > To unsubscribe from this topic, visit https://groups.google.com/d/topic/reactivemongo/Nsft75q699Y/unsubscribe. > To unsubscribe from this group and all its topics, send an email to reactivemong...@googlegroups.com. > For more options, visit https://groups.google.com/d/optout.

[Cédric Chantepie]

Have check the Future result there?

[Romain Chivot]

Yes, I've put a logger as well, nothing is displayed at all in the console :

override def onStart(app: Application) {
  Logger.info("creating object in database...")
  someProducts.foreach{ product =>

    ProductDB.insertOrUpdate(product._id, product).map { res =>
      println("* Res..." + res)
    }
  }
}

Romain Chivot

2016-05-18 13:49 GMT+02:00 Cédric Chantepie <chantep...@gmail.com>:

Have check the Future result there?

--

[Cédric Chantepie]

map is not a combinator to used to check a Future. If it's not mapped, the Future is failed. You should check the failure.

[Romain Chivot]

Yes, indeed. So, here's what I get when I try to recover the Future :

override def onStart(app: Application) {
  Logger.info("creating object in database...")
  someProducts.foreach{ product =>

    ProductDB.insertOrUpdate(product._id, product) recover {
      case e: Throwable => println("** Failure ! " + e)
    }
  }
}

** Failure ! reactivemongo.core.errors.ConnectionNotInitialized: MongoError['Connection is missing metadata (like protocol version, etc.) The connection pool is probably being initialized.']
** Failure ! reactivemongo.core.errors.ConnectionNotInitialized: MongoError['Connection is missing metadata (like protocol version, etc.) The connection pool is probably being initialized.']
** Failure ! reactivemongo.core.errors.ConnectionNotInitialized: MongoError['Connection is missing metadata (like protocol version, etc.) The connection pool is probably being initialized.']
Connection isn't established yet, how can I avoid this ? I mean, is there a way to be totally sure that the connection is really established in this entry point ?

Romain Chivot

2016-05-18 20:41 GMT+02:00 Cédric Chantepie <chantep...@gmail.com>:

map is not a combinator to used to check a Future. If it's not mapped, the Future is failed. You should check the failure.

[Cédric Chantepie]

I guess you are using connection.db (deprecated) instead of connection.database.

[Romain Chivot]

In fact, I'm just using the reactivemongo-play plugin, which handles connection to database and so on. I'm not doing any configuration stuff to database or whatever.

The only thing I do is using current.injector.instanceOf[ReactiveMongoApi].db.collection.

For me, it's more an asynchronous problem during the initialization of the reactivemongo plugin.

Romain Chivot

2016-05-19 9:57 GMT+02:00 Cédric Chantepie <chantep...@gmail.com>:

I guess you are using connection.db (deprecated) instead of connection.database.

[Cédric Chantepie]

Nope. Even the plugin offer both .db (deprecated) and .database functions. Please use the right one.

[Romain Chivot]

Erf, I don't see any info about deprecated .db. Nothing in the docs, neither in the code...

I think you should update this doc, it could be clearer for everyone : http://reactivemongo.org/releases/0.11/documentation/tutorial/play2.html

So if I do understand, I need to call .database : 

current.injector.instanceOf[ReactiveMongoApi].database

Since it's now a Future[DefaultDB] instead of DefaultDB, I need to ensure that my Future is resolved to access to my collections and so on. Any idea / best practice on how to to do that properly ? (ex: Await ?)

Romain Chivot

2016-05-19 13:13 GMT+02:00 Cédric Chantepie <chantep...@gmail.com>:

Nope. Even the plugin offer both .db (deprecated) and .database functions. Please use the right one.

[Cédric Chantepie]

I recommend you read Scala doc/tutorial about how to use/compose Future.

[Romain Chivot]

Well, I recommend you to update your docs, really.

You guys are doing a good job workin' on your plugin, but please, be more explicit in your official website/docs/whatever.
There are still examples using this ".db" and no word saying it's deprecated or not in this version.

Anyway, thanks for the help, hope it will bring some clarity for other people getting lost.

I recommend you read Scala doc/tutorial about how to use/compose Future.