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
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
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