Hi guys,
Today I want to talk about performance issues on MongoDB.
As a dba you may informed by users or developers that the queries respond very late.
When you check the connection numbers you may see high connection numbers.
|
1 |
db.serverStatus().connections |
You may see the system slowness from shard logs.
As a note if you want to see the long running queries in your logs you need to open database profiler.
Default level is 0 and no data is collected. In the example the queries last more than 100ms will be written to log files.
|
1 |
db.setProfilingLevel(1, { slowms: 100 }) |
In shard logs, the long running queries are listed like this:
COMMAND [conn290105] command db.BigCollection command: find { find: “BigCollection”, filter: { ColumnName: “xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx” }, projection: { $sortKey: { $meta: “sortKey” } }, sort: { _id: 1 }, limit: 1, shardVersion: [ Timestamp 0|0, ObjectId(‘000000000000000000000000’) ] } planSummary: IXSCAN { _id: 1 } keysExamined:950906 docsExamined:950906 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:7476 nreturned:0 reslen:224 locks:{ Global: { acquireCount: { r: 14954 } }, Database: {acquireCount: { r: 7477 } }, Collection: { acquireCount: { r: 7477 } } }protocol:op_command 2151786ms
COMMAND [conn307304] command kpsdb.db.BigCollection command: find {find: “BigCollection”, filter: { ColumnName:”xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx” },projection: { $sortKey: { $meta: “sortKey” } }, sort: { _id: 1 }, limit: 1, shardVersion: [ Timestamp 0|0,ObjectId(‘000000000000000000000000’) ] }planSummary: IXSCAN { _id: 1 } keysExamined:955760 docsExamined:955760 cursorExhausted:1keyUpdates:0 writeConflicts:0 numYields:7624 nreturned:0 reslen:224 locks:{Global: { acquireCount: { r: 15250 } }, Database: { acquireCount: { r: 7625 } },Collection: { acquireCount: { r: 7625 } } } protocol:op_command 4227699ms
Here we can get some information from this log:
1- The query operates on the collection named BigCollection.
2- The query gets data by filtering ColumnName.
3- In planSummary we can see IXSCAN that means index scanning is used.
Until here everything seems good. Index scan is ok but the point is keyExamined and docsExamined values.
4- docsExamined value shows us how many documant is accessed from disk. Here this value is 955760
Although the query result won’t give 955760 documents database needs to check 955760 document.
This shows us the used index is not the one we want!
With this index query lasts in 4227699ms. And this is a very high value for MongoDB.
This affects the other sessions and session values on Mongos are increasing.
If the session limit is hit then timeout errors are given to users.
This bad index does not affect only the users and the application, it also affects the replication process.The congestion in the primary node leads to send timeout messages to secondary. And secondary goes in the recovery state.
What is the solution?
We need to create the right index on the collection:
|
1 2 |
db.BigCollection.getIndexes() db.BigCollection.createIndex({ColumnName: 1}, {background: true}); |
Then from the logs you can see the queries are faster and there are no timeout messages.
The indexes are one of the most important objects in MongoDB.
The developers must check the explain plans and create appropriate indexes before deploying.
Checking explain plans will be subject of another post.
