search

marcello3d / node-mongolian

[project inactive] Mongolian DeadBeef is an awesome Mongo DB driver for node.js
https://groups.google.com/group/node-mongolian
zlib License
350 stars 50 forks source link

does not re-connect #34

Closed tcurdt closed 12 years ago

tcurdt commented 13 years ago

When mongodb gets restarted the node app loses the connection is no longer working. Mongolian should just re-connect in such an event.

andzdroid commented 13 years ago

This can be done by setting one of the serverConfig properties of the mongodb.Db instance:

db.serverConfig.connection.autoReconnect = true;

Unfortunately, I don't understand node-mongolian very well, and I can't see where and if there is an exposed mongodb.Db instance.

tcurdt commented 13 years ago

Maybe this could be done through

MongolianDB.prototype.eval

but I am not sure.

marcello3d commented 13 years ago

Mongolian DB doesn't use the mongodb-native Db class, so the above will not work. Mongolian DB should automatically reconnect automatically the next time you try to use it (though it doesn't currently proactively reconnect).

Can you give a test case of what's not working for you?

tcurdt commented 13 years ago

I guess this is more integration testing not sure how easy to put that into a test.

But this is how I can easily reproduce it

  1. start node and mongod
  2. make a request to an expressjs page that shows some data via mongolian - all good
  3. stop mongod
  4. start mongod
  5. reload the same page

Expected behavior: mongolian just re-connects to mongo Observed behavior: I get a 'not connected' exception

marcello3d commented 13 years ago

Ok, I made the following nodeunit test, ran it, then stopped my mongo server replicaset primary (I'm running two mongods and a mediator), and while it takes a few seconds to switch primaries and get connected again, it does eventually reconnect.

This process could probably be improved (automatically retry for x seconds before failing), but the current approach is pretty low-level and low-latency. Perhaps as part of the connection pooling work I can look into some options here.

var Mongolian = require("mongolian")

module.exports = {
    "rerun test":function(test) {
        var mongo = new Mongolian
        function foo() {
            mongo.dbNames(function(error,value) {
                console.log(new Date() + "value = "+value)
            })
            setTimeout(foo,1000)
        }
        foo()
    }
}

nodeunit test/reruntest.js

[debug] mongo://localhost:27017: Connected
[debug] mongo://localhost:27017: Initialized as secondary
[debug] mongo://localhost:27018: Connected
[debug] mongo://localhost:27018: Initialized as primary
[info] mongo://localhost:27018: Connected to primary
[debug] Finished scanning... primary? mongo://localhost:27018
[debug] mongo://localhost:27017: Disconnected
Fri Aug 12 2011 07:51:11 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:12 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:13 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:14 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:15 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:16 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:17 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:18 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:19 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:20 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:21 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:22 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:23 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:24 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:25 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:26 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
[debug] mongo://localhost:27018: Disconnected
[warn] mongo://localhost:27018: Lost primary
[debug] mongo://localhost:27017: Connected
[debug] mongo://localhost:27018: Disconnected
[error] mongo://localhost:27018: Error: ECONNREFUSED, Connection refused
[debug] mongo://localhost:27017: Initialized as secondary
[debug] Finished scanning... primary? no
Fri Aug 12 2011 07:51:27 GMT-0400 (EDT)value = undefined
[debug] mongo://localhost:27017: Disconnected
[debug] mongo://localhost:27017: Connected
[debug] mongo://localhost:27018: Disconnected
[error] mongo://localhost:27018: Error: ECONNREFUSED, Connection refused
[debug] mongo://localhost:27017: Initialized as secondary
[debug] Finished scanning... primary? no
Fri Aug 12 2011 07:51:28 GMT-0400 (EDT)value = undefined
[debug] mongo://localhost:27017: Disconnected
[debug] mongo://localhost:27017: Connected
[debug] mongo://localhost:27018: Disconnected
[error] mongo://localhost:27018: Error: ECONNREFUSED, Connection refused
[debug] mongo://localhost:27017: Initialized as secondary
[debug] Finished scanning... primary? no
Fri Aug 12 2011 07:51:29 GMT-0400 (EDT)value = undefined
[debug] mongo://localhost:27017: Disconnected
[debug] mongo://localhost:27017: Connected
[debug] mongo://localhost:27018: Disconnected
[error] mongo://localhost:27018: Error: ECONNREFUSED, Connection refused
[debug] mongo://localhost:27017: Initialized as secondary
[debug] Finished scanning... primary? no
Fri Aug 12 2011 07:51:30 GMT-0400 (EDT)value = undefined
[debug] mongo://localhost:27017: Disconnected
[debug] mongo://localhost:27017: Connected
[debug] mongo://localhost:27018: Disconnected
[error] mongo://localhost:27018: Error: ECONNREFUSED, Connection refused
[debug] mongo://localhost:27017: Initialized as secondary
[debug] Finished scanning... primary? no
Fri Aug 12 2011 07:51:31 GMT-0400 (EDT)value = undefined
[debug] mongo://localhost:27017: Disconnected
[debug] mongo://localhost:27017: Connected
[debug] mongo://localhost:27018: Disconnected
[error] mongo://localhost:27018: Error: ECONNREFUSED, Connection refused
[debug] mongo://localhost:27017: Initialized as secondary
[debug] Finished scanning... primary? no
Fri Aug 12 2011 07:51:32 GMT-0400 (EDT)value = undefined
[debug] mongo://localhost:27017: Disconnected
[debug] mongo://localhost:27017: Connected
[debug] mongo://localhost:27018: Connected
[debug] mongo://localhost:27017: Initialized as secondary
[debug] mongo://localhost:27017: Disconnected
[debug] mongo://localhost:27018: Initialized as secondary
[debug] Finished scanning... primary? no
Fri Aug 12 2011 07:51:33 GMT-0400 (EDT)value = undefined
[debug] mongo://localhost:27018: Disconnected
[debug] mongo://localhost:27017: Connected
[debug] mongo://localhost:27018: Connected
[debug] mongo://localhost:27017: Initialized as primary
[info] mongo://localhost:27017: Connected to primary
[debug] mongo://localhost:27018: Initialized as secondary
[debug] Finished scanning... primary? mongo://localhost:27017
[debug] mongo://localhost:27018: Disconnected
Fri Aug 12 2011 07:51:34 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:35 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:36 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:37 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:38 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:39 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:40 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:41 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:42 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:43 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
Fri Aug 12 2011 07:51:44 GMT-0400 (EDT)value = admin,local,mongolian_test,mongolian_trainer,nithub
tcurdt commented 13 years ago

Nice but that test case does not really resemble the situation. Try running this instead:

var Mongolian = require("mongolian")

   module.exports = {
       "rerun test":function(test) {
          var mongo = new Mongolian(),
              db = mongo.db('shop'),
              products = db.collection('products');

           console.log('new mongolian');
           function foo() {

              products.find().toArray(function(err, products) {
                if (err) {
                  console.log('failed to find');
                } else {
                  console.log('found ' + products.length);
                }
              });

             setTimeout(foo,1000)
           }
           foo()
       }
   }

and what I get is

test.js
new mongolian
mongo://localhost:27017: Connected
mongo://localhost:27017: Initialized as primary
mongo://localhost:27017: Connected to primary
Finished scanning... primary? mongo://localhost:27017
found 2
found 2
found 2
found 2
found 2
found 2
found 2
mongo://localhost:27017: Disconnected

.../node_modules/mongolian/node_modules/mongodb/lib/mongodb/connection.js:336
      throw err;   
      ^
notConnected
tcurdt commented 13 years ago

Please re-open, I don't have the permission to.

marcello3d commented 13 years ago

Ok, that looks pretty bad. Thanks for the test case.

0xfede commented 13 years ago

Hi, I think there's a problem is in server.js, at line 273, where you check for .value in a taxman object, which has no such property. Same on line 277: .value.close(). That way the lost event is never emitted, and a reconnection is not attempted

To temporarily fix the problem, I've added a value() method to taxman, implemented as

cacher.value = function() {
    return cached ? cachedValue : null;
}

And changed server.js to use that instead:

if (this._connection.value()) {
    var callbacks = this._callbacks
    this._callbacks = {}
    this._callbackCount = 0
    this._connection.value().close()

Not particularly elegant, but it fixed the problem for me.

Ciao, Federico

marcello3d commented 13 years ago

You guys are awesome. I appreciate your tracking this down. Apparently I have some changes to my local copy of taxman that I've forgotten to commit/publish. They should be available now.