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