-
Type:
Bug
-
Resolution: Done
-
Priority:
Critical - P2
-
Affects Version/s: None
-
Component/s: None
-
None
-
None
-
None
-
None
-
None
-
None
-
None
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
}
- 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
-