Meteor app crash randomly throwing a 'MongoError: server instance pool was destroyed' error


#1

I deployed a meteor app to a aws server using mup which used docker to deploy the app. I also used Mlab sandboxed db. The issue is, the app crash without warning after some time. Crashing means the app still work but data won’t load from the database. I have two versions of the app (staging and production) running in two different servers. But both have this issue. In the docker logs I see this error repeated a lot of times :

Exception in setInterval callback: MongoError: server instance pool was destroyed
    at Object.Future.wait (/bundle/bundle/programs/server/node_modules/fibers/future.js:446:16)
    at MongoConnection.<anonymous> (packages/meteor/helpers.js:119:1)
    at MongoConnection.(anonymous function) [as update] (packages/mongo/mongo_driver.js:771:49)
    at [object Object].update (packages/mongo/collection.js:589:29)
    at AccountsServer.Ap._expireTokens (packages/accounts-base/accounts_server.js:1100:14)
    at packages/accounts-base/accounts_server.js:1173:14
    at [object Object]._.extend.withValue (packages/meteor/dynamics_nodejs.js:56:1)
    at packages/meteor/timers.js:6:1
    at runWithEnvironment (packages/meteor/dynamics_nodejs.js:110:1)
    - - - - -
    at Function.MongoError.create (/bundle/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/error.js:29:11)
    at basicWriteValidations (/bundle/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/topologies/server.js:433:51)
    at [object Object].Server.update (/bundle/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/topologies/server.js:543:16)
    at [object Object].Server.update (/bundle/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/server.js:386:17)
    at updateDocuments (/bundle/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/collection.js:1037:19)
    at [object Object].Collection.update (/bundle/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/collection.js:1075:44)
    at MongoConnection._update (packages/mongo/mongo_driver.js:560:18)
    at MongoConnection.<anonymous> (packages/meteor/helpers.js:118:1)
    at MongoConnection.(anonymous function) [as update] (packages/mongo/mongo_driver.js:771:49)
    at [object Object].update (packages/mongo/collection.js:589:29)

Any idea what’s happening?


#2

The crash was it a ‘Server Crash - write after end’ by any chance?.. I’m seeing something similar in my logs, also no idea why, the system is not being used at the time of a crash.


#3

We are seeing this issue too: we are using Mongo DB 3.2.1 with metoer 1.4 it’s quite frequent over two servers about every 3-5 mins


#4

In the client browser console, I see this error WebSocket connection to 'wss://oursite.com/sockjs/373/2lrpal10/websocket' failed: WebSocket is closed before the connection is established.


#5

Stack trace for above:

Exception in setInterval callback: MongoError: server instance pool was destroyed at Object.Future.wait (D:\home\site\wwwroot\programs\server\node_modules\fibers\future.js:446:16) at MongoConnection. (packages/meteor/helpers.js:119:1) at MongoConnection.(anonymous function) [as update] (packages/mongo/mongo_driver.js:771:49) at [object Object].update (packages/mongo/collection.js:589:29) at AccountsServer.Ap.expireTokens (packages/accounts-base/accounts_server.js:1100:14) at packages/accounts-base/accounts_server.js:1173:14 at [object Object]..extend.withValue (packages/meteor/dynamics_nodejs.js:56:1) at packages/meteor/timers.js:6:1 at runWithEnvironment (packages/meteor/dynamics_nodejs.js:110:1) - - - - - at Function.MongoError.create (D:\home\site\wwwroot\programs\server\npm\node_modules\meteor\npm-mongo\node_modules\mongodb-core\lib\error.js:29:11) at basicWriteValidations (D:\home\site\wwwroot\programs\server\npm\node_modules\meteor\npm-mongo\node_modules\mongodb-core\lib\topologies\server.js:434:51) at [object Object].Server.update (D:\home\site\wwwroot\programs\server\npm\node_modules\meteor\npm-mongo\node_modules\mongodb-core\lib\topologies\server.js:545:16) at [object Object].Server.update (D:\home\site\wwwroot\programs\server\npm\node_modules\meteor\npm-mongo\node_modules\mongodb\lib\server.js:386:17) at updateDocuments (D:\home\site\wwwroot\programs\server\npm\node_modules\meteor\npm-mongo\node_modules\mongodb\lib\collection.js:1041:19) at [object Object].Collection.update (D:\home\site\wwwroot\programs\server\npm\node_modules\meteor\npm-mongo\node_modules\mongodb\lib\collection.js:1079:44) at MongoConnection._update (packages/mongo/mongo_driver.js:560:18) at MongoConnection. (packages/meteor/helpers.js:118:1) at MongoConnection.(anonymous function) [as update] (packages/mongo/mongo_driver.js:771:49) at [object Object].update (packages/mongo/collection.js:589:29) at AccountsServer.Ap.expireTokens (packages/accounts-base/accounts_server.js:1100:14) at packages/accounts-base/accounts_server.js:1173:14 at [object Object]..extend.withValue (packages/meteor/dynamics_nodejs.js:56:1) at packages/meteor/timers.js:6:1 at runWithEnvironment (packages/meteor/dynamics_nodejs.js:110:1)
severityLevel
1

I am seeing these issues in our failed request routing:

502 from our load balanacer

~\sockjs\566\8nybdr9g\websocket


#6

No love??

Can the MDG team please respond? We are getting errors from Meteor core and we want to know if should be concerned!


#7

Are you sure you’re getting the same error? (i.e. MongoError: server instance pool was destroyed)

Can you post your stack trace too?


It appears that the error is occurring within the accounts-base > expireTokens function.

What values do you all have set for loginExpirationInDays in your Accounts configuration?

What is the frequency for the rest of you?


#8

I’ve commented a stack trace in this github issue:


#9

We just ran into this issue on Meteor Galaxy, also updated to the new Meteor version earlier this week. The bug started coming up for the first time today. Our database is provided by a Sandbox cluster on MongoLabs, which doesn’t provide any redundancy – is there a chance this is happening because they temporarily took down our database? It’s certainly up now and the app is stuck in this crash cycle, not sure what to do to get up and running again.

Help!!

EDIT: We’re also users of Kadira, and our stack trace includes references to one of its collections – maybe that’s connected?

MongoError: server instance pool was destroyed
    at Object.Future.wait (/app/bundle/programs/server/node_modules/fibers/future.js:446:16)
    at MongoConnection.<anonymous> (packages/meteor/helpers.js:119:1)
    at MongoConnection.(anonymous function) (packages/mongo/mongo_driver.js:771:49)
    at [object Object].remove (packages/mongo/collection.js:624:29)
    at _cleanStaleResults (packages/oauth/pending_credentials.js:30:1)
    at [object Object]._.extend.withValue (packages/meteor/dynamics_nodejs.js:56:1)
    at packages/meteor/timers.js:6:1
    at runWithEnvironment (packages/meteor/dynamics_nodejs.js:110:1)
    - - - - -
    at Function.MongoError.create (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/error.js:29:11)
    at basicWriteValidations (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/topologies/server.js:433:51)
    at [object Object].Server.remove (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/topologies/server.js:574:16)
    at [object Object].Server.remove (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/server.js:393:17)
    at removeDocuments (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/collection.js:1227:19)
    at [object Object].Collection.remove (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/collection.js:1267:44)
    at MongoConnection._remove (packages/mongo/mongo_driver.js:417:16)
    at MongoConnection.kadira_MongoConnection_remove [as _remove] (packages/meteorhacks_kadira/lib/hijack/set_labels.js:29:1)
    at MongoConnection.<anonymous> (packages/meteor/helpers.js:118:1)
    at MongoConnection.(anonymous function) (packages/mongo/mongo_driver.js:771:49)

EDIT 2: After going back through the logs, it looks like the first exception started when our MongoDB set couldn’t be reached. We got a bunch of versions of the error below on different queries from different collections, every error appearing at the same moment, then started getting the “server instance pool was destroyed” error about 30 seconds later (and every minute since then). Anyone got any ideas? Is this a consequence of using the MLab Sandbox on production? Is there a way to rescue the app? The database is now accessible, I’ve checked from the terminal.

9nje
2016-09-28 16:48:51-04:00Exception while polling query {"collectionName":"users","selector":{"_id":{"$in":["RhDbqYQ7x8W4h27zT","iaXx5esvQ5hQi4v97","mtanBuMzEmnkYN47N","kgQZfkQiZJuJcEsQc"]}},"options":{"transform":null}}: MongoError: failed to reconnect after 30 attempts with interval 1000 ms
9nje
2016-09-28 16:48:51-04:00 at Object.Future.wait (/app/bundle/programs/server/node_modules/fibers/future.js:449:15)
9nje
2016-09-28 16:48:51-04:00 at SynchronousCursor._nextObject (packages/mongo/mongo_driver.js:1021:47)
9nje
2016-09-28 16:48:51-04:00 at SynchronousCursor.forEach (packages/mongo/mongo_driver.js:1055:22)
9nje
2016-09-28 16:48:51-04:00 at SynchronousCursor.getRawObjects (packages/mongo/mongo_driver.js:1104:12)
9nje
2016-09-28 16:48:51-04:00 at PollingObserveDriver._pollMongo (packages/mongo/polling_observe_driver.js:152:48)
9nje
2016-09-28 16:48:51-04:00 at PollingObserveDriver.proto._pollMongo (packages/meteorhacks_kadira/lib/hijack/wrap_observers.js:100:1)
9nje
2016-09-28 16:48:51-04:00 at Object.task (packages/mongo/polling_observe_driver.js:90:12)
9nje
2016-09-28 16:48:51-04:00 at [object Object]._.extend._run (packages/meteor/fiber_helpers.js:147:1)
9nje
2016-09-28 16:48:51-04:00 at packages/meteor/fiber_helpers.js:125:1
9nje
2016-09-28 16:48:51-04:00 - - - - -
9nje
2016-09-28 16:48:51-04:00 at [object Object].<anonymous> (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/pool.js:290:15)
9nje
2016-09-28 16:48:51-04:00 at emitTwo (events.js:87:13)
9nje
2016-09-28 16:48:51-04:00 at [object Object].emit (events.js:172:7)
9nje
2016-09-28 16:48:51-04:00 at Socket.<anonymous> (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb-core/lib/connection/connection.js:160:49)
9nje
2016-09-28 16:48:51-04:00 at Socket.g (events.js:260:16)
9nje
2016-09-28 16:48:51-04:00 at emitOne (events.js:77:13)
9nje
2016-09-28 16:48:51-04:00 at Socket.emit (events.js:169:7)
9nje
2016-09-28 16:48:51-04:00 at emitErrorNT (net.js:1269:8)
9nje
2016-09-28 16:48:51-04:00 at nextTickCallbackWith2Args (node.js:442:9)
9nje
2016-09-28 16:48:51-04:00 at process._tickCallback (node.js:356:17)

#10

Has anyone managed to reproduce this locally yet?

It sounds more and more like the mongo driver / Meteor not coping with disconnections / problems at the mongo end.

It might be more constructive to get into technical details on an issue, this one seems the same: https://github.com/meteor/meteor/issues/7822

If you are seeing this issue “MongoError: server instance pool was destroyed” can you please post the following information there:

  1. Mongo setup (are you using a DBaaS, if so which type/plan, if not what is your replicaset setup?)
  2. Which version of the mongo driver you have (which version of the npm-mongo package).

Hopefully a pattern will emerge and we can get a reproduction of this issue going, which will make it possible trace the problem to the mongo driver or Meteor’s wrapper.


#11

Our MongoDB instance is running on a VM in Azure as a single instance. No replica set. Version 3.2.1.

Here is my full list of packages for our project:

accounts-base@1.2.11
accounts-password@1.3.0
allow-deny@1.0.5
angular@1.3.11
angular-meteor-auth@1.0.3
angular-meteor-data@1.3.11
angular-templates@1.0.9
angular:angular@1.5.3_1
angular:angular-animate@1.5.3_1
angular:angular-sanitize@1.5.3_1
angularui:angular-ui-router@0.2.15
autoupdate@1.3.11
babel-compiler@6.9.1
babel-runtime@0.1.11
barbatus:typescript@0.4.1
barbatus:typescript-compiler@0.7.1_1
barbatus:typescript-runtime@0.1.2
base64@1.0.9
benjamine:jsondiffpatch@0.1.38_1
binary-heap@1.0.9
blaze@2.1.9
blaze-tools@1.0.10
boilerplate-generator@1.0.10
caching-compiler@1.1.7
caching-html-compiler@1.0.7
callback-hook@1.0.9
cfs:http-methods@0.0.32
check@1.2.3
civilframe:angular-jade@0.0.3
coffeescript@1.0.17
cosmos:browserify@0.8.4
dburles:mongo-collection-instances@0.3.5
ddp@1.2.5
ddp-client@1.3.1
ddp-common@1.2.6
ddp-rate-limiter@1.0.5
ddp-server@1.3.10
deanius:promise@3.1.3
deps@1.0.12
diff-sequence@1.0.6
ecmascript@0.5.8
ecmascript-runtime@0.3.14
ejson@1.0.12
email@1.1.17
fastclick@1.0.12
geojson-utils@1.0.9
hot-code-push@1.0.4
html-tools@1.0.11
htmljs@1.0.11
http@1.2.9
id-map@1.0.8
johnantoni:meteor-normalize@0.0.1
jquery@1.11.9
kyleking:customizable-bootstrap-stylus@3.6.3
kyleking:customizable-bootstrap-stylus-data@4.0.6
lai:collection-extensions@0.2.1_1
launch-screen@1.0.12
livedata@1.0.18
localstorage@1.0.11
logging@1.1.15
meteor@1.2.17
meteor-base@1.0.4
mgcrea:angular-strap@2.3.7
minifier-css@1.2.14
minifier-js@1.2.14
minifiers@1.1.7
minimongo@1.0.17
mobile-experience@1.0.4
mobile-status-bar@1.0.12
modules@0.7.6
modules-runtime@0.7.6
momentjs:moment@2.15.0
mongo@1.1.12
mongo-id@1.0.5
mquandalle:jade@0.4.9
mquandalle:jade-compiler@0.4.5
npm-bcrypt@0.9.1
npm-mongo@1.5.49
observe-sequence@1.0.12
ordered-dict@1.0.8
pbastowski:angular-babel@1.3.6
percolate:synced-cron@1.3.2
practicalmeteor:chai@2.1.0_1
practicalmeteor:loglevel@1.2.0_2
practicalmeteor:mocha@2.4.5_6
practicalmeteor:mocha-core@1.0.1
practicalmeteor:sinon@1.14.1_2
promise@0.8.7
random@1.0.10
rate-limit@1.0.5
reactive-dict@1.1.8
reactive-var@1.0.10
reload@1.1.10
retry@1.0.8
routepolicy@1.0.11
service-configuration@1.0.10
session@1.1.6
sgi:ui-mask@1.4.7
sha@1.0.8
shell-server@0.2.1
spacebars@1.0.13
spacebars-compiler@1.0.13
srp@1.0.9
standard-minifier-css@1.2.0
standard-minifier-js@1.2.0
stevezhu:lodash@4.15.0
stolinski:stylus-multi@1.4.3
templating@1.2.15
templating-compiler@1.2.15
templating-runtime@1.2.15
templating-tools@1.0.5
tmeasday:test-reporter-helpers@0.2.1
tracker@1.1.0
ui@1.0.12
underscore@1.0.9
urigo:static-html-compiler@0.1.8
url@1.0.10
vishalm:angular-toastr@1.5.0
webapp@1.3.11
webapp-hashing@1.0.9


#12

@tmeasday Thanks for jumping in!!


#13

@tmeasday I am going to come clean here: Just remembered we are using a logging adapter that consumes all console statements and sends them to our ApplicationInsights tracer / exception logs.

So what we maybe seeing is just an error, but we do not get to see an indication of recovery.

Food for thought


#14

@mspi - so you configure and run the mongo instance yourself?

Have you tried manually stopping the mongo instance or killing the network link to see if you can replicate the problem?


#15

@bretth Can you look at tmeasday’s request? I am not in the office today :slight_smile:


#16

@mspi can can definitely run a test for that.


#17

Having the same problem on local dev from time to time when loosing internet connection. Using mLab sandbox for local (no oplog url) development. I believe it has to do with the autoreconnect in the mongo driver (using 1.4.1.1).
THe mongo_url env variable looks like this

mongodb://user:password/dbName?readPreference=primary

#18

Hi @tmeasday, this began happening to me locally, a few times today - see the screenshot attached.

I’m not sure what initiates the error. I’m running on a Macbook and suddenly the fan would start running like crazy and the whole OS would freeze with exceptions of allowing me to click on my browser and code editor. Any OS menus/taskbar would be inaccessible. I was not able to scroll in terminal and that’s the only screenshot I have for now.


#19

It would be interesting to know if it was mongo or meteor that locked up your CPU… Perhaps you could leave a window running top open somewhere on screen and when things crashed you might see :slight_smile:


#20
 Exception in setInterval callback: MongoError: server instance pool was destroyed
     at Object.Future.wait (/Users/fabien/.meteor/packages/meteor-tool/.1.4.1_2.1jlej5l++os.osx.x86_64+web.browser+web.cordova/mt-os.osx.x86_64/dev_bundle/server-lib/node_modules/fibers/future.js:446:16)
     at MongoConnection.<anonymous> (packages/meteor/helpers.js:119:1)
     at MongoConnection.(anonymous function) [as remove] (packages/mongo/mongo_driver.js:771:49)
     at [object Object].remove (packages/mongo/collection.js:624:29)
     at _cleanStaleResults (packages/oauth/pending_credentials.js:30:1)
     at [object Object]._.extend.withValue (packages/meteor/dynamics_nodejs.js:56:1)
     at packages/meteor/timers.js:6:1
     at runWithEnvironment (packages/meteor/dynamics_nodejs.js:110:1)
     - - - - -
     at Function.MongoError.create (/Users/fabien/.meteor/packages/npm-mongo/.1.5.50.126i5ny++os+web.browser+web.cordova/npm/node_modules/mongodb-core/lib/error.js:29:11)
     at basicWriteValidations (/Users/fabien/.meteor/packages/npm-mongo/.1.5.50.126i5ny++os+web.browser+web.cordova/npm/node_modules/mongodb-core/lib/topologies/server.js:434:51)
     at [object Object].Server.remove (/Users/fabien/.meteor/packages/npm-mongo/.1.5.50.126i5ny++os+web.browser+web.cordova/npm/node_modules/mongodb-core/lib/topologies/server.js:578:16)
     at [object Object].Server.remove (/Users/fabien/.meteor/packages/npm-mongo/.1.5.50.126i5ny++os+web.browser+web.cordova/npm/node_modules/mongodb/lib/server.js:393:17)
     at removeDocuments (/Users/fabien/.meteor/packages/npm-mongo/.1.5.50.126i5ny++os+web.browser+web.cordova/npm/node_modules/mongodb/lib/collection.js:1232:19)
     at [object Object].Collection.remove (/Users/fabien/.meteor/packages/npm-mongo/.1.5.50.126i5ny++os+web.browser+web.cordova/npm/node_modules/mongodb/lib/collection.js:1272:44)
     at MongoConnection._remove (packages/mongo/mongo_driver.js:417:16)
     at MongoConnection.<anonymous> (packages/meteor/helpers.js:118:1)
     at MongoConnection.(anonymous function) [as remove] (packages/mongo/mongo_driver.js:771:49)
     at [object Object].remove (packages/mongo/collection.js:624:29)

Same Error here. Happening since today. Rolled back to 1.4.1 and it seems to work for now.

[Edit] : No it does not :frowning:

I did nothing special for the config.