Exception while polling query (QUERY): MongoError: connection (NUMBER) to (MONGODB) closed #9135

raphaelarias · 2017-09-26T15:07:01Z

I've checked every issue and post in the Meteor forum, but It was not quite like this error.

Sometimes Meteor may try to query the DB but the connection is closed, so it will log an error:

meteor/packages/mongo/polling_observe_driver.js

Line 175 in d93c021

Meteor._debug("Exception while polling query " +

The app although the failed attempt keeps working (I can see login attempts in the log), my app keeps on 'Loading'.

I'm getting this almost every day, for some reason. The mongo connection string has the replicas sets too, and sometimes this occur when Mongo just elected a new primary.

Meteor version 1.5.
Ubuntu: Galaxy.
DB: Atlas

Would you have any idea what can it be, or how could I create a repo to simulate this part of the observe driver?

I think that even if Meteor is not crashing the software, something is stopping working.

PS: It stays "Loading" because the Meteor.loggingIn() does not change to false, even if the login has finished (it only happens after this error).

hwillson · 2017-09-26T16:01:34Z

Are these normally long running queries @raphaelarias? Maybe your connection is timing out for some reason, before the query has completed? Or the connection is being reclaimed by the connection pool a bit early? You could try playing around with your Mongo connection settings a bit, using Mongo.setConnectionOptions (maybe try tweaking your poolSize, connectTimeoutMS, etc.).

raphaelarias · 2017-09-26T16:10:15Z

Awesome, I'll take a look on those. This queries are supposed to be very small, and they have indexes too. I was trying to find the root of the problem, as when that happens my app keeps on "Loading" so my users don't have access. I discovered that, all the publications are working, but the flag on Meteor.isLoggingIn() never changes to true. I'm deleting this validation on my Blaze layout, and ill test. Do you think could be something related?

…

________________________________ From: Hugh Willson <notifications@github.com> Sent: Tuesday, September 26, 2017 1:06 PM To: meteor/meteor Cc: Raphael Arias; Mention Subject: Re: [meteor/meteor] Exception while polling query (QUERY): MongoError: connection (NUMBER) to (MONGODB) closed (#9135) Are these normally long running queries @raphaelarias<https://github.com/raphaelarias>? Maybe your connection is timing out for some reason, before the query has completed? Or the connection is being reclaimed by the connection pool a bit early? You could try playing around with your Mongo connection settings<http://mongodb.github.io/node-mongodb-native/2.2/reference/connecting/connection-settings/> a bit, using Mongo.setConnectionOptions<https://github.com/meteor/meteor/blob/d93c021c896029d774ccecc7241ff20ec4045568/packages/mongo/connection_options.js#L7> (maybe try tweaking your poolSize, connectTimeoutMS, etc.). — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub<#9135 (comment)>, or mute the thread<https://github.com/notifications/unsubscribe-auth/AExrJljeykPJTNJI1vLxmk2oXOjFL7__ks5smSAvgaJpZM4PkZ2W>.

raphaelarias · 2017-10-03T16:47:21Z

I double checked.

These queries are not long running, it usually happens when there is new primary elected (not always thought).

Maybe MongoDB drops the connection (some) when electing a new primary or time out.

Every publication and method still works.

The only very weird thing that doesn't is the Meteor.logginIn().

Is there any way to simulate this exception in dev?

maxfi · 2017-10-16T05:10:21Z

@raphaelarias I seem to be experiencing the same issue with:

METEOR@1.5.2.2
Meteor Galaxy
MongoDB Atlas

I have 3 meteor apps connected to the same replica set and when the replica set elects a new primary all 3 apps become partially unresponsive. That is, long running subscriptions don't show updates on the client and method calls that try to insert/update to the database seem to just hang.

Strangely though only one of the 3 apps shows an error:

Got exception while reading last entry: MongoError: connection 39 to {{ATLAS_DB_URL}}:27017 closed

Restarting the galaxy containers disconnects clients and once the containers are restarted the clients reconnect and the long running subscriptions update again and incomplete method calls successfully complete. The apps continue to operate correctly until the replica set elects a new primary.

Were you able to make any progress on this @raphaelarias?

abernix · 2017-10-16T09:47:03Z

@maxfi What version of the npm-mongo package are you using? There have been some updates in the more recent versions of that package (which simply wraps the mongodb npm) specifically solving failover recovery. See #8598 for more information, and to see whether it might apply to you. Either way, I'd likely recommend an update to npm-mongo if you're not running the latest: meteor update npm-mongo in a Meteor application should do the trick!

maxfi · 2017-10-16T13:53:32Z

@abernix you beat me to it! I just came across #8598 and was going to mention it here. The 3 apps of mine that were affected all depend on npm-mongo@2.2.30. Running a meteor update npm-mongo updates to npm-mongo@2.2.33. I'll try to force the replica set to elect a new primary (just need to figure out how to do that on atlas) on both npm-mongo@2.2.30 and npm-mongo@2.2.33 to confirm and will report back. Thanks!

raphaelarias · 2017-10-16T14:05:42Z

Awesome. I'll update the package (and Meteor) too and test it. It's worth mentioning that, I tried forcing an election, but the problem does not always happen (Since I opened the issue it never happened again).

raphaelarias · 2017-10-16T14:06:53Z

@abernix This may help: https://docs.mongodb.com/manual/tutorial/force-member-to-be-primary/

You can do via the shell.

maxfi · 2017-10-18T20:56:01Z

@raphaelarias Since the MongoDB Atlas service is designed to be fully managed and is responsible for all the cluster administration, Atlas users won't have access to cluster administration commands such as rs.stepDown. However, you can use Test Failover for the test.

hwillson · 2017-12-01T18:00:34Z

Is anyone here still encountering this issue with npm-mongo version 2.2.33? I'll assume this issue has been resolved by the changes put in place to address #8598, but definitely let me know otherwise. Thanks!

schiefferstudios · 2017-12-29T18:59:52Z

I just encountered this error:

Exception while polling query {"collectionName" ...

I am using:

Meteor @1.6.0.1
npm-mongo @2.2.33
minimongo @1.4.3
mongo @1.3.1

It is the first time I am seeing meteor crash on my digital ocean droplet, I recovered by restarting the server

schiefferstudios · 2017-12-29T19:00:25Z

@hwillson ^^^

abernix · 2018-01-05T01:17:50Z

@schiefferstudios Is there more to that error message? Feel free to redact any sensitive information (like the selector or options), but keep in mind that the information after that is helpful, including the full stack trace on the lines after the error message!

schiefferstudios · 2018-01-21T23:35:29Z

Hi, apologies for delayed response, I think I may have found what the issue was - looks like I may be running out of memory - see below

...
2018-01-21T22:36:06.870+0000 I COMMAND [conn2] command meteor.principals command: find { find: "principals", filter: { $or: [ { dataId: "H6Sj....
2018-01-21T22:36:07.330+0000 F - [conn3] out of memory.

0x5590577426fa 0x559057741dd9 0x5590576b12c1 0x559056a033e7 0x5590574e2c05 0x559056bfdd7e 0x559056bff565 0x55905722fd56 0x559056e2609c 0x559056e2851e 0x559056a05302 0x559056a05c2d 0x5590576abdc8 0x7f25065117fc 0x7f250623eb0f
----- BEGIN BACKTRACE -----
{"backtrace":[{"b":"559056296000","o":"14AC6FA","s":"_ZN5mongo15printStackTra
...

milianoo · 2018-10-11T08:19:21Z

I am experiencing the same issue on Meteor 1.6.1 and as of the last comment, no memory issue and also no error on mongodb server.

Exception while polling query {"collectionName":"*****","selector":{},"options":{}}: MongoError: cursor id ****** not found
at Function.MongoError.create (/Users/milianoo/.meteor/packages/npm-mongo/.2.2.34.fdnyzh.ihgj4++os+web.browser+web.cordova/npm/node_modules/mongodb-core/lib/error.js:31:11)
at /Users/milianoo/.meteor/packages/npm-mongo/.2.2.34.fdnyzh.ihgj4++os+web.browser+web.cordova/npm/node_modules/mongodb-core/lib/connection/pool.js:497:72
at authenticateStragglers (/Users/milianoo/.meteor/packages/npm-mongo/.2.2.34.fdnyzh.ihgj4++os+web.browser+web.cordova/npm/node_modules/mongodb-core/lib/connection/pool.js:443:16)
at Connection.messageHandler (/Users/milianoo/.meteor/packages/npm-mongo/.2.2.34.fdnyzh.ihgj4++os+web.browser+web.cordova/npm/node_modules/mongodb-core/lib/connection/pool.js:477:5)
at Socket.<anonymous> (/Users/milianoo/.meteor/packages/npm-mongo/.2.2.34.fdnyzh.ihgj4++os+web.browser+web.cordova/npm/node_modules/mongodb-core/lib/connection/connection.js:363:20)
at emitOne (events.js:116:13)
at Socket.emit (events.js:211:7)
at addChunk (_stream_readable.js:263:12)
at readableAddChunk (_stream_readable.js:250:11)
at Socket.Readable.push (_stream_readable.js:208:10)
at TCP.onread (net.js:607:20)

cmkramer · 2018-10-23T14:00:12Z

Same here, on a very basic query, looking into a collection with only 105 records and 153kb of data:

Exception while polling query {"collectionName":"game-sessions","selector":{},"options":{"transform":null,"fields":{"players.sessions":0}}} { MongoError: cursor id 247569748781 not found 
    at /app/.meteor/heroku_build/app/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:598:61 
    at authenticateStragglers (/app/.meteor/heroku_build/app/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:516:16) 
    at Connection.messageHandler (/app/.meteor/heroku_build/app/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:552:5) 
    at emitMessageHandler (/app/.meteor/heroku_build/app/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/connection.js:309:10) 
    at Socket.<anonymous> (/app/.meteor/heroku_build/app/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/connection.js:452:17) 
    at emitOne (events.js:116:13) 
    at Socket.emit (events.js:211:7) 
    at addChunk (_stream_readable.js:263:12) 
    at readableAddChunk (_stream_readable.js:250:11) 
    at Socket.Readable.push (_stream_readable.js:208:10) 
    at TCP.onread (net.js:597:20) 
 => awaited here: 
    at Function.Promise.await (/app/.meteor/heroku_build/app/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12) 
    at Promise.asyncApply (packages/mongo/mongo_driver.js:1034:11) 
    at /app/.meteor/heroku_build/app/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40 
 => awaited here: 
    at Promise.await (/app/.meteor/heroku_build/app/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:60:12) 
    at SynchronousCursor._nextObject (packages/mongo/mongo_driver.js:1083:12) 
    at SynchronousCursor.forEach (packages/mongo/mongo_driver.js:1097:22) 
    at SynchronousCursor.getRawObjects (packages/mongo/mongo_driver.js:1146:12) 
    at PollingObserveDriver._pollMongo (packages/mongo/polling_observe_driver.js:153:44) 
    at Object.task (packages/mongo/polling_observe_driver.js:90:12) 
    at Meteor._SynchronousQueue.SQp._run (packages/meteor.js:872:16) 
    at packages/meteor.js:849:12 
  name: 'MongoError', 
  message: 'cursor id 247569748781 not found', 
  ok: 0, 
  errmsg: 'cursor id 247569748781 not found', 
  code: 43, 
  codeName: 'CursorNotFound', 
  operationTime: Timestamp { _bsontype: 'Timestamp', low_: 1, high_: 1540288912 }, 
  '$clusterTime':  
   { clusterTime: Timestamp { _bsontype: 'Timestamp', low_: 1, high_: 1540288912 }, 
     signature: { hash: [Object], keyId: [Object] } } }

I'm utterly puzzled as to what is causing this, but it probably has something to do with a write action as mentioned before. A single document in the collection is updated on a refresh of the page, and is broadcasted to who-ever listens at that time, but it is most of the time limited to less than 5 active connections.

Version info:

npm-mongo@3.0.7
mongo@1.5.0
meteor@1.9.0

Running on a Heroku node, connected to an mLab mongo instance.

paulincai · 2021-02-17T09:40:32Z

Years later, Meteor 2.0 with Atlas

[server-internal] Exception while polling query {"collectionName":"usersSessions","selector":{},"options":{"transform":null}}: Pool was force destroyed

Sergeyamir · 2021-02-22T19:29:59Z

The same problem, log from galaxy.meteor.com:

... 
Exception while polling query {"collectionName":"mls","selector":{},"options":{"transform":null}} MongoError: Pool was force destroyed
cx9w32021-02-22 20:22:56+03:00 at Pool.destroy (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/core/connection/pool.js:678:21)
cx9w32021-02-22 20:22:56+03:00 at Server.destroy (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/core/topologies/server.js:902:15)
cx9w32021-02-22 20:22:56+03:00 at ReplSetState.update (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/core/topologies/replset_state.js:558:18)
cx9w32021-02-22 20:22:56+03:00 at /app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/core/topologies/replset.js:466:36
cx9w32021-02-22 20:22:56+03:00 at /app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/core/connection/pool.js:404:18
cx9w32021-02-22 20:22:56+03:00 at processTicksAndRejections (internal/process/task_queues.js:79:11)
cx9w32021-02-22 20:22:56+03:00 => awaited here:
cx9w32021-02-22 20:22:56+03:00 at Function.Promise.await (/app/bundle/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)
cx9w32021-02-22 20:22:56+03:00 at packages/mongo/mongo_driver.js:1073:14
cx9w32021-02-22 20:22:56+03:00 at /app/bundle/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40
cx9w32021-02-22 20:22:56+03:00 => awaited here:
cx9w32021-02-22 20:22:56+03:00 at Promise.await (/app/bundle/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:60:12)
cx9w32021-02-22 20:22:56+03:00 at SynchronousCursor._nextObject (packages/mongo/mongo_driver.js:1122:38)
cx9w32021-02-22 20:22:56+03:00 at SynchronousCursor.forEach (packages/mongo/mongo_driver.js:1136:22)
cx9w32021-02-22 20:22:56+03:00 at SynchronousCursor.getRawObjects (packages/mongo/mongo_driver.js:1185:12)
cx9w32021-02-22 20:22:56+03:00 at PollingObserveDriver._pollMongo (packages/mongo/polling_observe_driver.js:156:44)
cx9w32021-02-22 20:22:56+03:00 at Object.task (packages/mongo/polling_observe_driver.js:93:12)
cx9w32021-02-22 20:22:56+03:00 at Meteor._SynchronousQueue.SQp._run (packages/meteor.js:917:16)
cx9w32021-02-22 20:22:56+03:00 at packages/meteor.js:894:12 {
cx9w32021-02-22 20:22:56+03:00 name: 'MongoError',
cx9w32021-02-22 20:22:56+03:00 [Symbol(mongoErrorContextSymbol)]: {}
cx9w32021-02-22 20:22:56+03:00}
cx9w32021-02-22 20:22:56+03:00Exception while polling query {"collectionName":"users","selector":{"_id":"X5wvvmGdqPZrHhmMA","services.resume.loginTokens.hashedToken":"WuvQsn/GWL/OY9KI5A****="},"options":{"transform":null,"fields":{"_id":1}}} MongoError: Pool was force destroyed

and further down the cycle...

santiagopuentep · 2021-03-26T23:29:20Z

Same here. @paulincai @Sergeyamir were you able to fix it?

Sergeyamir · 2021-03-27T06:07:57Z

Not fixed yet. I tried a little to distribute the calls to the database in time (put a delay between calls where there was a problem), and now it happens rarely, 0-1 times a month. It's not good enough, but I don't know how to fix it completely.

santiagopuentep · 2021-03-31T14:28:17Z

I was in MongoDB Atlas' free shared cluster and moving to a dedicated cluster seems to have solved the issue. Maybe it's an Atlas thing.

hwillson added the Project:Mongo Driver label Sep 26, 2017

hwillson closed this as completed Dec 1, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Exception while polling query (QUERY): MongoError: connection (NUMBER) to (MONGODB) closed #9135

Exception while polling query (QUERY): MongoError: connection (NUMBER) to (MONGODB) closed #9135

raphaelarias commented Sep 26, 2017 •

edited

hwillson commented Sep 26, 2017

raphaelarias commented Sep 26, 2017 via email

raphaelarias commented Oct 3, 2017

maxfi commented Oct 16, 2017

abernix commented Oct 16, 2017

maxfi commented Oct 16, 2017

raphaelarias commented Oct 16, 2017

raphaelarias commented Oct 16, 2017

maxfi commented Oct 18, 2017

hwillson commented Dec 1, 2017 •

edited by klaussner

schiefferstudios commented Dec 29, 2017 •

edited

schiefferstudios commented Dec 29, 2017

abernix commented Jan 5, 2018

schiefferstudios commented Jan 21, 2018 •

edited

milianoo commented Oct 11, 2018 •

edited

cmkramer commented Oct 23, 2018 •

edited

paulincai commented Feb 17, 2021

Sergeyamir commented Feb 22, 2021

santiagopuentep commented Mar 26, 2021

Sergeyamir commented Mar 27, 2021

santiagopuentep commented Mar 31, 2021

Exception while polling query (QUERY): MongoError: connection (NUMBER) to (MONGODB) closed #9135

Exception while polling query (QUERY): MongoError: connection (NUMBER) to (MONGODB) closed #9135

Comments

raphaelarias commented Sep 26, 2017 • edited

hwillson commented Sep 26, 2017

raphaelarias commented Sep 26, 2017 via email

raphaelarias commented Oct 3, 2017

maxfi commented Oct 16, 2017

abernix commented Oct 16, 2017

maxfi commented Oct 16, 2017

raphaelarias commented Oct 16, 2017

raphaelarias commented Oct 16, 2017

maxfi commented Oct 18, 2017

hwillson commented Dec 1, 2017 • edited by klaussner

schiefferstudios commented Dec 29, 2017 • edited

schiefferstudios commented Dec 29, 2017

abernix commented Jan 5, 2018

schiefferstudios commented Jan 21, 2018 • edited

milianoo commented Oct 11, 2018 • edited

cmkramer commented Oct 23, 2018 • edited

paulincai commented Feb 17, 2021

Sergeyamir commented Feb 22, 2021

santiagopuentep commented Mar 26, 2021

Sergeyamir commented Mar 27, 2021

santiagopuentep commented Mar 31, 2021

raphaelarias commented Sep 26, 2017 •

edited

hwillson commented Dec 1, 2017 •

edited by klaussner

schiefferstudios commented Dec 29, 2017 •

edited

schiefferstudios commented Jan 21, 2018 •

edited

milianoo commented Oct 11, 2018 •

edited

cmkramer commented Oct 23, 2018 •

edited