Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

does not re-connect #34

Closed
tcurdt opened this issue Jul 27, 2011 · 10 comments
Closed

does not re-connect #34

tcurdt opened this issue Jul 27, 2011 · 10 comments

Comments

@tcurdt
Copy link

tcurdt commented Jul 27, 2011

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

@andzdroid
Copy link

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
Copy link
Author

tcurdt commented Aug 7, 2011

Maybe this could be done through

MongolianDB.prototype.eval

but I am not sure.

@marcello3d
Copy link
Owner

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
Copy link
Author

tcurdt commented Aug 12, 2011

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
Copy link
Owner

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
Copy link
Author

tcurdt commented Aug 16, 2011

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
Copy link
Author

tcurdt commented Aug 16, 2011

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

@marcello3d marcello3d reopened this Aug 17, 2011
@marcello3d
Copy link
Owner

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

@0xfede
Copy link

0xfede commented Aug 29, 2011

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
Copy link
Owner

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.

marcello3d pushed a commit that referenced this issue Aug 30, 2011
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants