Mongo slow query - timeAcquiringMicros

[sajit mathew kunnumkal]

Hi,

I am looking into some slow queries against mongo. The one thing I notice is that timeAcquiringMicros  is  taking a long time.

For example,

locks:{ Global: { acquireCount: { r: 10 }, acquireWaitCount: { r: 5 }, timeAcquiringMicros: { r: 2388792 } }, Database: { acquireCount: { r: 5 } }, Collection: { acquireCount: { r: 5 } } }

{and total time for the read operation is 2667ms.


Running the same query at other times is trivially fast ( around 78 ms)

Any insight on what could be going on? What are some of the things I should be monitoring to get an idea.

This is a sharded & replicated mongo cluster. (10 shards & 3 set replica)

Any help is appreciated. Thank you.

[Kevin Adistambha]

Hi Sajit

There could be many different reason why a query can be slow. For example, if the cluster is busy, long query times would be expected. Another is if you perform the query against a secondary, where it will block reads during oplog apply operations.

You mentioned that “at other times” the query is fast. Is there a different load on the cluster, different time of day, etc. that you can observe?

You might want to investigate further using mongostat and mongotop to see if there’s any pattern.

If you’re still having issues, could you post more information:

• Your MongoDB version and your OS version
• The detail of your query (output of db.collection.explain().find(...), whether this is through mongos or not, example documents, etc.)
• Have you peruse the Production Notes and ensure that your deployment follows the recommended settings
• Any error/notable lines you can see in the mongod and mongos logs

Best regards
Kevin

​