Memory spike when using find()

[almeidx]

Do you want to request a feature or report a bug?
Report a bug

What is the current behavior?
When I make a Model#find call with an $or operator, not only does the operation take ~5 minutes, it also takes up ~1 GB memory.

If the current behavior is a bug, please provide the steps to reproduce.
My use-case:

  const result = await Guild.find({
    $or: [
      { premium: { $eq: true } },
      { prefix: { $ne: 'p!' } },
      { blacklistedChannels: { $exists: true, $ne: [], $type: 'array' } },
    ],
  });

Reproduction repo: https://github.com/almeidx/mongoose-memory-leak-repro

When I run node index.js on this repository:

Not sure if relevant but, here are my collection details:

• documents: 8360
• size: 38.71MB

What is the expected behavior?
I expected it to not take ~5 minutes to process, but I can understand why it could take that long to process.
What I really didn't expect is the operation using ~1 GB of memory.

What are the versions of Node.js, Mongoose and MongoDB you are using? Note that "latest" is not a version.
14.17.1, 5.12.15 and 3.6.8, respectively
(I'm not sure if by 'MongoDB' you meant the mongodb npm module or the version of the database. I am using MongoDB Atlas version 4.4.6, mongodb npm module version 3.6.8)

[almeidx]

UPDATE:

I tried using return fields on the find method, and these were the results (that I'm totally okay with):

  const result = await Guild.find(
    {
      $or: [
        { premium: { $eq: true } },
        { prefix: { $ne: 'p!' } },
        { blacklistedChannels: { $exists: true, $ne: [], $type: 'array' } },
      ],
    },
    ['_id', 'premium', 'prefix', 'blacklistedChannels']
  );

[vkarpov15]

Hard to tell without taking a closer look at your data. Based on the fact that using a projection helps, my best guess is that one of the other fields is either unexpectedly massive or there's some issue with how Mongoose is handling one of the data types in your schema.

Are you able to determine which field you need to add in order to trigger the spike in memory usage? Also, does using lean() make a difference?

I've been able to trigger similar memory spikes, but I get the same memory spike using lean(), so it doesn't look like it's due to an issue with Mongoose schema types. Below is the latest iteration of the script I've been using to try to create data to repro this.

'use strict';

const mongoose = require('mongoose');
const Guild = require('./database/guild');

run().catch(err => console.log(err));

async function run() {
  await mongoose.connect('mongodb://localhost:27017/test', {
    useCreateIndex: true,
    useFindAndModify: false,
    useNewUrlParser: true,
    useUnifiedTopology: true,
  });

  await mongoose.connection.dropDatabase();

  for (let i = 0; i < 8360; ++i) {
    const xpRoles = {};
    for (let j = 0; j < 100; ++j) {
      xpRoles[`test${i}_${j}`] = [`test${i}`, `test${j}`];
    }

    await Guild.create({
      _id: `guild${i}`,
      autoPublishChannels: ['test'],
      autoResetLevels: i,
      autoRole: ['test'],
      autoRoleTimeout: i,
      blacklistedChannels: ['foo', 'bar'],
      counts: [],
      emojiList: true,
      emojiListChannel: 'test',
      leftAt: i,
      levels: true,
      mentionCooldown: 17 * i,
      mentionCooldownRoles: ['test'],
      mentionedRoles: [{ _id: `test${i}`, date: new Date() }],
      milestones: [{ count: 1, date: new Date(), member: 'test' }],
      milestonesChannel: 'test',
      milestonesInterval: 42,
      milestonesMessage: 'test',
      milestonesRoles: ['test'],
      noXpRoles: ['test'],
      prefix: 'foo',
      premium: true,
      prioritiseMultiplierRoleHierarchy: true,
      stackXpRoles: true,
      storeCounts: true,
      storeMilestones: true,
      topXp: 'test',
      topXpRole: 'test',
      xpBlacklistedChannels: ['test'],
      xpMessage: 'test',
      xpMultipliers: [{ multiplier: 2, targets: ['test'], type: 'test' }],
      xpResponseType: 'test',
      xpRoles,
      xpWhitelistedChannels: ['test']           
    });
    console.log(i);
  }
}

[almeidx]

@vkarpov15 I won't be able to test anything for the time being. But here are some stats that might help to answer your question:

• the counts array could have anywhere from 0 to 200 items per document
• the milestones array could have anywhere from 0 to 50 items per document

I'm guessing those are the only fields that could be causing some trouble. I don't know if that is they are considered exceedingly large

If they are problematic, would you suggest I use a separate collection for each mapped by the guild id instead, each count/milestone being its own document?

[vkarpov15]

@almeidx a separate collection could help if large arrays arrays or maps are causing this issue. I'll take another shot at repro-ing this later this week.

[vkarpov15]

We took a closer look using data generated via the below script and it looks like counts is causing a disproportionately large spike in memory usage. We're investigating why.

'use strict';
  
const mongoose = require('mongoose');
const Guild = require('./database/guild');

run().catch(err => console.log(err));

async function run() {
  await mongoose.connect('mongodb://localhost:27017/test', {
    useCreateIndex: true,
    useFindAndModify: false,
    useNewUrlParser: true,
    useUnifiedTopology: true,
  });

  await mongoose.connection.dropDatabase();

  for (let i = 0; i < 8360; ++i) {
    const xpRoles = {};
    for (let j = 0; j < 100; ++j) {
      xpRoles[`test${i}_${j}`] = [`test${i}`, `test${j}`];
    }

    const counts = [];
    for (let j = 0; j < 200; ++j) {
      counts.push([{ date: new Date(), count: j * 17 }]);
    }

    const milestones = [];
    for (let j = 0; j < 50; ++j) {
      milestones.push([{ count: j * 17, date: new Date(), member: '0'.repeat(100) }]);
    }

       await Guild.create({
      _id: `guild${i}`,
      autoPublishChannels: ['test'],
      autoResetLevels: i,
      autoRole: ['test'],
      autoRoleTimeout: i,
      blacklistedChannels: ['foo', 'bar'],
      counts,
      emojiList: true,
      emojiListChannel: 'test',
      leftAt: i,
      levels: true,
      mentionCooldown: 17 * i,
      mentionCooldownRoles: ['test'],
      mentionedRoles: [{ _id: `test${i}`, date: new Date() }],
      milestones,
      milestonesChannel: 'test',
      milestonesInterval: 42,
      milestonesMessage: 'test',
      milestonesRoles: ['test'],
      noXpRoles: ['test'],
      prefix: 'foo',
      premium: true,
      prioritiseMultiplierRoleHierarchy: true,
      stackXpRoles: true,
      storeCounts: true,
      storeMilestones: true,
      topXp: 'test',
      topXpRole: 'test',
      xpBlacklistedChannels: ['test'],
      xpMessage: 'test',
      xpMultipliers: [{ multiplier: 2, targets: ['test'], type: 'test' }],
      xpResponseType: 'test',
      xpRoles,
      xpWhitelistedChannels: ['test']
    });
    console.log(i);
  }
}

For some reason .select('-counts').limit(3500) uses almost 1 GB less memory than .limit(3500) or even .select('-milestones').limit(3500)

[Uzlopak]

I run this in the mongoose benchmark folder

'use strict';
  
const mongoose = require('../lib/index');

const { Schema, model } = require('../lib/index');

const MilestoneSchema = new Schema({
  count: Number,
  date: Date,
  member: String,
});

const CountSchema = new Schema({
  count: Number,
  date: Date,
});

const MultiplierSchema = new Schema({
  multiplier: Number,
  targets: [String],
  type: String,
});

const MentionedRoleSchema = new Schema({
  _id: String,
  date: Date,
});

const GuildSchema = new Schema({
  _id: { required: true, type: String },
  autoPublishChannels: { of: String, type: Array },
  autoResetLevels: Number,
  autoRole: { of: String, type: Array },
  autoRoleTimeout: Number,
  blacklistedChannels: { of: String, type: Array },
  counts: [CountSchema],
  emojiList: Boolean,
  emojiListChannel: String,
  leftAt: Number,
  levels: Boolean,
  mentionCooldown: Number,
  mentionCooldownRoles: { of: String, type: Array },
  mentionedRoles: { of: MentionedRoleSchema, type: Array },
  milestones: [MilestoneSchema],
  milestonesChannel: String,
  milestonesInterval: Number,
  milestonesMessage: String,
  milestonesRoles: { of: String, type: Array },
  noXpRoles: { of: String, type: Array },
  prefix: String,
  premium: Boolean,
  prioritiseMultiplierRoleHierarchy: Boolean,
  stackXpRoles: Boolean,
  storeCounts: Boolean,
  storeMilestones: Boolean,
  topXp: String,
  topXpRole: String,
  xpBlacklistedChannels: { of: String, type: Array },
  xpMessage: String,
  xpMultipliers: { of: MultiplierSchema, type: Array },
  xpResponseType: String,
  xpRoles: { of: [String], type: Map },
  xpWhitelistedChannels: { of: String, type: Array },
},  {versionKey: false });
const Guild = model('guilds', GuildSchema)

run().catch(err => console.log(err));

async function run() {
  await mongoose.connect('mongodb://localhost:27017/test', {
    useNewUrlParser: true,
    useUnifiedTopology: true,
  });

  await mongoose.connection.dropDatabase();

  setInterval(() => {
    console.log('[Timer] Memory usage:', process.memoryUsage().heapUsed / (1024 ** 2));
  }, 10_000);

  for (let i = 0; i < 8360; ++i) {
    const xpRoles = {};
    for (let j = 0; j < 100; ++j) {
      xpRoles[`test${i}_${j}`] = [`test${i}`, `test${j}`];
    }

    const counts = [];
    for (let j = 0; j < 200; ++j) {
      counts.push([{ date: new Date(), count: j * 17 }]);
    }

    const milestones = [];
    for (let j = 0; j < 50; ++j) {
      milestones.push([{ count: j * 17, date: new Date(), member: '0'.repeat(100) }]);
    }

       await Guild.create({
      _id: `guild${i}`,
      autoPublishChannels: ['test'],
      autoResetLevels: i,
      autoRole: ['test'],
      autoRoleTimeout: i,
      blacklistedChannels: ['foo', 'bar'],
      counts,
      emojiList: true,
      emojiListChannel: 'test',
      leftAt: i,
      levels: true,
      mentionCooldown: 17 * i,
      mentionCooldownRoles: ['test'],
      mentionedRoles: [{ _id: `test${i}`, date: new Date() }],
      milestones,
      milestonesChannel: 'test',
      milestonesInterval: 42,
      milestonesMessage: 'test',
      milestonesRoles: ['test'],
      noXpRoles: ['test'],
      prefix: 'foo',
      premium: true,
      prioritiseMultiplierRoleHierarchy: true,
      stackXpRoles: true,
      storeCounts: true,
      storeMilestones: true,
      topXp: 'test',
      topXpRole: 'test',
      xpBlacklistedChannels: ['test'],
      xpMessage: 'test',
      xpMultipliers: [{ multiplier: 2, targets: ['test'], type: 'test' }],
      xpResponseType: 'test',
      xpRoles,
      xpWhitelistedChannels: ['test']
    });
  }
}

It seems that the memory leak now is just the many many strings we are creating on the fly

[vkarpov15]

We made a few minor improvements in 1a1d3cc. We also found that removing _id in countSchema, or creating your own _id without a default (_id: 'ObjectId') improves memory usage significantly: shaves off over 10% in our benchmark.

We're looking to see if there's a way to avoid running extra unnecessary _id defaults.

[vkarpov15]

Shaved off another 10% in 4c85c70 by properly passing skipId for array subdocuments. That means we've reduced the memory usage by about 50% overall since we've started working on this 👍