Details
-
Bug
-
Resolution: Done
-
Critical - P2
-
None
-
None
-
Empty show more show less
Description
I am doing simple tests to evaluate if to migrate to MongoDb and i am facing with memory leak (i suppose).
MongoDB using all memory then it's killing the process. VM i am using for test have 4 GBs of ram. Basically it's done on benchmark in which i am only doing 2 queries on two small collections which return small amount of same data all the time.
I can reproduce this every time.
If i am reading correctly serverStatus then it's not cache problem.
With fresh started mongod instance have vsize 187 MB and res 45 MB.
As you can see:

It goes up to 2.5 GB of res and 2.5 GB of vsize in ~20 seconds. If i would continue the benchmark it would go up to full memory usage and kill the process.
Collection sizes:
"db" : "test", |
"collections" : 6, |
"objects" : 3177626, |
"avgObjSize" : 85.97832753130797, |
"dataSize" : 273206969, |
"storageSize" : 107515904, |
"numExtents" : 0, |
"indexes" : 12, |
"indexSize" : 47673344, |
"ok" : 1 |
Server status:
> db.serverStatus()
|
{
|
"host" : "debian", |
"version" : "3.0.3", |
"process" : "mongod", |
"pid" : NumberLong(18930), |
"uptime" : 289, |
"uptimeMillis" : NumberLong(289083), |
"uptimeEstimate" : 274, |
"localTime" : ISODate("2015-06-15T19:38:59.340Z"), |
"asserts" : { |
"regular" : 0, |
"warning" : 0, |
"msg" : 0, |
"user" : 0, |
"rollovers" : 0 |
},
|
"connections" : { |
"current" : 9, |
"available" : 51191, |
"totalCreated" : NumberLong(16) |
},
|
"cursors" : { |
"note" : "deprecated, use server status metrics", |
"clientCursors_size" : 12000, |
"totalOpen" : 12000, |
"pinned" : 0, |
"totalNoTimeout" : 0, |
"timedOut" : 0 |
},
|
"extra_info" : { |
"note" : "fields vary by platform", |
"heap_usage_bytes" : -1810706720, |
"page_faults" : 102 |
},
|
"globalLock" : { |
"totalTime" : NumberLong(289059000), |
"currentQueue" : { |
"total" : 0, |
"readers" : 0, |
"writers" : 0 |
},
|
"activeClients" : { |
"total" : 14, |
"readers" : 0, |
"writers" : 0 |
}
|
},
|
"locks" : { |
"Global" : { |
"acquireCount" : { |
"r" : NumberLong(24519), |
"w" : NumberLong(9), |
"W" : NumberLong(4) |
}
|
},
|
"Database" : { |
"acquireCount" : { |
"r" : NumberLong(24516), |
"R" : NumberLong(3), |
"W" : NumberLong(9) |
}
|
},
|
"Collection" : { |
"acquireCount" : { |
"r" : NumberLong(24536) |
}
|
}
|
},
|
"network" : { |
"bytesIn" : 2819838, |
"bytesOut" : 15011546, |
"numRequests" : 24163 |
},
|
"opcounters" : { |
"insert" : 0, |
"query" : 24001, |
"update" : 0, |
"delete" : 0, |
"getmore" : 0, |
"command" : 164 |
},
|
"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" : 286720, |
"bytes written" : 184320, |
"mapped blocks read" : 0, |
"blocks pre-loaded" : 455, |
"blocks read" : 63, |
"blocks written" : 27 |
},
|
"cache" : { |
"tracked dirty bytes in the cache" : 0, |
"tracked bytes belonging to internal pages in the cache" : 95081, |
"bytes currently in the cache" : 212470, |
"tracked bytes belonging to leaf pages in the cache" : 1073646743, |
"maximum bytes configured" : 1073741824, |
"tracked bytes belonging to overflow pages in the cache" : 0, |
"bytes read into cache" : 85038, |
"bytes written from cache" : 98014, |
"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" : 0, |
"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" : 0, |
"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" : 0, |
"pages currently held in the cache" : 37, |
"pages read into cache" : 37, |
"pages written from cache" : 13 |
},
|
"connection" : { |
"pthread mutex condition wait calls" : 6367, |
"files currently open" : 26, |
"memory allocations" : 743544, |
"memory frees" : 76355, |
"memory re-allocations" : 24471, |
"total read I/Os" : 104, |
"pthread mutex shared lock read-lock calls" : 138156, |
"pthread mutex shared lock write-lock calls" : 317, |
"total write I/Os" : 42 |
},
|
"cursor" : { |
"cursor create calls" : 125941, |
"cursor insert calls" : 13, |
"cursor next calls" : 135, |
"cursor prev calls" : 60041, |
"cursor remove calls" : 0, |
"cursor reset calls" : 72284, |
"cursor search calls" : 108292, |
"cursor search near calls" : 48007, |
"cursor update calls" : 0 |
},
|
"data-handle" : { |
"connection dhandles swept" : 0, |
"connection candidate referenced" : 2, |
"connection sweeps" : 44, |
"connection time-of-death sets" : 15, |
"session dhandles swept" : 2, |
"session sweep attempts" : 12049 |
},
|
"log" : { |
"log buffer size increases" : 0, |
"total log buffer size" : 1048576, |
"log bytes of payload data" : 2948, |
"log bytes written" : 3968, |
"yields waiting for previous log file close" : 0, |
"total size of compressed records" : 2843, |
"total in-memory size of compressed records" : 4470, |
"log records too small to compress" : 5, |
"log records not compressed" : 0, |
"log records compressed" : 4, |
"maximum log file size" : 104857600, |
"pre-allocated log files prepared" : 1, |
"number of pre-allocated log files to create" : 1, |
"pre-allocated log files used" : 0, |
"log read operations" : 0, |
"log release advances write LSN" : 9, |
"records processed by log scan" : 10, |
"log scan records requiring two reads" : 0, |
"log scan operations" : 5, |
"consolidated slot closures" : 0, |
"logging bytes consolidated" : 0, |
"consolidated slot joins" : 0, |
"consolidated slot join races" : 0, |
"slots selected for switching that were unavailable" : 0, |
"record size exceeded maximum" : 0, |
"failed to find a slot large enough for record" : 0, |
"consolidated slot join transitions" : 0, |
"log sync operations" : 8, |
"log sync_dir operations" : 1, |
"log server thread advances write LSN" : 0, |
"log write operations" : 9 |
},
|
"reconciliation" : { |
"page reconciliation calls" : 13, |
"page reconciliation calls for eviction" : 0, |
"split bytes currently awaiting free" : 0, |
"split objects currently awaiting free" : 0 |
},
|
"session" : { |
"open cursor count" : 53902, |
"open session count" : 12047 |
},
|
"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" : 24129, |
"transaction checkpoints" : 5, |
"transaction checkpoint generation" : 5, |
"transaction checkpoint currently running" : 0, |
"transaction checkpoint max time (msecs)" : 26, |
"transaction checkpoint min time (msecs)" : 0, |
"transaction checkpoint most recent time (msecs)" : 0, |
"transaction checkpoint total time (msecs)" : 47, |
"transactions committed" : 3, |
"transaction failures due to cache overflow" : 0, |
"transaction range of IDs currently pinned by a checkpoint" : 0, |
"transaction range of IDs currently pinned" : 1, |
"transactions rolled back" : 24128 |
},
|
"concurrentTransactions" : { |
"write" : { |
"out" : 0, |
"available" : 128, |
"totalTickets" : 128 |
},
|
"read" : { |
"out" : 1, |
"available" : 127, |
"totalTickets" : 128 |
}
|
}
|
},
|
"writeBacksQueued" : false, |
"mem" : { |
"bits" : 64, |
"resident" : 2390, |
"virtual" : 2538, |
"supported" : true, |
"mapped" : 0 |
},
|
"metrics" : { |
"commands" : { |
"dbStats" : { |
"failed" : NumberLong(0), |
"total" : NumberLong(1) |
},
|
"getnonce" : { |
"failed" : NumberLong(0), |
"total" : NumberLong(3) |
},
|
"isMaster" : { |
"failed" : NumberLong(0), |
"total" : NumberLong(15) |
},
|
"ping" : { |
"failed" : NumberLong(0), |
"total" : NumberLong(27) |
},
|
"serverStatus" : { |
"failed" : NumberLong(0), |
"total" : NumberLong(118) |
}
|
},
|
"cursor" : { |
"timedOut" : NumberLong(0), |
"open" : { |
"noTimeout" : NumberLong(0), |
"pinned" : NumberLong(0), |
"total" : NumberLong(12000) |
}
|
},
|
"document" : { |
"deleted" : NumberLong(0), |
"inserted" : NumberLong(0), |
"returned" : NumberLong(36000), |
"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(36000), |
"scannedObjects" : NumberLong(36000) |
},
|
"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(4) |
}
|
},
|
"ok" : 1 |
}
|
|
Attachments
Issue Links
- is related to
-
SERVER-17334 Runs out of sessions on capped collection during load test (WT, not MMAP)
-
- Closed
-
- related to
-
SERVER-17386 Cursor cache causes excessive memory utilization in WiredTiger
-
- Closed
-