I run mongo 4.2.9 foreground with no change to logging settings. They come out as INFO level logs from mongod. I usually run with (mongod --dbpath /data/db --wiredTigerCacheSizeGB 2)
I don’t think I have see any errors in the log however I will do some investigating just in case.
Reactivemongo 1.0.0 – finally no more JSONCollection’s for me.
Mongod (ubuntu 18.04 WSL2 instance) – I’ll try a Windows native version to just in case.
--
You received this message because you are subscribed to the Google Groups "ReactiveMongo -
http://reactivemongo.org" group.
To unsubscribe from this group and stop receiving emails from it, send an email to
reactivemong...@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/reactivemongo/6bf71bc6-ec5e-4c99-a432-93271827d57dn%40googlegroups.com.
Exactly the same thing happens when running a Windows native mongo 4.4.x.
I turned on reactivemongo DEBUG logging and when my .tailable.awaitData cursor is being used, I get a high rate of request/responses on the reactivemongo/database system as suggested by these scala-side logs…
If there is a particular logger I could turn to DEBUG or TRACE, please suggest and I’ll give it a try.
2020-10-13 09:35:30,344 [debug] r.c.a.MongoDBSystem - [Supervisor-3/prod-copy] Received a request expecting a response (160440): reactivemongo.core.actors.ExpectingResponse@46e765b7
2020-10-13 09:35:30,345 [debug] r.c.a.MongoDBSystem - [Supervisor-3/prod-copy] Received a request expecting a response (160441): reactivemongo.core.actors.ExpectingResponse@46e765b7
2020-10-13 09:35:30,346 [debug] r.c.a.MongoDBSystem - [Supervisor-3/prod-copy] Received a request expecting a response (160442): reactivemongo.core.actors.ExpectingResponse@46e765b7
2020-10-13 09:35:30,347 [debug] r.c.a.MongoDBSystem - [Supervisor-3/prod-copy] Received a request expecting a response (160443): reactivemongo.core.actors.ExpectingResponse@46e765b7
2020-10-13 09:35:30,348 [debug] r.c.a.MongoDBSystem - [Supervisor-3/prod-copy] Received a request expecting a response (160444): reactivemongo.core.actors.ExpectingResponse@46e765b7
2020-10-13 09:35:30,349 [debug] r.c.a.MongoDBSystem - [Supervisor-3/prod-copy] Received a request expecting a response (160445): reactivemongo.core.actors.ExpectingResponse@46e765b7
2020-10-13 09:35:30,350 [debug] r.c.a.MongoDBSystem - [Supervisor-3/prod-copy] Received a request expecting a response (160446): reactivemongo.core.actors.ExpectingResponse@46e765b7
2020-10-13 09:35:30,350 [debug] r.c.a.MongoDBSystem - [Supervisor-3/prod-copy] Received a request expecting a response (160447): reactivemongo.core.actors.ExpectingResponse@46e765b7
2020-10-13 09:35:30,351 [debug] r.c.a.MongoDBSystem - [Supervisor-3/prod-copy] Received a request expecting a response (160448): reactivemongo.core.actors.ExpectingResponse@46e765b7
2020-10-13 09:35:30,352 [debug] r.c.a.MongoDBSystem - [Supervisor-3/prod-copy] Received a request expecting a response (160449): reactivemongo.core.actors.ExpectingResponse@46e765b7
2020-10-13 09:35:30,353 [debug] r.c.a.MongoDBSystem - [Supervisor-3/prod-copy] Received a request expecting a response (160450): reactivemongo.core.actors.ExpectingResponse@46e765b7
To view this discussion on the web visit https://groups.google.com/d/msgid/reactivemongo/BY5PR18MB3761EADD7C798A0E8C44236CCD070%40BY5PR18MB3761.namprd18.prod.outlook.com.
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/HFgX5IIK9NA/unsubscribe.
To unsubscribe from this group and all its topics, send an email to reactivemong...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/reactivemongo/BY5PR18MB3761111E9A116BF807C0B648CD040%40BY5PR18MB3761.namprd18.prod.outlook.com.
These logging statements on mongodb side and jvm side are coming a thousand a second which suggests to me that a thousand cursors per second are being created. Surely something is not as planned. Additionally, my WSL2 instance load average goes up to 250 which is crazy.
Would a sandbox replication of this be required to investigate more?
To view this discussion on the web visit https://groups.google.com/d/msgid/reactivemongo/CAFGeoOV%2BK_82%2Bm2KnQa3Wv0KE%2Bvzz-zam-Q9oHQvZfNmVA%3DcEA%40mail.gmail.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/reactivemongo/BY5PR18MB37617A2EA9D03F1D61E82927CD020%40BY5PR18MB3761.namprd18.prod.outlook.com.
The same thing happens on a Windows Native Mongo 4.4 instance. It is not just happening on WSL2.
To view this discussion on the web visit https://groups.google.com/d/msgid/reactivemongo/CAFGeoOWEcDddZ-xbtiE%3D%3DKhhNUTEkcccHddgtzUJsAYXqg2jKg%40mail.gmail.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/reactivemongo/BY5PR18MB37610FC0071573D956C9DC55CD030%40BY5PR18MB3761.namprd18.prod.outlook.com.
Thank you. I have a test case where I can *sometimes* reproduce it. So I haven’t gotten back to this particular “please help me” request.
From: reacti...@googlegroups.com <reacti...@googlegroups.com>
On Behalf Of Cédric Chantepie
Sent: Sunday, November 8, 2020 9:23 AM
To: ReactiveMongo - http://reactivemongo.org <reacti...@googlegroups.com>
Subject: Re: anyone using capped collections with tailable and awaitData?
I cannot reproduce locally with a simple use case.
--
You received this message because you are subscribed to the Google Groups "ReactiveMongo -
http://reactivemongo.org" group.
To unsubscribe from this group and stop receiving emails from it, send an email to
reactivemong...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/reactivemongo/a12ae594-b508-49c3-af78-25f2f4685e36n%40googlegroups.com.
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/HFgX5IIK9NA/unsubscribe.
To unsubscribe from this group and all its topics, send an email to reactivemong...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/reactivemongo/BY5PR18MB37617738D8E7F99A814FB388CDEA0%40BY5PR18MB3761.namprd18.prod.outlook.com.
Cédric,
As I am trying to reproduce this, I have come across what might be the “problem” in my situation. Thanks again for replying.
From: reacti...@googlegroups.com <reacti...@googlegroups.com>
On Behalf Of Cédric Chantepie
Sent: Sunday, November 8, 2020 9:23 AM
To: ReactiveMongo - http://reactivemongo.org <reacti...@googlegroups.com>
Subject: Re: anyone using capped collections with tailable and awaitData?
I cannot reproduce locally with a simple use case.
--
You received this message because you are subscribed to the Google Groups "ReactiveMongo -
http://reactivemongo.org" group.
To unsubscribe from this group and stop receiving emails from it, send an email to
reactivemong...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/reactivemongo/a12ae594-b508-49c3-af78-25f2f4685e36n%40googlegroups.com.
Cédric,
As I am trying to reproduce this, I have come across what might be the “problem” in my situation. Thanks again for replying.
- In Production, running behind a (google) load balancer (which has a timeout in this case of 2 minutes)
- Browser-side server-socket gets timed-out and re-opens the server-socket which creates a new tailable, awaitData, cappedCollection cursor
- The previous cursor never completes or times-out (even with a maxTimeMs value of 1 minute)
- Question,… is there a pattern/approach to having a tailable, awaitData cursor with a Timeout to make sure the cursor itself is gracefully-ish destroyed and would therefore propagate downstream and allow the next “poll” of my cappedCollection to not exhaust resources?
- Question,… is there any way to shutdown your example program (below) without a kill/ctrl-c?... maybe a poison-pill message as part of the documentSource stream?
- In Development, I am constantly making code-changes with Play recompiles and Play-App restarts.
- Is it possible that the tailable, awaitData cursor is “stuck” or never gets destroyed in this case?
This is mostly your example and it shows it (to me at least)
import scala.concurrent.Await
import scala.concurrent.ExecutionContext.Implicits.global
import scala.concurrent.duration._
import reactivemongo.api._
val drv = AsyncDriver()
val con = Await.result(drv.connect(List("localhost:27017")), 5.seconds)
val db = Await.result(con.database("foo"), 5.seconds)
import reactivemongo.api.bson._
import reactivemongo.akkastream.cursorProducer
val sys = akka.actor.ActorSystem()
// implicit val mat: Materializer = app.injector.instanceOf[Materializer]
// used the above to access to materializer in scalatest Spec.
// one below would not compile for me because of deprecations
implicit val mat = akka.stream.ActorMaterializer.create(sys)
val cName = "notifications"
val drop = db.collection(cName).drop()
Await.result(drop, 5.seconds)
val capped = db.collection(cName).createCapped(5 * 1024 * 1024, Option(5000))
Await.result(capped, 5.seconds)
val x = db.collection(cName)
.find(BSONDocument.empty)
.tailable
.awaitData
.cursor[BSONDocument]()
.documentSource()
.runWith(akka.stream.scaladsl.Sink.foreach { doc =>
println(
s"- ${BSONDocument pretty doc}")
})
Await.result(x, 10.seconds)
Running the above case which I started from your example you had sent in this group (granted I did this inside of a ScalaTest block), in the 10 seconds that the test runs for, 3500 cursors are produced when grepping output for “r.a.c.GenericQueryBuilder”.
From: reacti...@googlegroups.com <reacti...@googlegroups.com>
On Behalf Of Cédric Chantepie
To view this discussion on the web visit https://groups.google.com/d/msgid/reactivemongo/233c2248-25a5-44c7-8854-9f27686890fdn%40googlegroups.com.
Running the above case which I started from your example you had sent in this group (granted I did this inside of a ScalaTest block), in the 10 seconds that the test runs for, 3500 cursors are produced when grepping output for “r.a.c.GenericQueryBuilder”.
Fine, perhaps it doesn’t mean that a cursor is created – assumption on my part.
However, the current bahavior makes using a tailableCursor simply unusable (unless you have inserted documents and you never want the Actor to complete except with a Process kill). It pegs the CPU at 100% because of the tight looping of whatever it is doing. This behaviour caused an Atlas JVM to reboot because of the load or resource contention placed. This has taken down our production servers because of the GB’s of logging generated. Sure I can turn logging off but please please please consider this as a defect. It simply is NOT usable in the current state.
I am not sure how else to describe this.
From: reacti...@googlegroups.com <reacti...@googlegroups.com>
On Behalf Of Cédric Chantepie
Sent: Monday, November 23, 2020 1:03 PM
To: ReactiveMongo - http://reactivemongo.org <reacti...@googlegroups.com>
Subject: Re: anyone using capped collections with tailable and awaitData?
On Monday, 23 November 2020 at 16:59:27 UTC+1 br...@interpayments.com wrote:
--
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/HFgX5IIK9NA/unsubscribe.
To unsubscribe from this group and all its topics, send an email to
reactivemong...@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/reactivemongo/ad1ea0db-434d-4095-8101-9386a65f3206n%40googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/reactivemongo/BY5PR18MB37614158371713E91497C865CDFC0%40BY5PR18MB3761.namprd18.prod.outlook.com.
It isn’t the logging that is causing the load. I turned off logging and it still happens. CPU gets pegged immediately.
How can I convince you that something is wrong?
--
You received this message because you are subscribed to the Google Groups "ReactiveMongo -
http://reactivemongo.org" group.
To unsubscribe from this group and stop receiving emails from it, send an email to
reactivemong...@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/reactivemongo/CAFGeoOVWfAkcmjubo54_coanPM7EsEbv46c_dq%2B5sorw%3D5eLdA%40mail.gmail.com.
It isn’t the logging that is causing the load. I turned off logging and it still happens. CPU gets pegged immediately.
How can I convince you that something is wrong?
Certainly the tests that I wrote started with a clean collection and therefore the corner case you are describing. However, the alternative still fails and is unusable which is represented by a selector on the find which yields no results (which would always be the case when starting with a clean (dropped and then created) collection.
To get around this, on each call to my long-lived “connection”, I insert a record that will immediately be returned by the find(<date gte>).tailable.awaitData cursor. So for each iteration of my Browser/Client making a server-side-event call, it always immediately returns with an Event which is a filler/bogus/useless event that I have to insert to avoid catastrophic resource creation.
--
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/HFgX5IIK9NA/unsubscribe.
To unsubscribe from this group and all its topics, send an email to
reactivemong...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/reactivemongo/CAFGeoOXWkLpSrP3hAygDK1k7hEzAzMf%2BGPnW2omu7ZBnfvKr4Q%40mail.gmail.com.
Certainly the tests that I wrote started with a clean collection and therefore the corner case you are describing.
However, the alternative still fails and is unusable which is represented by a selector on the find which yields no results (which would always be the case when starting with a clean (dropped and then created) collection.
To get around this, on each call to my long-lived “connection”, I insert a record that will immediately be returned by the find(<date gte>).tailable.awaitData cursor. So for each iteration of my Browser/Client making a server-side-event call, it always immediately returns with an Event which is a filler/bogus/useless event that I have to insert to avoid catastrophic resource creation.