4

I'm working with an application using MongoDB that is getting a fairly large number of incoming requests and I've noticed that the responses are getting slower as the number of requests get higher.

I'm suspecting that there is some inefficiency with the database. I ran mongostat during one of our higher load periods and the result seems to indicate high lock percentage:

insert  query update delete getmore command flushes mapped  vsize    res faults           locked db idx miss %     qr|qw   ar|aw  netIn netOut  conn set repl       time
*0   1120    479     *0     179   472|0       0  72.1g   146g  1.31g      0 server-prod:15.7%          0       0|0     1|0     1m     4m   298 rs0  PRI   15:37:28
*0   1192    509     *0     178   428|0       0  72.1g   146g   1.3g      0 server-prod:18.9%          0       0|0     0|0     1m     5m   298 rs0  PRI   15:37:29
*0   1107    456     *0     174   362|0       0  72.1g   146g   1.3g      0 server-prod:20.4%          0       0|0     2|1     1m     5m   298 rs0  PRI   15:37:30
*0   1320    556     *0     211   532|0       0  72.1g   146g   1.3g      0 server-prod:19.5%          0       0|0     0|1     1m     6m   298 rs0  PRI   15:37:31
*0   1094    474     *0     179   449|0       0  72.1g   146g   1.3g      0 server-prod:15.7%          0       0|0     0|0     1m     5m   298 rs0  PRI   15:37:32
*0   1120    487     *0     184   458|0       0  72.1g   146g   1.3g      0 server-prod:20.8%          0       0|0     1|1     1m     5m   298 rs0  PRI   15:37:33
*0    807    299     *0     108   270|0       0  72.1g   146g   1.3g      0 server-prod:15.3%          0     103|1     0|3     1m     3m   298 rs0  PRI   15:37:34
*0   1613    709     *0     161   146|0       0  72.1g   146g   1.3g      0 server-prod:63.5%          0       0|0     1|0     2m     7m   298 rs0  PRI   15:37:35
*0   1133    472     *0     167   341|0       0  72.1g   146g  1.31g      0 server-prod:21.2%          0       1|0     0|1     1m     6m   298 rs0  PRI   15:37:36
*0   1292    555     *0     189   440|0       0  72.1g   146g  1.31g      0 server-prod:23.3%          0       5|0     1|4     2m     6m   298 rs0  PRI   15:37:37

The 3rd line from the bottom has a lock percentage of 60% which is pretty crazy considering the average lock percentage is around ~20%. On higher loads the average goes up to 35-40%.

I also ran show log in my production mongo shell and have not seen a single query that ran below 100ms. Some of the queries have an execution time of ~700ms to 1s.

The machine the database is running on might also be the problem (an n1-standard-1 (1 vCPU, 3.8 GB memory) google compute engine VM instance). The database is also structured as a three-member replica set (one primary and two secondaries with no arbiter).

What are some ways I can troubleshoot and increase my query speed?

Thanks!

EDIT: Forgot to mention that I'm using Mongo v2.6

EDIT: Here is the output of db.stats()

{
"db" : "server-prod",
"collections" : 20,
"objects" : 36560,
"avgObjSize" : 359.20568927789935,
"dataSize" : 13132560,
"storageSize" : 43479040,
"numExtents" : 62,
"indexes" : 24,
"indexSize" : 6189232,
"fileSize" : 67108864,
"nsSizeMB" : 16,
"dataFileVersion" : {
    "major" : 4,
    "minor" : 5
},
"extentFreeList" : {
    "num" : 0,
    "totalSize" : 0
},
"ok" : 1

}

EDIT: Last night I saw my CPU go up to 128% during peak load hours, how is this possible? (This is a single core machine)

EDIT: I created indexes on some of the most queried fields and noticed an increase in performance, however, the update queries are still taking way too long (~500-800ms). What are some optimisations I can do to increase update/insert performance?

Improve this question
5
  • a.) Find out your working set size. (db.serverStatus()). This will give us an idea if the System memory is limiting factor. b.) regarding the queries do an explain and check if you can use covered indexes in your queries by selecting only indexed fields.
    – vishad
    Jun 16, 2015 at 12:51
  • Have you checked indexes and explained your slow queries? Note: you won't see any queries slower than 100ms in the logs because that's the default slow query threshold. If you can share the logs there is probably helpful context such as other slow operations. I would recommend watching Asya's talk on Debugging & Diagnostics for some background on performance troubleshooting.
    – Stennie
    Jun 16, 2015 at 22:21
  • @vishad I posted the db.stats() output, which part of the db.serverStatus() output should I post? It's pretty big and detailed so I'm assuming posting the entire thing would be overkill.
    – Alistair
    Jun 17, 2015 at 6:53
  • @Stennie, I did, the thing is when I connect to the shell and execute the same query it only takes around ~3-4ms, but if I repeatedly execute the same query over and over again, I will see it go up to 200-300ms and then it goes back to 3-4ms.
    – Alistair
    Jun 17, 2015 at 6:54
  • @Alistair Worth posting a separate question on a query/update that has variable performance. If there are multiple candidate indexes, perhaps a poor index is periodically being chosen? You should include the output of 'explain(true)' for the query which will show more details on the candidate indexes considered. Also to note: query timing with explain() is expected to be slower than the actual runtime of the query as you are forcing plan evaluation.
    – Stennie
    Jun 26, 2015 at 3:29

1 Answer 1

Reset to default
5

To see if the hardware is not limiting:

  • top/htop => cpu percentage
  • iostat -x 1 => sysstat tool to see disk r/w limits (%util)

Concerning locking:

  • Mongo 2.6 : database locking
  • Mongo 3.0 + MMAPv1 storage engine : collection locking
  • Mongo 3.0 + WiredTiger storage engine : document locking

If you have 1 huge collection (server-prod), maybe Sharding is an option to distribute the load, or more cores + less locking with Mongo3.0

Improve indexes: - More indexes = slower write + faster read - Less indexes = faster write + slower read

Read from Secondaries, Only write on Primary.

> db.setProvilingLevel(1,4)  ##  save slow logs for that db slower than 4ms
> db.system.profile.find({millis:{$gt:100}}).sort({ts:-1}) ## find queries slower than 100ms, order by timestamp descending
> ....query.explain()  ## find out which indexes it uses

Information: http://docs.mongodb.org/manual/administration/optimization/

Improve this answer
2
  • The primary database is always around 90% cpu, along with 70-80% memory usage. I will check iostat as well.
    – Alistair
    Jun 16, 2015 at 7:49
  • New course of M202: MongoDB Advanced Deployment and Operations starts August 4th : university.mongodb.com/courses/M202/about
    – aldwinaldwin
    Jun 16, 2015 at 8:09

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.