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

Severe Query Performance Issue with Mongoose 8.9.5 #15194

Open
2 tasks done
totomers opened this issue Jan 22, 2025 · 15 comments
Open
2 tasks done

Severe Query Performance Issue with Mongoose 8.9.5 #15194

totomers opened this issue Jan 22, 2025 · 15 comments
Milestone

Comments

@totomers
Copy link

Prerequisites

  • I have written a descriptive issue title
  • I have searched existing issues to ensure the performance issue has not already been reported

Last performant version

"^6.8.1"

Slowed down in version

"^8.9.4"

Node.js version

18.x

🦥 Performance issue

I'm facing a severe performance issue with Mongoose v8.9.5. Despite the MongoDB explain output showing lightning-fast query execution on the database, Mongoose is inexplicably taking an unreasonably long time to return results.

For example, the following simple query takes around 700 ms, however, when using the native mongodb driver the result is returned in 60ms.

 console.time("mongoose");

     await Business.findById(new ObjectId("673e24037abe20cc29e0225b")).lean();

    console.timeEnd("mongoose");
 

Output: 695.934ms

   console.time("Native MongoDB Driver");

    await db
      .collection("businesses")
      .findOne({ _id: new ObjectId("673e24037abe20cc29e0225b") });

    console.timeEnd("Native MongoDB Driver");

Output: 64.584ms

I suspect this could be related to how Mongoose processes the query or interacts with MongoDB in this version. The problem persists despite having the appropriate indexes in place and minimal query execution time reported by MongoDB.

Environment:

Node.js Version: v18.20.4
Mongoose Version: v8.9.5
MongoDB Driver Version: v6.12.0 (mongoose dependency)
MongoDB Server Version: 8.0.4 (Atlas Cluster)
OS: Amazon Linux 2 (AWS Lambda)

This occurred only after I updated the mongoose version from v6.8.1 to v8.9.5, and the MongoDB Server Version from 6.0.0 to 8.0.4

Could this be a bug in Mongoose v8.9.5? What else can I try to find the cause of this slowdown?

What I’ve Tried For Each Query:

  1. Verified that MongoDB itself is not at fault (query execution is fast per explain()).
  2. Ensured proper indexing on the collection fields.
  3. Added mongoose.set('debug', true) to confirm the query being executed is correct.
  4. Cleared npm cache and reinstalled dependencies to rule out dependency corruption.
  5. Checked with MongoDB support to double check it doesn't show up as a slow operation.

Could this be a regression or specific issue with Mongoose v8.9.5? Is there any additional debugging you recommend to pinpoint the cause of this delay?

Steps to Reproduce

1. Define the schema and create a million mock documents:

const TransactionSchema = new mongoose.Schema({
  businessId: { type: mongoose.Schema.Types.ObjectId, required: true },
  acquirerTransactionId: { type: String, index: true },
  partnerReferenceId: { type: String, index: true },
  tempUniqueId: { type: String, index: true },
  transactionTime: { type: Date, index: true },
});

const Transaction = mongoose.model("Transaction", TransactionSchema);

Use the following code to connect to MongoDB and log the Mongoose and MongoDB driver versions:*


import mongoose from "mongoose";

mongoose.Promise = global.Promise;
let isConnected;

export const connectToDatabase = () => {
  if (isConnected) {
    console.log("DB connection was previously established");
    return Promise.resolve();
  }
  console.log("Establishing a new DB connection...");
  console.log(`Mongoose version: ${mongoose?.version}`);

  const DB_URL = "mongodb+srv://<username>:<password>@<cluster>.mongodb.net/dbname";
  mongoose.set("strictQuery", true);

  return mongoose
    .connect(DB_URL, { maxIdleTimeMS: 60000 })
    .then((db) => {
      isConnected = db.connections[0].readyState;
      try {
        const connection = mongoose.connection;
        const driverInfo = connection?.client?.s?.options?.metadata;

        if (driverInfo) {
          console.log(`MongoDB Driver Info:`, driverInfo);
        } else {
          console.log("Driver info is not accessible.");
        }
      } catch (error) {
        console.error("Error accessing MongoDB driver info:", error);
      }
    })
    .catch((err) => {
      console.error("Connection error:", err);
    });
};

connectToDatabase();

3. Execute the query:

const result = await Transaction.findOne({
  $or: [
    { acquirerTransactionId: "502109000037" },
    { partnerReferenceId: "502109000037" },
    { tempUniqueId: "502109000037" },
  ],
  businessId: "673e24037abe20cc29e0225b",
});
console.log("Query result:", result);

4. Observe the following:

Always takes more than around 1 second.
MongoDB query execution time (based on explain) is ~1 millisecond.

5. Run the explain() on the query directly on MongoDB, and see that the winning plan looks optimal. Here’s the relevant snippet of what I got:

{
  "queryPlanner": {
    "winningPlan": {
      "stage": "FETCH",
      "filter": { "businessId": { "$eq": "673e24037abe20cc29e0225b" } },
      "inputStage": {
        "stage": "OR",
        "inputStages": [
          {
            "stage": "IXSCAN",
            "keyPattern": { "acquirerTransactionId": 1 },
            "indexBounds": { "acquirerTransactionId": [ "[\"502109000037\", \"502109000037\"]" ] }
          },
          {
            "stage": "IXSCAN",
            "keyPattern": { "tempUniqueId": 1 },
            "indexBounds": { "tempUniqueId": [ "[\"502109000037\", \"502109000037\"]" ] }
          },
          {
            "stage": "IXSCAN",
            "keyPattern": { "partnerReferenceId": 1 },
            "indexBounds": { "partnerReferenceId": [ "[\"502109000037\", \"502109000037\"]" ] }
          }
        ]
      }
    }
  },
  "executionStats": {
    "executionTimeMillis": 1,
    "totalKeysExamined": 1,
    "totalDocsExamined": 1
  }
}

Expected Behavior

The query should return results in a reasonable time frame (similar to the MongoDB execution time, with minimal additional overhead).

@totomers
Copy link
Author

It's worth noting that the issue is not observed in 6.12.9, but is observed in Mongoose 6.13.8.

After the Atlas Version 8.0.4 was set, I tested the following Mongoose versions to limit the scope of the issue:

mongoose 8.9.5 (+ native MongoDB driver 6.12.0) - significant time delays.

mongoose 8.9.4 (+ native MongoDB driver 6.12.0) - significant time delays.

mongoose 8.9.0 (+ native MongoDB driver 6.12.0) - significant time delays.

mongoose 8.9.0 (+ native MongoDB driver 6.10.0 override) - significant time delays.

mongoose 7.8.4 (+ native MongoDB driver 5.9.2) -significant time delays.

mongoose 6.13.8 (+ native MongoDB driver 4.17.2) - significant time delays.

mongoose 6.12.9 (+ native MongoDB driver 4.17.2) - Fast response!

@vkarpov15 vkarpov15 added this to the 8.10.1 milestone Feb 10, 2025
@vkarpov15
Copy link
Collaborator

Are you able to bisect the exact version any further? Specifically, I suspect the culprit may be 6.13.4 and #15043, but I would like to confirm.

@clamb-dunbar
Copy link

For what it's worth; I've also experienced the same slow queries when using mongoose vs mongo drivers (6.13.0). Tracked it down to the change occurring between these 2 versions of mongoose.
8.8.1 fast
8.8.2 slow

@vkarpov15
Copy link
Collaborator

@clamb-dunbar that's another data point in favor of #15039 / #15043, which was also released in 8.8.2. Can you give me an idea of how much % of performance regression you're seeing? Also, what does your build system look like and are you using any tools that augment Node.js stack traces?

@clamb-dunbar
Copy link

clamb-dunbar commented Feb 11, 2025

It's very early in the project lifecycle so don't have much logging. It's all built using gha; but the package management is handled by renovate-bot so ensure that we don't roll new version out unless we test them.
Mongo call to get the value from a collection with only 1 record in it was ~ 50ms with the rest of the endpoint overhead; replaced that same call using a mongoose model and it was around 800ms.

edit after totmers posted My project is indeed running inside a Lambda so consistent with their findings

@totomers
Copy link
Author

Update - Mongoose Performance Issue and Fix

After upgrading Mongoose from version 6.12.9 to 8.10.0, queries executed inside AWS Lambda using the Serverless Framework became four times slower. However, the same queries remained fast when executed outside the framework (e.g., locally, in a manually deployed Lambda, or using the native MongoDB driver).

Extensive debugging revealed that the issue was not caused by Mongoose itself but rather by how it was bundled inside the Lambda function when using esbuild. Moving Mongoose to an AWS Lambda Layer restored optimal query performance. The fix was to explicitly exclude mongoose and mongodb in the esbuild configuration (exclude: ["mongoose", "mongodb"]). This ensured that the Lambda function used the version from the Lambda Layer instead of bundling its own copy, which resolved the performance issue.

Possible Cause

My theory is that this might be due to dynamic imports within the Mongoose module, which were affected by esbuild's tree shaking when packaging the Lambda function. Could this be the case? If so, is there a way to overcome this so Mongoose doese not need to be moved to an AWS Lambda Layer?

Alternative Solutions Tried

Upgrading esbuild and serverless-esbuild and including mongoose and mongodb in the esbuild bundle did not resolve the issue:

"esbuild": "^0.24.2"

"serverless-esbuild": "^1.54.6"

@vkarpov15
Copy link
Collaborator

We haven't tried Mongoose with esbuild, so we don't know right now but we will find out. @clamb-dunbar are you also using esbuild?

@clamb-dunbar
Copy link

Yes. Building with a sam template that uses esbuild.

@vkarpov15 vkarpov15 modified the milestones: 8.10.1, 8.10.2 Feb 14, 2025
@vkarpov15
Copy link
Collaborator

I wasn't able to repro this locally using esbuild:

import mongoose from "mongoose";

const MONGO_URI = "mongodb://localhost:27017/testdb"; // Update with your database

// Define User schema and model
const userSchema = new mongoose.Schema({
  name: String,
  email: { type: String, unique: true },
  age: Number,
}, { timestamps: true });

const User = mongoose.model("User", userSchema);

async function main() {
  try {
    // Connect to MongoDB
    await mongoose.connect(MONGO_URI);

    // Clear existing users (optional)
    await User.deleteMany({});
    console.log("Cleared existing users");

    // Insert a user
    const newUser = await User.create({ name: "Alice", email: "[email protected]", age: 30 });
    console.log("Inserted user:", newUser);

    // Fetch all users
    const start = Date.now();
    const users = await User.find();
    console.log("All users:", users, Date.now() - start);

  } catch (error) {
    console.error("Error:", error);
  } finally {
    await mongoose.disconnect();
    console.log("Disconnected from MongoDB");
  }
}

// Run the script
main();

Output:

$ npx esbuild index.mjs --bundle --platform=node --outfile=dist/script.js

  dist/script.js  2.6mb ⚠️

⚡ Done in 57ms
$ node ./dist/script.js 
Cleared existing users
Inserted user: {
  name: 'Alice',
  email: '[email protected]',
  age: 30,
  _id: new ObjectId('67b358cf3efd8e4dd6c1a284'),
  createdAt: 2025-02-17T15:42:07.381Z,
  updatedAt: 2025-02-17T15:42:07.381Z,
  __v: 0
}
All users: [
  {
    _id: new ObjectId('67b358cf3efd8e4dd6c1a284'),
    name: 'Alice',
    email: '[email protected]',
    age: 30,
    createdAt: 2025-02-17T15:42:07.381Z,
    updatedAt: 2025-02-17T15:42:07.381Z,
    __v: 0
  }
] 3
Disconnected from MongoDB

We will try to set up serverless framework with Lambda to see if we can repro there.

@vkarpov15
Copy link
Collaborator

Still unable to repro on AWS Lambda with serverless. Below is my handler.mjs:

import mongoose from "mongoose";

const MONGO_URI = process.env.MONGO_URI; // Use an environment variable

const userSchema = new mongoose.Schema({
  name: String,
  email: { type: String, unique: true },
  age: Number,
}, { timestamps: true });

const User = mongoose.model("User", userSchema);

export async function main(event) {
  try {
    await mongoose.connect(MONGO_URI);
    console.log("Connected to MongoDB");

    await User.deleteMany({});

    // Insert a user (example)
    const newUser = await User.create({ name: "Lambda User", email: "[email protected]", age: 25 });
    console.log("Inserted user:", newUser);

    // Fetch all users
    const start = Date.now();
    const user = await User.findOne();

    return {
      statusCode: 200,
      body: JSON.stringify({ user, elapsedMS: Date.now() - start }),
    };
  } catch (error) {
    console.error("Error:", error);
    return {
      statusCode: 500,
      body: JSON.stringify({ error: error.message }),
    };
  } finally {
    await mongoose.disconnect();
    console.log("Disconnected from MongoDB");
  }
}

Here's my serverless.yaml with Atlas connection string omitted

service: mongoose-lambda

provider:
  name: aws
  runtime: nodejs18.x
  region: us-east-1
  environment:
    MONGO_URI: "XYZ"

functions:
  app:
    handler: handler.main
    events:
      - httpApi:
          path: /
          method: get

package:
  patterns:
    - node_modules/**
    - handler.mjs

custom:
  esbuild:
    bundle: true
    minify: true
    external: []
    platform: node
    target: node18

Output looks like this:

{"user":{"_id":"67b3619f81bfa5087f657659","name":"Lambda User","email":"[email protected]","age":25,"createdAt":"2025-02-17T16:19:43.214Z","updatedAt":"2025-02-17T16:19:43.214Z","__v":0},"elapsedMS":3}

Mongoose version 8.10.1, [email protected].

If you're running into this issue, can you please provide more detailed repro instructions? I would need a complete serverless.yaml (make sure to omit connection string etc) and exact version of serverless you're using @clamb-dunbar @totomers

@vkarpov15 vkarpov15 added can't reproduce Mongoose devs have been unable to reproduce this issue. Close after 14 days of inactivity. and removed performance labels Feb 17, 2025
@vkarpov15 vkarpov15 removed this from the 8.10.2 milestone Feb 17, 2025
@clamb-dunbar
Copy link

I've been using a sam template.yaml - i'll try and spend some time today making an example for you

@vkarpov15
Copy link
Collaborator

What is "sam" in this context?

@clamb-dunbar
Copy link

@vkarpov15 After much poking of things; it looks like the problem occurs when enabling Sourcemap for the esbuild section of the sam template. If i'm on mongoose 8.8.1 that has no affect, under mongoose 8.8.2 having that set as true results in things being much slower - toggle it to false and the performance returns.

Metadata:
  BuildMethod: esbuild
  BuildProperties:
    Sourcemap: true
    EntryPoints:
      - src/noauth-api.ts

@hansgen
Copy link

hansgen commented Feb 25, 2025

Just wanted to chime in we're experiencing a 2-4x performance degradation as well in our product after upgrading from <8.8.2 to 8.10.1.

We're using AWS CDK, NodeJS, Typescript. AWS CDK bundles the lambda using esbuild.

Disabling sourcemaps restored the performance.

Pseudocode -- this is what we used to do

import { NodejsFunction } from 'aws-cdk-lib/aws-lambda-nodejs';

new NodejsFunction(this, 'my-function', {
   bundling: {
      sourceMap: true
   },
   environment: {
      NODE_OPTIONS:  '--enable-source-maps'
   }
});

package.json

"devDependencies": {
    "esbuild": "^0.25.0",
    "aws-cdk-lib": "^2.179.0",
}

Snapshot of performance of a randomly chosen Lambda before/after:

Image

@vkarpov15 vkarpov15 removed the can't reproduce Mongoose devs have been unable to reproduce this issue. Close after 14 days of inactivity. label Feb 25, 2025
@vkarpov15 vkarpov15 modified the milestones: 8.11.1, 8.12.1, 8.12.2 Feb 25, 2025
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