Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-17456

Mongodb 3.0 wiredTiger storage engine memory usage too high.

    • Type: Icon: Bug Bug
    • Resolution: Duplicate
    • Priority: Icon: Critical - P2 Critical - P2
    • None
    • Affects Version/s: 3.0.0
    • Component/s: WiredTiger
    • Fully Compatible

      My OS is ubuntu server 14.04.2, and my mongodb version is 3.0.

      I make a stress test with the new storage engine wiredTiger. But I find the memory usage never reduce. Finally, killed by kernel because of "out of memory"

      localhost kernel: [12422.302136] Out of memory: Kill process 5893 (mongod) score 405 or sacrifice child.
      

      Here is the db.serverStatus():

      > db.serverStatus()
      {
      	"host" : "rtdstest",
      	"version" : "3.0.0",
      	"process" : "mongod",
      	"pid" : NumberLong(14049),
      	"uptime" : 5109,
      	"uptimeMillis" : NumberLong(5108843),
      	"uptimeEstimate" : 4731,
      	"localTime" : ISODate("2015-03-04T05:56:32.167Z"),
      	"asserts" : {
      		"regular" : 0,
      		"warning" : 0,
      		"msg" : 0,
      		"user" : 0,
      		"rollovers" : 0
      	},
      	"connections" : {
      		"current" : 6,
      		"available" : 51194,
      		"totalCreated" : NumberLong(12)
      	},
      	"cursors" : {
      		"note" : "deprecated, use server status metrics",
      		"clientCursors_size" : 0,
      		"totalOpen" : 0,
      		"pinned" : 0,
      		"totalNoTimeout" : 0,
      		"timedOut" : 0
      	},
      	"extra_info" : {
      		"note" : "fields vary by platform",
      		"heap_usage_bytes" : 1181006888,
      		"page_faults" : 59806
      	},
      	"globalLock" : {
      		"totalTime" : NumberLong("5108855000"),
      		"currentQueue" : {
      			"total" : 0,
      			"readers" : 0,
      			"writers" : 0
      		},
      		"activeClients" : {
      			"total" : 11,
      			"readers" : 0,
      			"writers" : 0
      		}
      	},
      	"locks" : {
      		"Global" : {
      			"acquireCount" : {
      				"r" : NumberLong(1040910),
      				"w" : NumberLong(416818),
      				"W" : NumberLong(4)
      			}
      		},
      		"MMAPV1Journal" : {
      			"acquireCount" : {
      				"r" : NumberLong(2),
      				"w" : NumberLong(5)
      			}
      		},
      		"Database" : {
      			"acquireCount" : {
      				"r" : NumberLong(1040902),
      				"w" : NumberLong(413816),
      				"R" : NumberLong(8),
      				"W" : NumberLong(3002)
      			},
      			"acquireWaitCount" : {
      				"r" : NumberLong(526),
      				"w" : NumberLong(2926),
      				"W" : NumberLong(2787)
      			},
      			"timeAcquiringMicros" : {
      				"r" : NumberLong(83807792),
      				"w" : NumberLong(117579505),
      				"W" : NumberLong(318323222)
      			}
      		},
      		"Collection" : {
      			"acquireCount" : {
      				"r" : NumberLong(1113677),
      				"w" : NumberLong(416816)
      			}
      		}
      	},
      	"network" : {
      		"bytesIn" : 125421456,
      		"bytesOut" : 10352393,
      		"numRequests" : 417271
      	},
      	"opcounters" : {
      		"insert" : 413816,
      		"query" : 1,
      		"update" : 0,
      		"delete" : 0,
      		"getmore" : 0,
      		"command" : 3456
      	},
      	"opcountersRepl" : {
      		"insert" : 0,
      		"query" : 0,
      		"update" : 0,
      		"delete" : 0,
      		"getmore" : 0,
      		"command" : 0
      	},
      	"storageEngine" : {
      		"name" : "wiredTiger"
      	},
      	"wiredTiger" : {
      		"uri" : "statistics:",
      		"LSM" : {
      			"sleep for LSM checkpoint throttle" : 0,
      			"sleep for LSM merge throttle" : 0,
      			"rows merged in an LSM tree" : 0,
      			"application work units currently queued" : 0,
      			"merge work units currently queued" : 0,
      			"tree queue hit maximum" : 0,
      			"switch work units currently queued" : 0,
      			"tree maintenance operations scheduled" : 0,
      			"tree maintenance operations discarded" : 0,
      			"tree maintenance operations executed" : 0
      		},
      		"async" : {
      			"number of allocation state races" : 0,
      			"number of operation slots viewed for allocation" : 0,
      			"current work queue length" : 0,
      			"number of flush calls" : 0,
      			"number of times operation allocation failed" : 0,
      			"maximum work queue length" : 0,
      			"number of times worker found no work" : 0,
      			"total allocations" : 0,
      			"total compact calls" : 0,
      			"total insert calls" : 0,
      			"total remove calls" : 0,
      			"total search calls" : 0,
      			"total update calls" : 0
      		},
      		"block-manager" : {
      			"mapped bytes read" : 0,
      			"bytes read" : 661356544,
      			"bytes written" : 3154300928,
      			"mapped blocks read" : 0,
      			"blocks pre-loaded" : 6,
      			"blocks read" : 161464,
      			"blocks written" : 732235
      		},
      		"cache" : {
      			"tracked dirty bytes in the cache" : 145758110,
      			"bytes currently in the cache" : 218847451,
      			"maximum bytes configured" : 1073741824,
      			"bytes read into cache" : 306,
      			"bytes written from cache" : 1474341161,
      			"pages evicted by application threads" : 0,
      			"checkpoint blocked page eviction" : 0,
      			"unmodified pages evicted" : 0,
      			"page split during eviction deepened the tree" : 0,
      			"modified pages evicted" : 3000,
      			"pages selected for eviction unable to be evicted" : 0,
      			"pages evicted because they exceeded the in-memory maximum" : 0,
      			"pages evicted because they had chains of deleted items" : 0,
      			"failed eviction of pages that exceeded the in-memory maximum" : 0,
      			"hazard pointer blocked page eviction" : 0,
      			"internal pages evicted" : 0,
      			"maximum page size at eviction" : 249,
      			"eviction server candidate queue empty when topping up" : 0,
      			"eviction server candidate queue not empty when topping up" : 0,
      			"eviction server evicting pages" : 0,
      			"eviction server populating queue, but not evicting pages" : 0,
      			"eviction server unable to reach eviction goal" : 0,
      			"pages split during eviction" : 0,
      			"pages walked for eviction" : 0,
      			"eviction worker thread evicting pages" : 0,
      			"in-memory page splits" : 0,
      			"percentage overhead" : 8,
      			"tracked dirty pages in the cache" : 7243,
      			"pages currently held in the cache" : 18009,
      			"pages read into cache" : 6,
      			"pages written from cache" : 400314
      		},
      		"connection" : {
      			"pthread mutex condition wait calls" : 235351,
      			"files currently open" : 9007,
      			"memory allocations" : 19023254,
      			"memory frees" : 9436838,
      			"memory re-allocations" : 23706,
      			"total read I/Os" : 176475,
      			"pthread mutex shared lock read-lock calls" : 3201232,
      			"pthread mutex shared lock write-lock calls" : 797865,
      			"total write I/Os" : 1152662
      		},
      		"cursor" : {
      			"cursor create calls" : 2802022,
      			"cursor insert calls" : 1523920,
      			"cursor next calls" : 3012,
      			"cursor prev calls" : 3003,
      			"cursor remove calls" : 0,
      			"cursor reset calls" : 1613872,
      			"cursor search calls" : 1972827,
      			"cursor search near calls" : 52143,
      			"cursor update calls" : 0
      		},
      		"data-handle" : {
      			"connection dhandles swept" : 6,
      			"connection candidate referenced" : 448192,
      			"connection sweeps" : 507,
      			"connection time-of-death sets" : 181568,
      			"session dhandles swept" : 325685,
      			"session sweep attempts" : 13896
      		},
      		"log" : {
      			"log buffer size increases" : 1,
      			"total log buffer size" : 22503424,
      			"log bytes of payload data" : 142640845,
      			"log bytes written" : 161999360,
      			"yields waiting for previous log file close" : 0,
      			"total size of compressed records" : 67924473,
      			"total in-memory size of compressed records" : 226948923,
      			"log records too small to compress" : 6082,
      			"log records not compressed" : 240504,
      			"log records compressed" : 194371,
      			"maximum log file size" : 104857600,
      			"pre-allocated log files prepared" : 2,
      			"number of pre-allocated log files to create" : 1,
      			"pre-allocated log files used" : 1,
      			"log read operations" : 0,
      			"records processed by log scan" : 0,
      			"log scan records requiring two reads" : 0,
      			"log scan operations" : 0,
      			"consolidated slot closures" : 364624,
      			"logging bytes consolidated" : 144881408,
      			"consolidated slot joins" : 394190,
      			"consolidated slot join races" : 5,
      			"slots selected for switching that were unavailable" : 7,
      			"record size exceeded maximum" : 0,
      			"failed to find a slot large enough for record" : 1,
      			"consolidated slot join transitions" : 4,
      			"log sync operations" : 132,
      			"log write operations" : 440958
      		},
      		"reconciliation" : {
      			"page reconciliation calls" : 392016,
      			"page reconciliation calls for eviction" : 3000,
      			"split bytes currently awaiting free" : 0,
      			"split objects currently awaiting free" : 0
      		},
      		"session" : {
      			"open cursor count" : 413754,
      			"open session count" : 90
      		},
      		"thread-yield" : {
      			"page acquire busy blocked" : 0,
      			"page acquire eviction blocked" : 0,
      			"page acquire locked blocked" : 0,
      			"page acquire read blocked" : 0,
      			"page acquire time sleeping (usecs)" : 0
      		},
      		"transaction" : {
      			"transaction begins" : 428981,
      			"transaction checkpoints" : 79,
      			"transaction checkpoint currently running" : 1,
      			"transaction checkpoint max time (msecs)" : 15011,
      			"transaction checkpoint min time (msecs)" : 1,
      			"transaction checkpoint most recent time (msecs)" : 14423,
      			"transaction checkpoint total time (msecs)" : 201933,
      			"transactions committed" : 428980,
      			"transaction failures due to cache overflow" : 0,
      			"transaction range of IDs currently pinned" : 1933,
      			"transactions rolled back" : 1
      		},
      		"concurrentTransactions" : {
      			"write" : {
      				"out" : 0,
      				"available" : 128,
      				"totalTickets" : 128
      			},
      			"read" : {
      				"out" : 1,
      				"available" : 127,
      				"totalTickets" : 128
      			}
      		}
      	},
      	"writeBacksQueued" : false,
      	"mem" : {
      		"bits" : 64,
      		"resident" : 1153,
      		"virtual" : 1299,
      		"supported" : true,
      		"mapped" : 0,
      		"mappedWithJournal" : 0
      	},
      	"metrics" : {
      		"commands" : {
      			"buildInfo" : {
      				"failed" : NumberLong(0),
      				"total" : NumberLong(6)
      			},
      			"createIndexes" : {
      				"failed" : NumberLong(0),
      				"total" : NumberLong(3000)
      			},
      			"dbStats" : {
      				"failed" : NumberLong(0),
      				"total" : NumberLong(3)
      			},
      			"getLog" : {
      				"failed" : NumberLong(0),
      				"total" : NumberLong(5)
      			},
      			"getnonce" : {
      				"failed" : NumberLong(0),
      				"total" : NumberLong(1)
      			},
      			"isMaster" : {
      				"failed" : NumberLong(0),
      				"total" : NumberLong(403)
      			},
      			"listCollections" : {
      				"failed" : NumberLong(0),
      				"total" : NumberLong(5)
      			},
      			"listDatabases" : {
      				"failed" : NumberLong(0),
      				"total" : NumberLong(7)
      			},
      			"ping" : {
      				"failed" : NumberLong(0),
      				"total" : NumberLong(6)
      			},
      			"replSetGetStatus" : {
      				"failed" : NumberLong(5),
      				"total" : NumberLong(5)
      			},
      			"serverStatus" : {
      				"failed" : NumberLong(0),
      				"total" : NumberLong(1)
      			},
      			"top" : {
      				"failed" : NumberLong(0),
      				"total" : NumberLong(9)
      			},
      			"whatsmyuri" : {
      				"failed" : NumberLong(0),
      				"total" : NumberLong(5)
      			}
      		},
      		"cursor" : {
      			"timedOut" : NumberLong(0),
      			"open" : {
      				"noTimeout" : NumberLong(0),
      				"pinned" : NumberLong(0),
      				"total" : NumberLong(0)
      			}
      		},
      		"document" : {
      			"deleted" : NumberLong(0),
      			"inserted" : NumberLong(413816),
      			"returned" : NumberLong(0),
      			"updated" : NumberLong(0)
      		},
      		"getLastError" : {
      			"wtime" : {
      				"num" : 0,
      				"totalMillis" : 0
      			},
      			"wtimeouts" : NumberLong(0)
      		},
      		"operation" : {
      			"fastmod" : NumberLong(0),
      			"idhack" : NumberLong(0),
      			"scanAndOrder" : NumberLong(0),
      			"writeConflicts" : NumberLong(0)
      		},
      		"queryExecutor" : {
      			"scanned" : NumberLong(0),
      			"scannedObjects" : NumberLong(0)
      		},
      		"record" : {
      			"moves" : NumberLong(0)
      		},
      		"repl" : {
      			"apply" : {
      				"batches" : {
      					"num" : 0,
      					"totalMillis" : 0
      				},
      				"ops" : NumberLong(0)
      			},
      			"buffer" : {
      				"count" : NumberLong(0),
      				"maxSizeBytes" : 268435456,
      				"sizeBytes" : NumberLong(0)
      			},
      			"network" : {
      				"bytes" : NumberLong(0),
      				"getmores" : {
      					"num" : 0,
      					"totalMillis" : 0
      				},
      				"ops" : NumberLong(0),
      				"readersCreated" : NumberLong(0)
      			},
      			"preload" : {
      				"docs" : {
      					"num" : 0,
      					"totalMillis" : 0
      				},
      				"indexes" : {
      					"num" : 0,
      					"totalMillis" : 0
      				}
      			}
      		},
      		"storage" : {
      			"freelist" : {
      				"search" : {
      					"bucketExhausted" : NumberLong(0),
      					"requests" : NumberLong(0),
      					"scanned" : NumberLong(0)
      				}
      			}
      		},
      		"ttl" : {
      			"deletedDocuments" : NumberLong(0),
      			"passes" : NumberLong(85)
      		}
      	},
      	"ok" : 1
      }
      

        1. 09-05.png
          09-05.png
          76 kB
        2. 09-05-detail.png
          09-05-detail.png
          133 kB
        3. all.png
          all.png
          121 kB
        4. ay_mr01a_ss.txt
          15 kB
        5. early.png
          early.png
          121 kB
        6. leak.png
          leak.png
          54 kB
        7. mongod.log
          443 kB
        8. mongod.log
          1.83 MB
        9. ss.log.xz
          39.25 MB
        10. ss.log.xz
          9.90 MB
        11. status.json
          12 kB
        12. syslog
          11 kB
        13. syslog.1
          16 kB

            Votes:
            12 Vote for this issue
            Watchers:
            47 Start watching this issue

              Created:
              Updated:
              Resolved: