We have an API working with MongoDB Atlas, connection works 99% of the time, but we occasionally get a MongoServerSelectionError: Server selection timed out after 30000 ms on a specific endpoint for some reason. Like I said, it fails 2/3 times out of 100.
This is running on Netlify Functions, and whenever the function needs to use Mongo, it just awaits the connection promise.
Full error:
{
"errorType":"Runtime.UnhandledPromiseRejection",
"errorMessage":"MongoServerSelectionError: Server selection timed out after 30000 ms",
"reason":{
"errorType":"MongoServerSelectionError",
"errorMessage":"Server selection timed out after 30000 ms",
"reason":{
"type":"ReplicaSetNoPrimary",
"servers":{
},
"stale":false,
"compatible":true,
"heartbeatFrequencyMS":10000,
"localThresholdMS":15,
"setName":"atlas-13tibr-shard-0"
},
"stack":[
"MongoServerSelectionError: Server selection timed out after 30000 ms",
" at Timeout._onTimeout (/var/task/node_modules/mongodb/lib/sdam/topology.js:330:38)",
" at listOnTimeout (internal/timers.js:557:17)",
" at processTimers (internal/timers.js:500:7)"
]
},
"promise":{
},
"stack":[
"Runtime.UnhandledPromiseRejection: MongoServerSelectionError: Server selection timed out after 30000 ms",
" at process.<anonymous> (/var/runtime/index.js:35:15)",
" at process.emit (events.js:400:28)",
" at processPromiseRejections (internal/process/promises.js:245:33)",
" at processTicksAndRejections (internal/process/task_queues.js:96:32)"
]
}
From the original error, the topology is of type ReplcaSetNoPrimary, which would indicate some sort of network connection issue between the driver and the primary node and a write was taking place when this happened or the use or the default read preference or “primary” was being used with a read. To debug this better one can add a listener on the server monitors to see if an error occurred:
Note:
What type of operation is being executed when the error occurs? If it’s a write, the primary must be available, if it’s a read, check the read preference and consider if using “primary” to change it to something like “primaryPreferred”, “secondaryPreferred”, or “secondary”.
It happens for me on both reads and rights. What is really odd is that I have instrumented my code heavily with log output all over the place. When this error occurs NONE of the logging happens. It’s almost as if request A creates a connection, responds. Then that connection, while pooled, has an issue, but nothing consumes the exception. Then when request B comes in and gets assigned to the thread it blows up before running ANY of my actual code. No idea if this is the case but that is what it appears to be.
Also for whatever it’s worth - there is a thread looking at this from the Vercel perspective:
I’m using 5.9.1, in the latest version of my code I see that when the issue occurs the “serverClosed” event runs at basically the same time (or at least outputs it logs).
So I think my theory is correct. I just had an example where a request that does not even use the database errors out with the following logs associated with it:
serverHeartbeat issue (might not be an error): {"connectionId":"ac-mxrxhwn-shard-00-02.ss9fyeo.mongodb.net:27017","duration":318996,"failure":{}}
serverClosed! ServerClosedEvent {
topologyId: 0,
address: 'ac-mxrxhwn-shard-00-02.ss9fyeo.mongodb.net:27017'
}
serverHeartbeat issue (might not be an error): {"connectionId":"ac-mxrxhwn-shard-00-00.ss9fyeo.mongodb.net:27017","duration":318982,"failure":{}}
serverClosed! ServerClosedEvent {
topologyId: 0,
address: 'ac-mxrxhwn-shard-00-00.ss9fyeo.mongodb.net:27017'
}
serverHeartbeat issue (might not be an error): {"connectionId":"ac-mxrxhwn-shard-00-01.ss9fyeo.mongodb.net:27017","duration":318981,"failure":{}}
serverClosed! ServerClosedEvent {
topologyId: 0,
address: 'ac-mxrxhwn-shard-00-01.ss9fyeo.mongodb.net:27017'
}
Unhandled Promise Rejection {"errorType":"Runtime.UnhandledPromiseRejection","errorMessage":"MongoServerSelectionError: Server selection timed out after 10000 ms","reason":{"errorType":"MongoServerSelectionError","errorMessage":"Server selection timed out after 10000 ms","reason":{"type":"ReplicaSetNoPrimary","servers":{},"stale":false,"compatible":true,"heartbeatFrequencyMS":10000,"localThresholdMS":15,"setName":"atlas-1327c9-shard-0","maxElectionId":null,"maxSetVersion":null,"commonWireVersion":0,"logicalSessionTimeoutMinutes":null},"stack":["MongoServerSelectionError: Server selection timed out after 10000 ms"," at Timeout._onTimeout (/var/task/node_modules/mongodb/lib/sdam/topology.js:278:38)"," at listOnTimeout (node:internal/timers:569:17)"," at process.processTimers (node:internal/timers:512:7)"]},"promise":{},"stack":["Runtime.UnhandledPromiseRejection: MongoServerSelectionError: Server selection timed out after 10000 ms"," at process.<anonymous> (file:///var/runtime/index.mjs:1276:17)"," at process.emit (node:events:529:35)"," at emit (node:internal/process/promises:149:20)"," at processPromiseRejections (node:internal/process/promises:283:27)"," at processTicksAndRejections (node:internal/process/task_queues:96:32)"," at runNextTicks (node:internal/process/task_queues:64:3)"," at process.processTimers (node:internal/timers:509:9)"]}
Error: Runtime exited without providing a reason