I have been experiencing slow mongo queries suddenly. The execution times varies very randomly. Initially I was suspecting this expensive aggregation operation :-
{ "appName": "XXXXXX", "operation": { "aggregate": "ABC", "pipeline": [ { "$match": { "is_deleted": false, "seller_company_id": { "$oid": "XXXXX" }, "is_hidden": false, "meetings": { "$elemMatch": { "is_meeting_deleted": { "$in": [ false, null ] } } } } }, { "$lookup": { "from": "Company", "let": { "companyId": "$seller_company_id" }, "pipeline": [ { "$match": { "$expr": { "$eq": [ "$_id", "$$companyId" ] } } }, { "$project": { "configuration.crm_stages": 1 } } ], "as": "company" } }, { "$unwind": "$company" }, { "$addFields": { "crm_stage_info": { "$ifNull": [ { "$first": { "$filter": { "input": { "$ifNull": [ "$company.configuration.crm_stages", [] ] }, "as": "stage", "cond": { "$eq": [ "$$stage.name", "$crm_stage.name" ] } } } }, null ] } } }, { "$addFields": { "crm_stage": { "$cond": [ { "$ne": [ "$crm_stage_info", null ] }, "$crm_stage_info", "$crm_stage" ] } } }, { "$project": { "_id": 1, "name": 1, "is_lead_qualified": 1, "is_from_calendar": { "$ifNull": [ "$is_from_calendar", false ] }, "is_hidden": { "$ifNull": [ "$is_hidden", false ] }, "is_closed": { "$ifNull": [ "$is_closed", false ] }, "is_closed_won": { "$ifNull": [ "$is_closed_won", false ] }, "is_closed_lost": { "$ifNull": [ "$is_closed_lost", false ] }, "updated_on": 1, "created_on": 1, "user_id": 1, "average_sales_score": 1, "total_sales_score": 1, "crm_info": 1, "crm_stage": 1, "recent_meeting_stage": 1, "meetings": { "$map": { "input": { "$filter": { "input": { "$ifNull": [ "$meetings", [] ] }, "as": "meeting", "cond": { "$and": [ { "$ne": [ "$$meeting.is_meeting_deleted", true ] } ] } } }, "as": "meeting", "in": { "_id": "$$meeting._id", "title": "$$meeting.title", "start_meet": "$$meeting.start_meet", "end_meet": "$$meeting.end_meet", "meeting_stage": "$$meeting.meeting_stage", "bot_id": "$$meeting.bot_id", "is_completed": { "$ifNull": [ "$$meeting.is_completed", true ] }, "is_meet_proper": { "$ifNull": [ "$$meeting.is_meet_proper", true ] }, "is_copilot_allowed": { "$ifNull": [ "$$meeting.is_copilot_allowed", false ] }, "crm_push_error": "$$meeting.crm_push_error", "is_crm_data_pushed": "$$meeting.is_crm_data_pushed", "crm_push_error_info": "$$meeting.crm_push_error_info" } } } } }, { "$sort": { "meetings.start_meet": -1 } }, { "$match": { "meetings": { "$ne": [] } } }, { "$facet": { "totalCount": [ { "$count": "count" } ], "results": [ { "$skip": 0 }, { "$limit": 50 } ] } }, { "$project": { "results": 1, "total": { "$ifNull": [ { "$arrayElemAt": [ "$totalCount.count", 0 ] }, 0 ] } } } ], "$clusterTime": { "clusterTime": { "$timestamp": { "t": 1761315440, "i": 36 } }, "signature": { "hash": { "$binary": { "base64": "z5DD9Xgzf7eL3p6PhFzw3Zw9kyo=", "subType": "00" } }, "keyId": 7504763207190315000 } }, "$readPreference": { "mode": "secondaryPreferred" } }}Now for reference my Opportunities collection has a structure like this :-
{ "_id": { "$oid": "XXXX" }, "name": "Open AI", "seller_company_id": { "$oid": "XXX" }, "user_id": { "$oid": "XXX" }, "transactional_discovery_question_id": { "$oid": "XXX" }, "is_deleted": false, "is_closed": false, "is_from_calendar": false, "is_hidden": false, "created_on": { "$date": "2025-12-19T07:26:14.446Z" }, "updated_on": { "$date": "2025-03-31T07:36:51.476Z" },"meetings": [ { "_id": { "$oid": "XXX" }, "title": "ABCD", "meeting_stage": "Introduction", "start_meet": { "$date": "2024-12-20T16:30:00.000Z" }, "end_meet": { "$date": "2024-12-20T17:00:00.000Z" }, "is_completed": true, "attendees": [ . . . ], "bot_id": "XXXX", "is_meet_proper": true }, { "_id": { "$oid": "XXX" }, "title": "ABCD2", "meeting_stage": "Introduction", "start_meet": { "$date": "2024-12-20T16:30:00.000Z" }, "end_meet": { "$date": "2024-12-20T17:00:00.000Z" }, "is_completed": true, "attendees": [ . . . ], "bot_id": "XXXX", "is_meet_proper": true }, . . ]}This previously used to work fine, but the execution time has detoriated over a month and half.
Upon further investigation I checked that it's also same for the smaller queries
Query :-mongo_util.find_one(ABC_COLLECTION, {"_id": ObjectId(_id)}, {"chat_threads": 1})
The profiled times are here :-
| Sl. No | Timestamp | Time (seconds) || :----: | :-------- | :------------: || 1 | 11:08:22 | 3.2757 || 2 | 11:08:35 | 2.4719 || 3 | 11:08:38 | 0.3814 || 4 | 11:08:43 | 2.0034 || 5 | 11:08:46 | 0.4772 || 6 | 11:08:51 | 2.5315 || 7 | 11:08:58 | 1.2428 || 8 | 11:09:01 | 1.3702 || 9 | 11:09:03 | 0.3797 || 10 | 11:09:05 | 0.4925 || 11 | 11:09:06 | 0.4778 || 12 | 11:09:07 | 0.4129 || 13 | 11:09:12 | 3.6053 || 14 | 11:09:15 | 1.6135 || 15 | 11:09:16 | 0.4762 || 16 | 11:09:20 | 3.0884 |Mongo configuration :-
- M20 (General)
- 4GB RAM
- 20 GB Storage
- 2 vCPUs
For the context I migrated my DB from us region to stockholm on the exact time when the significant dip in the storage occured. And at that time the APIs got blazing fast. Post that the storage grew although there wasn't much data growth in my DB, I suspect that too as I read till the storage < RAM size the DB becomes very fast. So I am not able to figure that what's taking up that storage. As from the data explorer it showsStorage size: 468.54 MB
Also I am using DB triggers for syncing with ES.
The CPU persists to 100% throughout
- Kindly suggest me what I am doing wrong or how to debug this issue further ?
- If there is any please do provide if the expensive aggregate pipeline can be optimized further without splitting it to two different APIs
UPDATE :-Upon taking a dump and then restoring it to another DB (TEST DB) it was blazing fast. Although the test DB didn't have much load but our Prod DB doesn't have much load either, as the issue persists during the weekends too when the application usage is way too lower.
- Pull the mongod log, the slow query log should give some timing informationJoe– Joe2025-10-26 16:23:10 +00:00CommentedOct 26 at 16:23
1 Answer1
As per your suspect yes i agree that aggregation query is quiet inefficient. I am not sure if you have supportive index to these?
Base collection from where you running aggregate query should have below index:{ "seller_company_id": 1,'meetings.is_meeting_deleted':1, "is_deleted": 1,"is_hidden": 1 }
It is ok if you dont have 'meetings.is_meeting_deleted':1 in index as it is multikey.
And for the joining collection Company _id default index is sufficient.
Seems the CPU utilisation is pretty high 100% and as per the real time tab screenshot there seem lot of getMore running. I believe it is either Atlas search or the change stream. Can you help with what are the most common getMore command running?
with above info we can find some clue.
thanks,Darshan
1 Comment
{ "seller_company_id": 1,'meetings.is_meeting_deleted':1, "is_deleted": 1,"is_hidden": 1 } 2. Yes I see there are two types of getmore operations that are always there. :- a. One being run byOplogFetcher on local.oplog.rs most prolly for replication b. The others coming from my DB triggers. I have triggers on 5 collection which are subscribe to all the events [Insert, Update, Delete, Replace] These two getmore operations are always there whenever I check the real time metrExplore related questions
See similar questions with these tags.
