mongodb high cpu load

[rhchin...@gmail.com]

Hello,

I am using mongodb as a db server for one of my php web-application, my websites is deployed on amazon m3.medium instance (VCPU count:-1, RAM:- 1 3.75 GiB) and i am using  MongoDB shell version: 2.6.1 and it's a standalone instance.


Now when approx 50-60 users browse my website then cpu load of my instance goes too high when i check the cpu utilization it show me below output.

cat /proc/loadavg
35.03 32.07 36.23

And when i check which process is consuming the highest cpu then it shows
ps auxww --sort=-pcpu|head -20

mongod    4082 62.9  20.5 17521116 110368 ?     Sl   11:59  14:26 /usr/bin/mongod -f /etc/mongod.conf

it means mongodb is consuming the highest cpu and when i check the response time of queries then it shows that all the queries are taking only 500-700 ms to get execute except some queries which takes 10-11 seconds.

so If all the queries are smooth then why mongodb is consuming  too much of cpu and my site is responding extremely slow and sometimes even i don't get response.

is there any way to find out which mongodb component or which mongodb query is consuming the highest cpu so i can fix that issue.

Note:- memory utilization is not high when always 1-1.5 gb of memory is free on the server.


Best,
Chint.

[Asya Kamsky]

i already mentioned this in the other thread but 500ms is horribly slow response time - and 10 seconds is way out there - I'm guessing you don't have optimal indexes for your queries.   You already looked in the logs to see the long running queries, can you include some examples?    I suspect they involve in memory sorts or no indexes or both.

Asya

--
You received this message because you are subscribed to the Google Groups "mongodb-user"
group.
 
For other MongoDB technical support options, see: http://www.mongodb.org/about/support/.
---
You received this message because you are subscribed to the Google Groups "mongodb-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mongodb-user...@googlegroups.com.
To post to this group, send email to mongod...@googlegroups.com.
Visit this group at http://groups.google.com/group/mongodb-user.
To view this discussion on the web visit https://groups.google.com/d/msgid/mongodb-user/0df52c49-880a-4f52-b385-4506751354b6%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Asya Kamsky]

i already mentioned this in the other thread but 500ms is horribly slow response time - and 10 seconds is way out there - I'm guessing you don't have optimal indexes for your queries.   You already looked in the logs to see the long running queries, can you include some examples?    I suspect they involve in memory sorts or no indexes or both.

Asya

On Saturday, August 2, 2014, <rhchin...@gmail.com> wrote:

[rhchin...@gmail.com]

Hey Asya,

First of all, thanks for your help.

It is surprising for me thast 500ms is horribly slow response time becaue all the queries which i am running from our webapp on mongodb takes at-list 100-150 ms so my question is what i can do to achieve 5-10 ms of response time?

For your reference please see below information and the test which i run on the server.

My all the collections of db are indexed and i have enough memory on the server. i forgot to mention in the last post that mongodb is consuming too much cpu but not memory. i had enough free memory on the server when cpu load was too high,

Here i am showing you the query which is taking 10-13 second to get execute.

At first i executed free -m command to check how much free memory i have.

I had 1.5 gb of free memory available on my server.

then i started mongstat command before directly executing the query on my db.

then i executed  the query which takes the most time on my db and i executed the query with explain().

db.queue_sociallinks.find( {"flag":"","uid":"","facebook":"","twitter":"","linkedin":""}, [] ).sort( {"name":1} ).limit( 50 ).skip( 0 ).explain()

and query took 11.514 second to get execute and the output of the query is attached with this post.

And mongostats was showing below stats when this query was running on the server.
insert  query update delete getmore command flushes mapped  vsize    res faults  locked db idx miss %     qr|qw   ar|aw  netIn netOut  conn       time
    *0     *0     *0     *0       0     1|0       0  8.18g  16.7g   351m      0 mobapi:0.0%          0       0|0     1|0    62b     3k     5   18:46:48
    *0     *0     *0     *0       0     1|0       0  8.18g  16.7g   365m      0 mobapi:0.0%          0       0|0     1|0    62b     3k     5   18:46:49
    *0     *0     *0     *0       0     1|0       0  8.18g  16.7g   375m      0 mobapi:0.0%          0       0|0     1|0    62b     3k     5   18:46:50
    *0     *0     *0     *0       0     1|0       0  8.18g  16.7g   384m      0 mobapi:0.0%          0       0|0     1|0    62b     3k     5   18:46:51
    *0     *0     *0     *0       0     1|0       0  8.18g  16.7g   393m      0 mobapi:0.0%          0       0|0     1|0    62b     3k     5   18:46:52
    *0     *0     *0     *0       0     1|0       0  8.18g  16.7g   402m      0 mobapi:0.0%          0       0|0     1|0    62b     3k     5   18:46:53
     1      6     *0     *0       0    34|0       0  8.18g  16.7g   411m      0 mobapi:0.0%          0       0|0     1|0     4k     8k     6   18:46:54
     5     12     *0     *0       0    68|0       0  8.18g  16.7g   418m      0 mobapi:0.2%          0       0|0     1|0    10k    13k     5   18:46:55
insert  query update delete getmore command flushes mapped  vsize    res faults   locked db idx miss %     qr|qw   ar|aw  netIn netOut  conn       time
    *0     *0     *0     *0       0     1|0       0  8.18g  16.7g   394m      0 mobapi:2.6%          0       0|0     0|0   236b     6k     5   18:46:56
        *0     *0     *0     *0       0     3|0       0  8.18g  16.7g   394m      0   test:0.0%          0       0|0     0|0   176b     3k     5   18:46:57
    *0     *0     *0     *0       0     1|0       0  8.18g  16.7g   394m      0 mobapi:0.0%          0       0|0     0|0    62b     3k     5   18:46:58
    *0     *0     *0     *0       0     1|0       0  8.18g  16.7g   394m      0   test:0.0%          0       0|0     0|0    62b     3k     5   18:46:59
    *0     *0     *0     *0       0     1|0       0  8.18g  16.7g   394m      0   test:0.0%          0       0|0     0|0    62b     3k     5   18:47:00
    *0     *0     *0     *0       0     1|0       0  8.18g  16.7g   394m      0   test:0.0%          0       0|0     0|0    62b     3k     5   18:47:01
    *0     *0     *0     *0       0     1|0       0  8.18g  16.7g   394m      0   test:0.0%          0       0|0     0|0    62b     3k     5   18:47:02
     1      5     *0     *0       0    27|0       1  8.18g  16.7g   395m      0 mobapi:0.0%          0       0|0     1|0     3k     7k     6   18:47:03

And this output is showing that there wasn't any page fault, it means the query was definitely fetching data from memory.

So what you think what could be the root cause of high cou load and very slow query response time.

Please let me know if you need any additional detail.

Thanks.
Chint.

On Sunday, August 3, 2014 7:05:10 PM UTC+5:30, Asya Kamsky wrote:

i already mentioned this in the other thread but 500ms is horribly slow response time - and 10 seconds is way out there - I'm guessing you don't have optimal indexes for your queries.   You already looked in the logs to see the long running queries, can you include some examples?    I suspect they involve in memory sorts or no indexes or both.

Asya

On Saturday, August 2, 2014, <rhchin...@gmail.com> wrote:

Hello,

I am using mongodb as a db server for one of my php web-application, my websites is deployed on amazon m3.medium instance (VCPU count:-1, RAM:- 1 3.75 GiB) and i am using  MongoDB shell version: 2.6.1 and it's a standalone instance.


Now when approx 50-60 users browse my website then cpu load of my instance goes too high when i check the cpu utilization it show me below output.

cat /proc/loadavg
35.03 32.07 36.23

And when i check which process is consuming the highest cpu then it shows
ps auxww --sort=-pcpu|head -20

mongod    4082 62.9  20.5 17521116 110368 ?     Sl   11:59  14:26 /usr/bin/mongod -f /etc/mongod.conf

it means mongodb is consuming the highest cpu and when i check the response time of queries then it shows that all the queries are taking only 500-700 ms to get execute except some queries which takes 10-11 seconds.

so If all the queries are smooth then why mongodb is consuming  too much of cpu and my site is responding extremely slow and sometimes even i don't get response.

is there any way to find out which mongodb component or which mongodb query is consuming the highest cpu so i can fix that issue.

Note:- memory utilization is not high when always 1-1.5 gb of memory is free on the server.


Best,
Chint.

--
You received this message because you are subscribed to the Google Groups "mongodb-user"
group.
 
For other MongoDB technical support options, see: http://www.mongodb.org/about/support/.
---
You received this message because you are subscribed to the Google Groups "mongodb-user" group.

To unsubscribe from this group and stop receiving emails from it, send an email to mongodb-user+unsubscribe@googlegroups.com.

[jesus castello]

It seems like that query is scanning 230k documents, which is a lot specially since you just want 50 of them. Do you have an index on name? Also if you are using this as a queue you might want to consider using a dedicated queue system like RabbitMQ.

The way to make your queries fast is with proper schema desing and queries, you can read about that here http://docs.mongodb.org/master/MongoDB-data-models-guide.pdf

[Asya Kamsky]

Let's take a look at this query:

db.queue_sociallinks.find(
{"flag":"","uid":"","facebook":"","twitter":"","linkedin":""}, []
).sort( {"name":1} ).limit(50)

You are querying for records where flag, uid, facebook, twitter, and
linkedin fields each have value "".
You want to sort the results by field name and return the first 50.

Basically you are running an unindexed query (no index on any field
you are searching by) and the index on "name" is being used to avoid
having to do an in memory sort of the entire data set.

I'm a bit surprised by query conditions comparing fields to "" - are
you creating these fields for every user with "" to represent that
this value has not been provided? That doesn't sound like a good idea
- and searching by five fields usually would be fast only if you had
an index (preferably a compound index, but it's hard to make
suggestions without knowing what this request represents.

But this explains your high CPU load and slow response time - it's not
so much that it's that slow to check 230K documents before it
collections 50 that have these five fields as "" value, it's that it
has to keep yielding to other operations (long running operations have
to yield so that other operations can make progress - in this case
write operations).

Asya

>>> email to mongodb-user...@googlegroups.com.

>>> To post to this group, send email to mongod...@googlegroups.com.
>>> Visit this group at http://groups.google.com/group/mongodb-user.
>>> To view this discussion on the web visit
>>> https://groups.google.com/d/msgid/mongodb-user/0df52c49-880a-4f52-b385-4506751354b6%40googlegroups.com.
>>> For more options, visit https://groups.google.com/d/optout.
>

> --
> You received this message because you are subscribed to the Google Groups
> "mongodb-user"
> group.
>
> For other MongoDB technical support options, see:
> http://www.mongodb.org/about/support/.
> ---
> You received this message because you are subscribed to the Google Groups
> "mongodb-user" group.
> To unsubscribe from this group and stop receiving emails from it, send an

> email to mongodb-user...@googlegroups.com.

> To post to this group, send email to mongod...@googlegroups.com.
> Visit this group at http://groups.google.com/group/mongodb-user.
> To view this discussion on the web visit

> https://groups.google.com/d/msgid/mongodb-user/23499d83-ca48-493a-bd27-6641ebc82ff4%40googlegroups.com.

[rhchin...@gmail.com]

Hi Asya,

Thanks for reply.. To reframe the query. I have removed extra conditions from the query.

And new query look like this.

db.queue_sociallinks.find({"uid":"","flag":""},{"_id":1}).limit(50)

With this new query, have following results with limit 5,50 and 500. I have also uploaded screen shot for reference.
Query with limit
5 records .313ms
50 records .254ms
500 records .256ms

 
also, find the screen shot of indexes we have implemented.
Please suggest us what else we can do to drag down the time to 7 - 10ms

Thanks.
Chint

[rhchin...@gmail.com]

Hey Asya,

Please give me reply, whenever you have time.

Need your help.

Thanks.
Chint.

[Asya Kamsky]

Where are you getting these times from?   Is it from running with explain()?   Those will tend to be slower than normal since it has to try different query plans.   Can you show what times you're seeing the logs when this is running normally?

Asya

To view this discussion on the web visit https://groups.google.com/d/msgid/mongodb-user/e5442190-dab8-4519-9382-b2d32989d9ca%40googlegroups.com.