Parse server is sometimes unable to handle voting in mongo replicaset #2544

nerakhon · 2016-08-18T13:09:24Z

Issue Description

Describe your issue in as much detail as possible.

I have a parse server running dockerized on ubuntu 14.04 on digital ocean, connected to MongoDB 3.0 replicaset with rocksdb engine. When a network issue happens at digital ocean and cluster undergoes voting parse server ends up in unrecoverable state complaining about closed sockets on original primary of the replicaset.

Steps to reproduce

Please include a detailed list of steps that reproduce the issue. Include curl commands when applicable.

have active parse requests on parse server
initiate voting on mongodb replicaset

Expected Results

Parse to fail over to new primary

Actual Outcome

Parse server hanging

Environment Setup

Server
- parse-server version (Be specific! Don't say 'latest'.) : 2.2.16
- Operating System: Ubuntu 14.04 (Dockerized)
- Hardware: Digital ocean small droplet
- Localhost or remote server? (AWS, Heroku, Azure, Digital Ocean, etc): Digital ocean
Database
- MongoDB version: 3.0
- Storage engine: Rocks
- Hardware: same as above for parse
- Localhost or remote server? (AWS, mLab, ObjectRocket, Digital Ocean, etc): digital ocean

Logs/Trace

You can turn on additional logging by configuring VERBOSE=1 in your environment.

Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : Aug 17 22:06:10 : message: 'server db-1.######.com:27017 sockets closed' } MongoError: server db-1.######.com:27017 sockets closed
at Server.destroy (/parse/node_modules/mongodb-core/lib/topologies/server.js:1075:47)
at /parse/node_modules/mongodb-core/lib/topologies/replset.js:1267:20
at commandCallback (/parse/node_modules/mongodb-core/lib/topologies/server.js:1194:9)
at Callbacks.emit (/parse/node_modules/mongodb-core/lib/topologies/server.js:119:3)
at .messageHandler (/parse/node_modules/mongodb-core/lib/topologies/server.js:358:23)
at TLSSocket. (/parse/node_modules/mongodb-core/lib/connection/connection.js:292:22)
at emitOne (events.js:96:13)
at TLSSocket.emit (events.js:188:7)
at readableAddChunk (_stream_readable.js:172:18)
at TLSSocket.Readable.push (_stream_readable.js:130:10)
: #33[31merror#033[39m: error getting auth for sessionToken MongoError: server db-1.####.com:27017 sockets closed
at Server.destroy (/parse/node_modules/mongodb-core/lib/topologies/server.js:1075:47)
at /parse/node_modules/mongodb-core/lib/topologies/replset.js:1267:20
at commandCallback (/parse/node_modules/mongodb-core/lib/topologies/server.js:1194:9)
at Callbacks.emit (/parse/node_modules/mongodb-core/lib/topologies/server.js:119:3)
at .messageHandler (/parse/node_modules/mongodb-core/lib/topologies/server.js:358:23)
at TLSSocket. (/parse/node_modules/mongodb-core/lib/connection/connection.js:292:22)
at emitOne (events.js:96:13)
at TLSSocket.emit (events.js:188:7)
at readableAddChunk (_stream_readable.js:172:18)
at TLSSocket.Readable.push (_stream_readable.js:130:10)

Aug 20 05:16:33 : Uncaught internal server error. { MongoError: no valid seed servers in list
Aug 20 05:16:33 : at . (/parse/node_modules/mongodb-core/lib/topologies/replset.js:1415:39)
Aug 20 05:16:33 : at g (events.js:286:16)
Aug 20 05:16:33 : at emitTwo (events.js:106:13)
Aug 20 05:16:33 : at emit (events.js:191:7)
Aug 20 05:16:33 : at . (/parse/node_modules/mongodb-core/lib/topologies/server.js:177:12)
Aug 20 05:16:33 : at g (events.js:286:16)
Aug 20 05:16:33 : at emitTwo (events.js:106:13)
Aug 20 05:16:33 : at emit (events.js:191:7)
Aug 20 05:16:33 : at . (/parse/node_modules/mongodb-core/lib/connection/pool.js:119:12)
Aug 20 05:16:33 : at g (events.js:286:16) name: 'MongoError', message: 'no valid seed servers in list' } MongoError: no valid seed servers in list
Aug 20 05:16:33 : at . (/parse/node_modules/mongodb-core/lib/topologies/replset.js:1415:39)
Aug 20 05:16:33 : at g (events.js:286:16)
Aug 20 05:16:33 : at emitTwo (events.js:106:13)
Aug 20 05:16:33 : at emit (events.js:191:7)
Aug 20 05:16:33 : at . (/parse/node_modules/mongodb-core/lib/topologies/server.js:177:12)
Aug 20 05:16:33 : at g (events.js:286:16)
Aug 20 05:16:33 : at emitTwo (events.js:106:13)
Aug 20 05:16:33 : at emit (events.js:191:7)
Aug 20 05:16:33 : at . (/parse/node_modules/mongodb-core/lib/connection/pool.js:119:12)
Aug 20 05:16:33 : at g (events.js:286:16)

the exception repeatedly thrown by parse even when mongo replicaset is back online and finished voting

similar issue is referenced in issue: #2446 by @jeacott1

benishak · 2016-08-18T14:45:35Z

I also have similar issue but with mongos! althought I have 3 Mongos but when one of them is not available or a member of one of the replicaSet of one of the mongos goes down or one of the 3 replicaset enter an election stat, Parse stop working and throw error

flovilmart · 2016-08-25T15:22:06Z

@benishak what is the error that is thrown?

jeacott1 · 2016-08-25T22:38:09Z

I can confirm that there is an issue, but for us we get a "not master, slaveOk=false;." exception.
to be clear we intend slave to be set false. for me its bizarre behaviour when the slave=true/false setting is clientside, so why it would ever send a request to a mongo slave knowing that it will reject the response is just odd.
There is no problem if parse/mongo are idle. when a mongo election occurs and parse is idle, parse recovers to the new master properly.
When parse is actively serving load and an election occurs, we see this exception, and parse is dead until its restarted.

flovilmart · 2016-08-26T02:12:13Z

@jeacott1 what version are you running? We added in 2.2.17 a recovery for exceptions in the mongo driver. If that's not effective for your use case, we shall invesitgate what error is triggered and clean up the pending connections while the election is occurring.

benishak · 2016-08-26T09:33:09Z

As far as I remember, something like this
MongoError .... Primary shard shard_1 not available, election stat

nerakhon · 2016-09-26T14:13:43Z

Just a brief update, we've seen the same issue even with versions > 2.2.20

mrmarcsmith · 2017-01-19T18:51:39Z

The same happens for us. "not master and slaveOk=false" is the error and our server is completely unavailable until I restart it. we are running version 2.3.1

error: Error generating response. { MongoError: not master and slaveOk=false
    at Function.MongoError.create (/parse-server/node_modules/mongodb-core/lib/error.js:31:11)
    at queryCallback (/parse-server/node_modules/mongodb-core/lib/cursor.js:198:34)
    at /parse-server/node_modules/mongodb-core/lib/connection/pool.js:436:18
    at _combinedTickCallback (internal/process/next_tick.js:67:7)
    at process._tickDomainCallback (internal/process/next_tick.js:122:9)
  name: 'MongoError',
  message: 'not master and slaveOk=false',
  '$err': 'not master and slaveOk=false',
  code: 13435 } name=MongoError, message=not master and slaveOk=false, $err=not master and slaveOk=false, code=13435

mman · 2017-02-02T11:21:09Z

Just hit that again today, the moment mongo replica set changes PRIMARY the parse-server looses mongo connection and is not able to get it back until restarted.

This is on parse 2.3.2.

Parse Server `backend-2-nyc3`

The Mongo URL string contains db-1, db-2, and db-3. Parse Server was connected to db-3 that was the primary.

The moment primary changes parse server starts emitting these exceptions until the point when it's restarted automatically by monit for not serving HTTP requests. After the restart everything runs fine until next PRIMARY change.

Feb  2 07:29:38 backend-2-nyc3 ea73b33bcbfb[1179]: #033[31merror#033[39m: error getting auth for sessionToken MongoError: connection 1165 to db-3:27017 closed
Feb  2 07:29:38 backend-2-nyc3 ea73b33bcbfb[1179]:     at Function.MongoError.create (/parse/node_modules/mongodb-core/lib/error.js:29:11)
Feb  2 07:29:38 backend-2-nyc3 ea73b33bcbfb[1179]:     at TLSSocket.<anonymous> (/parse/node_modules/mongodb-core/lib/connection/connection.js:187:22)
Feb  2 07:29:38 backend-2-nyc3 ea73b33bcbfb[1179]:     at TLSSocket.g (events.js:286:16)
Feb  2 07:29:38 backend-2-nyc3 ea73b33bcbfb[1179]:     at emitOne (events.js:101:20)
Feb  2 07:29:38 backend-2-nyc3 ea73b33bcbfb[1179]:     at TLSSocket.emit (events.js:188:7)
Feb  2 07:29:38 backend-2-nyc3 ea73b33bcbfb[1179]:     at Socket._handle.close (net.js:492:12)
Feb  2 07:29:38 backend-2-nyc3 ea73b33bcbfb[1179]:     at Socket.g (events.js:286:16)
Feb  2 07:29:38 backend-2-nyc3 ea73b33bcbfb[1179]:     at emitOne (events.js:96:13)
Feb  2 07:29:38 backend-2-nyc3 ea73b33bcbfb[1179]:     at Socket.emit (events.js:188:7)
Feb  2 07:29:38 backend-2-nyc3 ea73b33bcbfb[1179]:     at TCP._handle.close [as _onclose] (net.js:492:12)

Mongo DB `db-3:27017`

Feb  2 07:29:38 db-3 ee4276c1a636[873]: 2017-02-02T06:29:38.329+0000 I REPL     [ReplicationExecutor] Member db-1:27017 is now in state PRIMARY
Feb  2 07:29:38 db-3 ee4276c1a636[873]: 2017-02-02T06:29:38.332+0000 I REPL     [ReplicationExecutor] replset: another primary seen with election time 5892d1d1:3 my election time is 588c2da7:1
Feb  2 07:29:38 db-3 ee4276c1a636[873]: 2017-02-02T06:29:38.333+0000 I REPL     [ReplicationExecutor] stepping down; another primary was elected more recently
Feb  2 07:29:38 db-3 ee4276c1a636[873]: 2017-02-02T06:29:38.333+0000 I REPL     [ReplicationExecutor] Stepping down from primary in response to heartbeat
Feb  2 07:29:38 db-3 ee4276c1a636[873]: 2017-02-02T06:29:38.334+0000 I REPL     [replCallbackWithGlobalLock-0] transition to SECONDARY

flovilmart · 2017-09-10T18:03:33Z

Closing as the mongodb driver was updated many times in between.

On a side note, we pass the DB URL provided right into the nodejs mongodb client. I believe the server that very little to do with those issues.

I've experienced a few failover over the past 6 months on our setup and parse-server seems to have responded very well to all of those.

flovilmart added the troubleshooting label Sep 3, 2016

flovilmart closed this as completed Sep 10, 2017

mtrezza added type:question Support or code-level question and removed 🔧 troubleshooting labels Jul 11, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Parse server is sometimes unable to handle voting in mongo replicaset #2544

Parse server is sometimes unable to handle voting in mongo replicaset #2544

nerakhon commented Aug 18, 2016 •

edited

Loading

benishak commented Aug 18, 2016

flovilmart commented Aug 25, 2016

jeacott1 commented Aug 25, 2016

flovilmart commented Aug 26, 2016 •

edited

Loading

benishak commented Aug 26, 2016

nerakhon commented Sep 26, 2016

mrmarcsmith commented Jan 19, 2017

mman commented Feb 2, 2017

flovilmart commented Sep 10, 2017

Parse server is sometimes unable to handle voting in mongo replicaset #2544

Parse server is sometimes unable to handle voting in mongo replicaset #2544

Comments

nerakhon commented Aug 18, 2016 • edited Loading

Issue Description

Steps to reproduce

Expected Results

Actual Outcome

Environment Setup

Logs/Trace

benishak commented Aug 18, 2016

flovilmart commented Aug 25, 2016

jeacott1 commented Aug 25, 2016

flovilmart commented Aug 26, 2016 • edited Loading

benishak commented Aug 26, 2016

nerakhon commented Sep 26, 2016

mrmarcsmith commented Jan 19, 2017

mman commented Feb 2, 2017

Parse Server backend-2-nyc3

Mongo DB db-3:27017

flovilmart commented Sep 10, 2017

nerakhon commented Aug 18, 2016 •

edited

Loading

flovilmart commented Aug 26, 2016 •

edited

Loading

Parse Server `backend-2-nyc3`

Mongo DB `db-3:27017`