Mongodb and very high blocking rate with low bandwidth

Question

We have some problems with our first use of mongodb :) Here are some facts:

• blocking percentage 95 %%
• the server is a VM with 2 cores, 6 GB of RAM, shared NFS v3 (noatime) on a fast NAS for mongodb.
• centos 5.7 x86_64, mongo 2.0.2, php-pecl-mongo 1.2.6 (not the latest version, but will be updated soon :)
• mongo (currently / erroneously) configured as one master without a slave
• db created today from scratch. 20 web servers write (using update)
• not sure how many updates / s were sent to the server, but the amount processed is very small.
• I'm not sure if this is a problem with the index: how to diagnose?
• current disk data (including oplog, journal ...) is less than 600 MB
• dstat:

  ---- total-cpu-usage ---- -dsk / total- -net / total- --- paging-- --- system--
 usr sys idl wai hiq siq |  read writ |  recv send |  in out |  int csw
  46 1 53 0 0 0 |  0 4096B |  42k 19k |  0 0 |  317 5328
  48 1 52 0 0 1 |  0 92k |  46k 7590B |  0 0 |  321 5308
  50 2 48 0 0 0 |  0 0 |  39k 7218B |  0 0 |  304 5359
  47 1 51 0 0 1 |  0 0 |  47k 10k |  0 0 |  332 5679
  46 1 52 0 0 0 |  0 0 |  44k 15k |  0 0 |  319 5099 

• nfsiostat is empty (0 ops / s) (of course, iostat is the same)
• mongostat:

  insert query update delete getmore command flushes mapped vsize res faults locked% idx miss% qr | qw ar | aw netIn netOut conn repl time
      0 0 0 0 0 1 0 1.41g 8.39g 242m 0 96.2 0 0 | 3280 1 | 5322 62b 1k 5324 M 21:11:50
      0 0 0 0 0 1 0 1.41g 8.39g 242m 0 96.5 0 0 | 3204 1 | 5322 62b 1k 5324 M 21:11:51
      0 0 0 0 0 1 0 1.41g 8.39g 242m 0 96 0 1 | 3351 1 | 5322 62b 1k 5324 M 21:11:52
      0 0 1 0 0 1 0 1.41g 8.39g 242m 0 96.9 0 0 | 3251 1 | 5322 485b 1k 5324 M 21:11:53
      0 0 0 0 1 1 0 1.41g 8.39g 242m 0 95.6 0 0 | 3280 1 | 5322 112b 1k 5324 M 21:11:54 

• db.serverStatus ()

  {
         "host": "foo001",
         "version": "2.0.2",
         "process": "mongod",
         "uptime": 21370,
         "uptimeEstimate": 18626,
         "localTime": ISODate ("2012-02-23T20: 20: 59.589Z"),
         "globalLock": {
                 "totalTime": 21369761258,
                 "lockTime": 19450568051,
                 "ratio": 0.9101911722911022,
                 "currentQueue": {
                         "total": 3570,
                         "readers": 0,
                         "writers": 3570
                 },
                 "activeClients": {
                         "total": 5500,
                         "readers": 1,
                         "writers": 5499
                 }
         },
         "mem": {
                 "bits": 64,
                 "resident": 255,
                 "virtual": 8782,
                 "supported": true,
                 "mapped": 1440,
                 "mappedWithJournal": 2880
         },
         "connections": {
                 "current": 5501,
                 "available": 4099
         },
         "extra_info": {
                 "note": "fields vary by platform",
                 "heap_usage_bytes": 81930736,
                 "page_faults": 2916
         },
         "indexCounters": {
                 "btree": {
                         "accesses": 2377,
                         "hits": 2377,
                         "misses": 0,
                         "resets": 0,
                         "missRatio": 0
                 }
         },
         "backgroundFlushing": {
                 "flushes": 356,
                 "total_ms": 2372,
                 "average_ms": 6.662921348314606,
                 "last_ms": 0,
                 "last_finished": ISODate ("2012-02-23T20: 20: 56.446Z")
         },
         "cursors": {
                 "totalOpen": 5500,
                 "clientCursors_size": 5500,
                 "timedOut": 0,
                 "totalNoTimeout": 5499
         },
         "network": {
                 "bytesIn": 51373772,
                 "bytesOut": 51176411,
                 "numRequests": 176017
         },
         "repl": {
                 "ismaster": true
         },
         "opcounters": {
                 "insert": 0,
                 "query": 25,
                 "update": 142157,
                 "delete": 0,
                 "getmore": 39053,
                 "command": 284
         },
         "asserts": {
                 "regular": 0,
                 "warning": 0,
                 "msg": 0,
                 "user": 0,
                 "rollovers": 0
         },
         "writeBacksQueued": false,
         "dur": {
                 "commits": 19,
                 "journaledMB": 0,
                 "writeToDataFilesMB": 0,
                 "compression": 0,
                 "commitsInWriteLock": 0,
                 "earlyCommits": 0,
                 "timeMs": {
                         "dt": 3083,
                         "prepLogBuffer": 0,
                         "writeToJournal": 0,
                         "writeToDataFiles": 0,
                         "remapPrivateView": 0
                 }
         },
         "ok": 1
 } 

• our db:

  {
         "db": "mydb",
         "collections": 6,
         "objects": 119174,
         "avgObjSize": 323.99872455401345,
         "dataSize": 38612224,
         "storageSize": 57286656,
         "numExtents": 26,
         "indexes": 4,
         "indexSize": 3899952,
         "fileSize": 469762048,
         "nsSizeMB": 16,
         "ok": 1
 } 

Any clues?

Hi,

D.

PS: I also crossed this with mongo-user

Answer 1

Please, please do not use NFS as a database. There are so many problems, especially with locking, and especially with NFS <v4. And since they are not just performance issues, NFS should probably not even be considered.

I would start by moving my database to a local drive and see if this solves the performance problems, which I suspect will be ...

EDIT:

The MongoDB people seem to agree , even if somewhat briefly, that NFS is not recommended.

Answer 2

According to the result of mongostat, you write to the queue (check qr | qw, the second value will be high and increase), which means that your system is not fast enough to write before a new record appears.

According to your mongostat, there are not many of them, but each of them is slow. Looks like the problem is with the updates. Perhaps you are using findAndModify? This will temporarily block the database if you use a complex query. Or maybe the information you put on the Mongostat was after a huge surge of letters. Anyway, they are probably very slow, or you won’t see this high lock (and the queue entries will decrease quickly)

You must activate the database profiler and analyze your updates. For more information, this page.

PD: index size looks fine:

"indexes" : 4, "indexSize" : 3899952, 

It is less than 4 MB

EDITED: Another detail, it seems that there are several clients for recording at the same time. If there are 20 web servers, perhaps each of them connects several times.

 "activeClients" : { "total" : 5500, "readers" : 1, "writers" : 5499 }