unable to Login when reading from a secondary

geekgonecrazy commented 7 years ago

Description:

When using a mongo cluster with multiple secondaries, and the option: readPreference=secondary in the connection string to Rocket.Chat. Login especially with authentication providers like oauth / saml etc fail.

Removing this option causes the login to start working again.

Server Setup Information:

Version of Rocket.Chat Server: 0.58.0
Operating System: Linux
Deployment Method(snap/docker/tar/etc): all
Number of Running Instances: 2-4
DB Replicaset Oplog: True

Steps to Reproduce:

Setup mongo cluster with at least 2 nodes in replicaset
add both nodes to mongo connection string
add readPreference=secondary to connection string
Try to login with oauth / saml or another authentication provider

Expected behavior:

It should login like normal

Actual behavior:

It throws an error

Relevant logs:

Exception while invoking method 'login' TypeError: Cannot read property 'includes' of undefined
  at /app/bundle/programs/server/app/app.js:237:22
  at runAndHandleExceptions (packages/callback-hook.js:152:24)
  at packages/callback-hook.js:159:12
  at /app/bundle/programs/server/packages/accounts-base.js:639:13
  at [object Object]._.extend.each (packages/callback-hook.js:128:15)
  at AccountsServer.Ap._validateLogin (/app/bundle/programs/server/packages/accounts-base.js:635:27)
  at AccountsServer.Ap._attemptLogin (/app/bundle/programs/server/packages/accounts-base.js:822:8)
  at [object Object].methods.login (/app/bundle/programs/server/packages/accounts-base.js:977:21)
  at [object Object].methodMap.(anonymous function) (packages/rocketchat_monitoring.js:2731:30)
  at maybeAuditArgumentChecks (/app/bundle/programs/server/packages/ddp-server.js:1823:12)
  at /app/bundle/programs/server/packages/ddp-server.js:905:20
  at [object Object]._.extend.withValue (packages/meteor.js:1122:17)
  at /app/bundle/programs/server/packages/ddp-server.js:904:41
  at [object Object]._.extend.withValue (packages/meteor.js:1122:17)
  at /app/bundle/programs/server/packages/ddp-server.js:903:46
  at [object Object]._.extend.protocol_handlers.method (/app/bundle/programs/server/packages/ddp-server.js:876:21)
  at /app/bundle/programs/server/packages/ddp-server.js:755:85

Exception while invoking method 'UserPresence:setDefaultStatus' Error: read ECONNRESET                                                                                     [467/1870]
  at Object.Future.wait (/app/bundle/programs/server/node_modules/fibers/future.js:449:15)
  at [object Object]._.extend._nextObject (/app/bundle/programs/server/packages/mongo.js:1059:47)
  at [object Object]._.extend.forEach (/app/bundle/programs/server/packages/mongo.js:1091:22)
  at [object Object]._.extend.map (/app/bundle/programs/server/packages/mongo.js:1101:10)
  at [object Object]._.extend.fetch (/app/bundle/programs/server/packages/mongo.js:1121:17)
  at [object Object].Cursor.(anonymous function) [as fetch] (/app/bundle/programs/server/packages/mongo.js:953:44)
  at Object.<anonymous> (packages/matb33_collection-hooks.js:445:81)
  at Object.collection.(anonymous function) [as update] (packages/matb33_collection-hooks.js:146:21)
  at [object Object].update (/app/bundle/programs/server/packages/mongo.js:3899:31)
  at ModelsBaseDb.update (/app/bundle/programs/server/packages/rocketchat_lib.js:10647:32)
  at [object Object].model.update (/app/bundle/programs/server/packages/rocketchat_lib.js:10408:24)
  at ModelsBaseDb.update (/app/bundle/programs/server/packages/rocketchat_lib.js:10647:32)
  at [object Object].model.update (/app/bundle/programs/server/packages/rocketchat_lib.js:10408:24)
  at Object.UserPresence.setDefaultStatus (packages/konecty_user-presence.js:217:29)
  at [object Object].Meteor.methods.UserPresence:setDefaultStatus (packages/konecty_user-presence.js:298:18)
  at [object Object].methodMap.(anonymous function) (packages/rocketchat_monitoring.js:2731:30)
  at [object Object].methodsMap.(anonymous function) (/app/bundle/programs/server/packages/rocketchat_lib.js:1028:26)
  at maybeAuditArgumentChecks (/app/bundle/programs/server/packages/ddp-server.js:1823:12)
  at /app/bundle/programs/server/packages/ddp-server.js:905:20
  at [object Object]._.extend.withValue (packages/meteor.js:1122:17)
  at /app/bundle/programs/server/packages/ddp-server.js:904:41
  at [object Object]._.extend.withValue (packages/meteor.js:1122:17)

I don't think this one is related. But including for completeness sake

Subscription without user nXwFTFL8sgZ6HFLDT

o0lit3 commented 7 years ago

Noting that in the use-case for our particular implementation (and currently broken deployment) of Rocket.Chat with replicated readers, we are using "nearest" as the read preference.

That may be creating a situation where a race condition is more likely to happen because it is more often hitting a mongo node that doesn't have data replicated from the primary yet. I anticipate that this issue would still occur regardless of that setting, however, and readPreference=secondary may exhibit the symptom even more frequently because you are guaranteed to hit a replicated db.

geekgonecrazy commented 6 years ago

readPreference=nearest seems to make this surface more often.

With 0.59.3 errors when deleting a user:

Exception while invoking method 'deleteUser' TypeError: Cannot read property 'indexOf' of undefined
  at [object Object].Meteor.methods.deleteUser (/app/bundle/programs/server/app/app.js:7188:31)
  at [object Object].methodMap.(anonymous function) (packages/rocketchat_monitoring.js:2731:30)
  at [object Object].methodsMap.(anonymous function) (/app/bundle/programs/server/packages/rocketchat_lib.js:1276:26)
  at maybeAuditArgumentChecks (/app/bundle/programs/server/packages/ddp-server.js:1857:12)
  at /app/bundle/programs/server/packages/ddp-server.js:903:20
  at [object Object].EVp.withValue (packages/meteor.js:1134:15)
  at /app/bundle/programs/server/packages/ddp-server.js:902:47
  at [object Object].EVp.withValue (packages/meteor.js:1134:15)
  at /app/bundle/programs/server/packages/ddp-server.js:901:46
  at [object Object]._.extend.protocol_handlers.method (/app/bundle/programs/server/packages/ddp-server.js:874:21)
  at /app/bundle/programs/server/packages/ddp-server.js:753:85

Registering a user:

Exception while invoking method 'registerUser' TypeError: Cannot read property 'username' of undefined
  at AccountsServer.<anonymous> (/app/bundle/programs/server/app/app.js:194:10)
  at AccountsServer.insertUserDoc (packages/underscore.js:797:22)
  at createUser (/app/bundle/programs/server/packages/accounts-password.js:1142:25)
  at AccountsServer.Accounts.createUser (/app/bundle/programs/server/packages/accounts-password.js:1202:10)
  at [object Object].Meteor.methods.registerUser (/app/bundle/programs/server/app/app.js:8601:22)
  at [object Object].methodMap.(anonymous function) (packages/rocketchat_monitoring.js:2731:30)
  at [object Object].methodsMap.(anonymous function) (/app/bundle/programs/server/packages/rocketchat_lib.js:1276:26)
  at maybeAuditArgumentChecks (/app/bundle/programs/server/packages/ddp-server.js:1857:12)
  at /app/bundle/programs/server/packages/ddp-server.js:903:20
  at [object Object].EVp.withValue (packages/meteor.js:1134:15)
  at /app/bundle/programs/server/packages/ddp-server.js:902:47
  at [object Object].EVp.withValue (packages/meteor.js:1134:15)
  at /app/bundle/programs/server/packages/ddp-server.js:901:46
  at [object Object]._.extend.protocol_handlers.method (/app/bundle/programs/server/packages/ddp-server.js:874:21)
  at /app/bundle/programs/server/packages/ddp-server.js:753:85

Exception while invoking method 'login' TypeError: Cannot read property 'includes' of undefined
  at /app/bundle/programs/server/app/app.js:237:22
  at runAndHandleExceptions (packages/callback-hook.js:152:24)
  at packages/callback-hook.js:159:12
  at /app/bundle/programs/server/packages/accounts-base.js:646:13
  at [object Object]._.extend.each (packages/callback-hook.js:128:15)
  at AccountsServer.Ap._validateLogin (/app/bundle/programs/server/packages/accounts-base.js:642:27)
  at AccountsServer.Ap._attemptLogin (/app/bundle/programs/server/packages/accounts-base.js:829:8)
  at [object Object].methods.login (/app/bundle/programs/server/packages/accounts-base.js:984:21)
  at [object Object].methodMap.(anonymous function) (packages/rocketchat_monitoring.js:2731:30)
  at maybeAuditArgumentChecks (/app/bundle/programs/server/packages/ddp-server.js:1857:12)
  at /app/bundle/programs/server/packages/ddp-server.js:903:20
  at [object Object].EVp.withValue (packages/meteor.js:1134:15)
  at /app/bundle/programs/server/packages/ddp-server.js:902:47
  at [object Object].EVp.withValue (packages/meteor.js:1134:15)
  at /app/bundle/programs/server/packages/ddp-server.js:901:46
  at [object Object]._.extend.protocol_handlers.method (/app/bundle/programs/server/packages/ddp-server.js:874:21)
  at /app/bundle/programs/server/packages/ddp-server.js:753:85

Attempting to reset a password:

Exception while invoking method 'resetPassword' TypeError: Cannot read property 'includes' of undefined
  at /app/bundle/programs/server/app/app.js:237:22
  at runAndHandleExceptions (packages/callback-hook.js:152:24)
  at packages/callback-hook.js:159:12
  at /app/bundle/programs/server/packages/accounts-base.js:646:13
  at [object Object]._.extend.each (packages/callback-hook.js:128:15)
  at AccountsServer.Ap._validateLogin (/app/bundle/programs/server/packages/accounts-base.js:642:27)
  at AccountsServer.Ap._attemptLogin (/app/bundle/programs/server/packages/accounts-base.js:829:8)
  at AccountsServer.Ap._loginMethod (/app/bundle/programs/server/packages/accounts-base.js:849:15)
  at [object Object].Meteor.methods.resetPassword (/app/bundle/programs/server/packages/accounts-password.js:786:21)
  at [object Object].methodMap.(anonymous function) (packages/rocketchat_monitoring.js:2731:30)
  at maybeAuditArgumentChecks (/app/bundle/programs/server/packages/ddp-server.js:1857:12)
  at /app/bundle/programs/server/packages/ddp-server.js:903:20
  at [object Object].EVp.withValue (packages/meteor.js:1134:15)
  at /app/bundle/programs/server/packages/ddp-server.js:902:47
  at [object Object].EVp.withValue (packages/meteor.js:1134:15)
  at /app/bundle/programs/server/packages/ddp-server.js:901:46
  at [object Object]._.extend.protocol_handlers.method (/app/bundle/programs/server/packages/ddp-server.js:874:21)
  at /app/bundle/programs/server/packages/ddp-server.js:753:85

geekgonecrazy commented 6 years ago

In dev environment you can access your rs.conf() and set priority to 0 and slaveDelay to any value greater then 0 to introduce a fraction of a delay in replication. In my case I was able to pull it off with value set to .2

Then simply try to register a user. Easiest way to reproduce

vikas0121 commented 6 years ago

Please help while calling this method process get stuck. _id = insertUserDoc.call(Accounts, options, user)

input: { username: 'Guest_3129810000-14:35', department: 'mt3uAwpz4dSqow7pg', type: 'visitor', custid: 0, country: undefined, userAgent: 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/62.0.3202.62 Safari/537.36', ip: '127.0.0.1', host: 'localhost:3000' }

geekgonecrazy commented 6 years ago

I don't think this is related to this issue at all

ndroo commented 4 years ago

This is super old sorry for re-opening the chat, but we had a similar challenge when we had the desire to read from a secondary. I had to set w=3 (as we have 3 nodes, 1 primary and 2 secondaries) to get around this issue. In any other app i'd cache the write and not rely on the DB to mitigate the replication delay challenge, maybe adding such a caching layer makes sense at some point?

Regardless, i also want to read from a secondary for the oplog. This is working for me locally, but in our AWS ECS environment it hangs (around 80% of the time) when doing the "node main.js" phase of the boot-up. No output nothing, just hangs. I'm looking into this as this is where 90% of our CPU load comes from, so we're super keen to distribute it on the secondary nodes.

geekgonecrazy commented 4 years ago

@ndroo #18887 might be of interest to you

cc @rodrigok for above comments.

RocketChat / Rocket.Chat