Query speed for documents containing arrays on M2 instance very sluggish

Hello,

I have an web app that is connected to a database with approx 10000 documents (about 30mb) on a M2 instance. Each document have 35 fields of which 4 are array fields. 3 array fields for numbers, where the biggest array has 168 elements, and 1 array with mixed data types. In my world this constitute a small database with little data.

The problem I have is that simple queries where I include the array fields take a lot of time to return. Note that I do not do any sorting or anything on those arrays. With out the array fields a typical query I make takes about 300ms to return. For each array field I include it adds about one second(!) to the query, and if I include all 4 the query takes about 4-5 seconds to return.

What is also very odd, is that from time to time, there is no slow down when I add the array fields. Then it stays like that for some hours or a day, then it goes back backing super slow again. This affects both my production code and my development code at the same time. According to MongoCompass the query is lightning fast, as I imagine it should be. But in reality it is not.

Any suggestion what could be wrong?

I am using node, express, and mongoose.

Regards

/Anders

Hi @Anders_Lindstrom - Welcome to the community.

Could you provide the following information regarding the query performance you’re experiencing?:

  1. Output of db.collection.explain("executionStats").find(...) for the query(s) you’re measuring
  2. Output of db.collection.getIndexes()
  3. Clarification if you’re just more recently experiencing this behaviour for the same queries or if it has been happening from the beginning
  1. Steps on how you verified / MongoDB compass has advised the above and what you mean by “lightning fast” - i.e. <100ms, <10ms, etc.
  2. Some sample documents

Please remove any personal or sensitive information before posting here.

Look forward to hearing from you.

Regards,
Jason

1 Like

Hello Jason,

Thank you for your reply. Right now when I was about to do the tests you suggested, the speed up is there. But I’ll give you the results anyway, so you do not think I am ignoring your reply. So.

I will start with replying to point 3: Yes I have experienced it from the beginning. I started my Atlas usage with a M0 instance to get things setup. Then I upgraded to a M2 instance. The performance issues have been there all the time on both instances.

4: Lightning fast means double digit ms execution times, as you can see its about 20ms

For or point 5 I have attached a dropbox link to a json file with 10 documents with no personal data (new users can not upload files here…).

5: Dropbox - sampledocuments.json - Simplify your life

For point 1 & 2 I just copy the output.

1 & 2:
executionSuccess: true,
nReturned: 100,
executionTimeMillis: 22,
totalKeysExamined: 0,
totalDocsExamined: 11524,
executionStages: {
stage: ‘PROJECTION_DEFAULT’,
nReturned: 100,
executionTimeMillisEstimate: 11,
works: 11927,
advanced: 100,
needTime: 11826,
needYield: 0,
saveState: 11,
restoreState: 11,
isEOF: 1,
transformBy: { anim: 0 },
inputStage: {
stage: ‘SKIP’,
nReturned: 100,
executionTimeMillisEstimate: 10,
works: 11927,
advanced: 100,
needTime: 11826,
needYield: 0,
saveState: 11,
restoreState: 11,
isEOF: 1,
skipAmount: 0,
inputStage: [Object]
}
},
allPlansExecution:
}
[
{ v: 2, key: { _id: 1 }, name: ‘id’ },
{ v: 2, key: { id: 1 }, name: ‘id_1_autocreated’ }
]

Let me know if there is any more info you need right now? I will get back when the speed goes down again

Regards

/Anders

Thanks for providing all those details Anders! I can’t see anything out of the blue in terms of the execution time but I believe another piece of information I would require is - how are you measuring the 300ms and 4-5 seconds to return (assuming the executionTime is 22ms).

Based off the execution stats output you provided - I wasn’t able to locate any particular filter. Can you share the full query used? I imagine it may look something like db.collection.find({},{<projection>}).skip(...) but will wait for your confirmation.

Lastly, can you try running the same queries using mongosh to see if the performance you’re experiencing is the same? This may give us an indication on whether or not it has something to do with the app code.

Might be also worth checking with the in-app chat support team if you have exceeded any data transfer limitations (it is the sum based off all nodes).

Regards,
Jason

Hello Jason,

Thank you for your quick reply.
Well, right now the database is back to it slow performance again. I measure the speed in my code, I just time the completion of the of the .find() operation. But it is also directly visible in the app. With server side page rendering loading in data for 100 documents to the browser takes about 700-1000ms when the database is fast and 4500-5500ms when it is slow. I suppose the 22ms is just the internal computation time for the operation but then there is some overhead for the actual transfer. But 4-5 seconds is way to much for the small amount of data that is transferred.

However, I have tried with mongosh and I get the same results, i.e., it is really slow. I guess that this means that its not my app code that is the problem.

here is a fully query that takes about 4-5 seconds to get the data from. note the two empty {}, they are additional filters but I left them empty for the test query. andding addtional filters do not change the time. But what change the time is if I remove the array fields. in this query the “anim” field is excluded by “default”. If I exclude all the array fields then the round takes about one second less per array field!

db.collection.find({$and:[{mcaprank: {$ne : null} }, {}, {}]}, { anim: 0 }).limit(100).sort({mcaprank:-1}).skip(0)

Regards

/Anders

Interesting - I’ll try reproduce this behaviour if I can on an M0 using mongosh.

I do note that you’ve noted it happened “all the time” on both instances however you’ve written “is back to slow performance again”. Does this mean it was faster at some points? Just want to clarify - If there are some scenarios where it is performing faster you should check with the atlas in-app chat support team if you’ve exceeded any limitations which result in throttling.

Regards,
Jason

Can you explain the behaviour you experienced with mongosh? I tried to see if I could notice any “slow” performance in mongosh but the command itself I ran against 10040 sample documents based off the ones you provided returned the cursor and first 20 results of the cursor almost instantaneously. I also ran the execution stats and got a similar time ~18ms:

perfdb> db.test.countDocuments()
10040
perdb> db.test.find({$and:[{mcaprank: {$ne : null} }, {}, {}]}, { anim: 0 }).limit(100).sort({mcaprank:-1}).skip(0).explain("executionStats")
{
  explainVersion: '1',
  queryPlanner: {
    namespace: 'perfdb.test',
    indexFilterSet: false,
    parsedQuery: { mcaprank: { '$not': { '$eq': null } } },
    queryHash: '2921F291',
    planCacheKey: 'D913DAF6',
    maxIndexedOrSolutionsReached: false,
    maxIndexedAndSolutionsReached: false,
    maxScansToExplodeReached: false,
    winningPlan: {
      stage: 'PROJECTION_DEFAULT',
      transformBy: { anim: 0 },
      inputStage: {
        stage: 'SORT',
        sortPattern: { mcaprank: -1 },
        memLimit: 33554432,
        limitAmount: 100,
        type: 'simple',
        inputStage: {
          stage: 'COLLSCAN',
          filter: { mcaprank: { '$not': { '$eq': null } } },
          direction: 'forward'
        }
      }
    },
    rejectedPlans: []
  },
  executionStats: {
    executionSuccess: true,
    nReturned: 100,
    executionTimeMillis: 18,
    totalKeysExamined: 0,
    totalDocsExamined: 10040,
    executionStages:
...

Hello Jason,

Sorry for my late reply. What I mean with the slow behavior in mongosh is that when I used the find() it took 4-5 seconds before the respond start to print out ( I have a fast internet connection). So even if the internal search is fast, the round trip is SLOW. IF I remove the array fields from what I want to get return it decrease the time it takes about a second per field I remove.

Regards

/Anders