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

fix(connection): avoid returning readyState = connected if connection state is stale #14812

Merged
merged 2 commits into from
Sep 17, 2024

Conversation

vkarpov15
Copy link
Collaborator

Fix #14727

cc @alexbevi

Summary

The problem here is that readyState can return connected immediately after an AWS Lambda container thaws after some time. readyState only looks at the last heartbeat, but not how long ago the last heartbeat occurred - with this PR, if the last heartbeat is stale (more than 2 heartbeat intervals) then we assume we're disconnected.

This PR still needs significant testing, but I wanted to put it out for review to solicit early feedback.

Examples

Copy link
Collaborator

@hasezoey hasezoey left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code looks good to me, though i agree this should need some testing

lib/drivers/node-mongodb-native/connection.js Outdated Show resolved Hide resolved
@vkarpov15 vkarpov15 modified the milestones: 8.8, 8.7 Aug 26, 2024
@vkarpov15
Copy link
Collaborator Author

Going to move this one back because I've been having trouble reproducing this issue in AWS lambda

@vkarpov15
Copy link
Collaborator Author

vkarpov15 commented Sep 17, 2024

It took some time, but I was able to repro this in Lambda. The following function is adapted from Mongoose's Lambda docs:

const mongoose = require('mongoose');

let conn = null;

const uri = 'mongodb+srv://chris2022:PennywinklePlaydays@zevo-dev.6lxkgiz.mongodb.net/chris2022?retryWrites=true&w=majority';

exports.handler = async function(event, context) {
  // Make sure to add this so you can re-use `conn` between function calls.
  // See https://www.mongodb.com/blog/post/serverless-development-with-nodejs-aws-lambda-mongodb-atlas
  context.callbackWaitsForEmptyEventLoop = false;

  // Because `conn` is in the global scope, Lambda may retain it between
  // function calls thanks to `callbackWaitsForEmptyEventLoop`.
  // This means your Lambda function doesn't have to go through the
  // potentially expensive process of connecting to MongoDB every time.
  if (conn == null) {
    conn = mongoose.createConnection(uri, {
      // and tell the MongoDB driver to not wait more than 5 seconds
      // before erroring out if it isn't connected
      serverSelectionTimeoutMS: 5000
    });

    // `await`ing connection after assigning to the `conn` variable
    // to avoid multiple function calls creating new connections
    await conn.asPromise();
    conn.model('Test', new mongoose.Schema({ name: String }));
  }

  console.log('Start', conn.readyState, new Date(conn._lastHeartbeatAt), Date.now() - conn._lastHeartbeatAt);

  const M = conn.model('Test');

  const doc = await M.findOne();
  console.log('After find', conn.readyState, new Date(conn._lastHeartbeatAt), Date.now() - conn._lastHeartbeatAt);
  console.log(doc);

  return doc;
};

Output:


Response
{
  "_id": "641b1cb82525faca0c0be001",
  "name": "Run Hook",
  "__v": 0
}

Function Logs
START RequestId: ec6e7091-f2dd-47f8-8a4a-8cee7cccc1fa Version: $LATEST
2024-09-17T16:36:30.288Z	ec6e7091-f2dd-47f8-8a4a-8cee7cccc1fa	INFO	Start 0 2024-09-17T16:36:08.749Z 21539
2024-09-17T16:36:30.408Z	ec6e7091-f2dd-47f8-8a4a-8cee7cccc1fa	INFO	After find 1 2024-09-17T16:36:30.371Z 37
2024-09-17T16:36:30.408Z	ec6e7091-f2dd-47f8-8a4a-8cee7cccc1fa	INFO	{
  _id: new ObjectId('641b1cb82525faca0c0be001'),
  name: 'Run Hook',
  __v: 0
}
END RequestId: ec6e7091-f2dd-47f8-8a4a-8cee7cccc1fa
REPORT RequestId: ec6e7091-f2dd-47f8-8a4a-8cee7cccc1fa	Duration: 204.32 ms	Billed Duration: 205 ms	Memory Size: 128 MB	Max Memory Used: 104 MB

Request ID
ec6e7091-f2dd-47f8-8a4a-8cee7cccc1fa

So readyState is correctly 0 at the beginning, but then changes to 1 when Mongoose gets a successful heartbeat back.

@vkarpov15 vkarpov15 changed the base branch from 8.6 to 8.7 September 17, 2024 16:39
@vkarpov15 vkarpov15 merged commit 89d7b8b into 8.7 Sep 17, 2024
46 checks passed
@hasezoey hasezoey deleted the vkarpov15/gh-14727 branch September 17, 2024 17:49
@halilbrhmtrn
Copy link

if ( this._readyState === STATES.connected && this._lastHeartbeatAt != null && typeof this.client?.topology?.s?.description?.heartbeatFrequencyMS === 'number' && Date.now() - this._lastHeartbeatAt >= this.client.topology.s.description.heartbeatFrequencyMS * 2) { return STATES.disconnected; }

This logic seems overly aggressive. Network latencies caused by high load on the MongoDB server could prevent heartbeats from being received within the heartbeatFrequencyMS * 2 time frame. Relying on such logic may lead Mongoose to falsely report a disconnected state. If this implementation is necessary for cold-start environments, it should be configurable and invoked only when required. Additionally, a more reliable method for detecting staleness should be employed. FYI
@vkarpov15

@halilbrhmtrn
Copy link

It seems there are already couple of issues opened related with this. @vkarpov15
#15042
#15015
#14971

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

Successfully merging this pull request may close these issues.

3 participants