Re: Master CPU 100% without apparent reason

57 views
Skip to first unread message

Adam C

unread,
Jul 26, 2012, 8:24:44 AM7/26/12
to mongod...@googlegroups.com
Andrés,

Are you replicating a capped collection by any chance?  If so, you have to define an index on _id for it to replicate efficiently (not done automatically for capped collections).  

Adam


On Thursday, July 26, 2012 1:10:38 PM UTC+1, Andres Lucena wrote:
Hi! 

We're seeing some problems in several mongos instances. We are running master/slave replication and with really low traffic we're seeing 100% mongo CPU usage in the master. When we stop the slave it automatically goes to normal values. 

We have proper indexes in _id field, and we use this to query the documents. 

> db.foo.getIndexKeys()
[ { "_id" : 1 }, { "i" : 1 } ]

Operating system is FreeBSD 8.2-RELEASE. 

Mongo version is 2.0.2, but we're also seeing this situation in 2.0.4. 

The tests we've done are: 

With no replication running (slave stop):

$ sudo iostat -c 10
       tty             ad4              ad6              ad8             cpu
 tin  tout  KB/t tps  MB/s   KB/t tps  MB/s   KB/t tps  MB/s  us ni sy in id
   0     2 16.84   2  0.03  124.92   0  0.00  49.99  13  0.63   3  0 15  0 82
   0   235  0.00   0  0.00   0.00   0  0.00   0.50   1  0.00   0  0  0  0 100
   0    79  0.00   0  0.00   0.00   0  0.00   0.00   0  0.00   0  0  0  0 100
   0    79  0.00   0  0.00   0.00   0  0.00  10.83   3  0.03   2  0 43  0 55
   0    78  0.00   0  0.00   0.00   0  0.00  16.00   6  0.09   1  0 19  0 81
   0    78  0.00   0  0.00   0.00   0  0.00  16.00   2  0.03   0  0 11  0 89
   0   143 10.62  13  0.13   0.00   0  0.00   0.00   0  0.00   0  0 19  0 80
   0    78  0.00   0  0.00   0.00   0  0.00  13.65  17  0.23   1  0 14  0 85
   0    78 16.00   2  0.03   0.00   0  0.00  16.00   3  0.05   6  0 16  0 79
   0    78  0.00   0  0.00   0.00   0  0.00   0.00   0  0.00   3  0 15  0 82

$ sudo mongostat --port 27002
connected to: 127.0.0.1:27002
insert  query update delete getmore command flushes locked % idx miss %     qr|qw   ar|aw  netIn netOut  conn repl       time 
     0      0      0      0       0       1       0        0          0       0|0     0|0    62b     1k     8    M   13:50:17 
     0      0      0      0       0       1       0        0          0       0|0     0|0    62b     1k     8    M   13:50:18 
     0      0      0      0       0       1       0        0          0       0|0     0|0    62b     1k     8    M   13:50:19 
     0      0      0      0       0       1       0        0          0       0|0     0|0    62b     1k     8    M   13:50:20 
     0      0      0      0       0       1       0        0          0       0|0     0|0    62b     1k     8    M   13:50:21 
     0      0      0      0       0       1       0        0          0       0|0     0|0    62b     1k     8    M   13:50:22 
     0      0      0      0       0       1       0        0          0       0|0     0|0    62b     1k     8    M   13:50:23 
     0      0      0      0       0       1       0        0          0       0|0     0|0    62b     1k     8    M   13:50:24 
     0      0      0      0       0       1       1        0          0       0|0     0|0    62b     1k     8    M   13:50:25 
     0      0      0      0       0       1       0        0          0       0|0     0|0    62b     1k     8    M   13:50:26 

* ps auxf | grep mongo

mongodb 37077  2.6  0.1 71691616 31648  ??  S     1:42PM   9:16.57 /usr/local/bin/mongod --port 27002 --fork --dbpath /data/mongod2 --logpath /var/log/mongodb/mongod2.log --logappend --master --oplogSize 1024 --pidfilepath /data/mongod2/mongod2.pid (mongod)

But with replication running (slave start):

* iostat

$ sudo iostat -c 10
       tty             ad4              ad6              ad8             cpu
 tin  tout  KB/t tps  MB/s   KB/t tps  MB/s   KB/t tps  MB/s  us ni sy in id
   0     2 16.84   2  0.03  124.92   0  0.00  49.99  13  0.63   3  0 15  0 82
   0   235  0.00   0  0.00   0.00   0  0.00  10.83   3  0.03   0  0  4  0 96
   0    78  0.00   0  0.00   0.00   0  0.00  16.00   7  0.11   4  0 67  0 29
   0    78  0.00   0  0.00   0.00   0  0.00   0.00   0  0.00   0  0 63  0 37
   0    78  0.00   0  0.00   0.00   0  0.00   0.00   0  0.00   1  0 53  0 46
   0    78  9.07  15  0.13   0.00   0  0.00   0.00   0  0.00   0  0 28  0 71
   0    78  0.00   0  0.00   0.00   0  0.00  13.78  18  0.24   2  0 40  1 58
   0    78  0.00   0  0.00   0.00   0  0.00   0.00   0  0.00   0  0 28  0 71
   0    78  0.00   0  0.00   0.00   0  0.00   0.00   0  0.00   2  0 20  0 77
   0    78  0.00   0  0.00   0.00   0  0.00   0.00   0  0.00   1  0 18  0 81

$ sudo mongostat --port 27002
connected to: 127.0.0.1:27002
insert  query update delete getmore command flushes locked % idx miss %     qr|qw   ar|aw  netIn netOut  conn repl       time 
     0      0      0      0       0       1       0        0          0       0|0     1|0    62b     1k     9    M   13:41:00 
     0      0      0      0       0       1       0        0          0       0|0     1|0    62b     1k     9    M   13:41:01 
     0      0      0      0       1       1       0        0          0       0|0     1|0   112b     1k     9    M   13:41:02 
     0      0      0      0       0       1       0        0          0       0|0     1|0    62b     1k     9    M   13:41:03 
     0      1      0      0       0       1       0        0          0       0|0     1|0   137b     1k     9    M   13:41:04 
     0      0      0      0       0       1       0        0          0       0|0     1|0    62b     1k     9    M   13:41:05 
     0      0      0      0       1       1       0        0          0       0|0     1|0   112b     1k     9    M   13:41:06 
     0      4      0      0       0       1       0        0          0       0|0     1|0   362b     3k     9    M   13:41:07 
     0      0      0      0       0       1       0        0          0       0|0     1|0    62b     1k     9    M   13:41:08 
     0      0      0      0       1       1       0        0          0       0|0     1|0   112b     1k     9    M   13:41:09 

$ ps auxf|grep mongo
mongodb 35188 126.7  0.2 71691872 62308  ??  S     1:35PM   6:19.30 /usr/local/bin/mongod --port 27002 --fork --dbpath /data/mongod2 --logpath /var/log/mongodb/mongod2.log --logappend --master --oplogSize 1024 --pidfilepath /data/mongod2/mongod2.pid (mongod)

And the slave it's well in the cpu related issue.

root     9381  2.2  0.3 75631816 63312  ??  I     1:50PM   0:12.42 /usr/local/bin/mongod --port 27002 --fork --dbpath /data/m2_mongod2 --logpath /var/log/mongodb/m2_mongod2.log --slave --source IPADDRESS:27002 --logappend (mongod)

In the logs we don't see anything related to this issue.

Greetings,
Andrés

Andres Lucena

unread,
Jul 26, 2012, 10:18:56 AM7/26/12
to mongod...@googlegroups.com
On Thu, Jul 26, 2012 at 2:24 PM, Adam C <ad...@10gen.com> wrote:
Andrés,

Are you replicating a capped collection by any chance?  If so, you have to define an index on _id for it to replicate efficiently (not done automatically for capped collections). 

Adam
 

No Adam, it's not a capped collection. We have defined indexes on _id in both dbs.

Thanks.

Greetings,
Andrés


 
--
You received this message because you are subscribed to the Google
Groups "mongodb-user" group.
To post to this group, send email to mongod...@googlegroups.com
To unsubscribe from this group, send email to
mongodb-user...@googlegroups.com
See also the IRC channel -- freenode.net#mongodb

Adam C

unread,
Jul 26, 2012, 10:38:49 AM7/26/12
to mongod...@googlegroups.com
That level of CPU usage is definitely odd, and there's nothing in the stats that suggests something obviously wrong - are these hosts in MMS?  

Also, is there a reason you are using Master/Slave and not a replica set? - the Master/Slave option is deprecated at this point and is a different code path, so I would be interested to see if the same issue was seen in a replica set environment.

Adam

Adam C

unread,
Aug 2, 2012, 1:32:43 PM8/2/12
to mongod...@googlegroups.com
One other thought - are you using NFS mounts for data or anything that might cause IOWait?

Any luck with the replica set option instead of master slave?

Adam
Reply all
Reply to author
Forward
0 new messages