[SERVER-4478] Mongod should allow a setting to periodically flush memory on windows Created: 13/Dec/11  Updated: 15/Aug/12  Resolved: 04/Mar/12

Status: Closed
Project: Core Server
Component/s: Stability
Affects Version/s: 2.0.1
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Andre' Hazelwood Assignee: Tad Marshall
Resolution: Duplicate Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Windows Server 2008 R2 x64.


Issue Links:
Duplicate
duplicates SERVER-5194 Windows version of mongod should mana... Closed
Backwards Compatibility: Fully Compatible
Operating System: Windows
Participants:

 Description   

We are currently testing mongodb for a document store, and in the process of inserting more than 3 million documents, mongodb used up so much memory on the machine that the box froze and had to be rebooted. There is currently only the _id index on the collection, and no other collections or databases currently defined. Because the size of the index is so small (way less than the memory assigned to the machine, I would expect it to continue to operate up to the point where the indexes no longer fit in memory (then slow way down). It would be nice if there was an option to tell mongodb to flush/release memory it is using for the memory mapped files and only keep the indexes in memory (even at the expense of some performance). After reboot, we are able to continue adding files to the collection since there is now more than an adequate amount of free memory for mongod to use.

Thanks.

mongod log file:

Tue Dec 13 06:24:19 [conn723] SocketException handling request, closing client connection: 9001 socket exception [2] server [192.168.4.2:22847] 
Tue Dec 13 06:24:31 [clientcursormon] mem (MB) res:9412 virt:32802 mapped:16329
Tue Dec 13 06:25:03 [conn722] SocketException handling request, closing client connection: 9001 socket exception [2] server [192.168.4.2:22843] 
 
 
***** SERVER RESTARTED *****
 
 
Tue Dec 13 09:31:39 [initandlisten] MongoDB starting : pid=1428 port=27017 dbpath=c:\mongodb\data 64-bit host=sqldev1
Tue Dec 13 09:31:39 [initandlisten] db version v2.0.1, pdfile version 4.5
Tue Dec 13 09:31:39 [initandlisten] git version: 3a5cf0e2134a830d38d2d1aae7e88cac31bdd684
Tue Dec 13 09:31:39 [initandlisten] build info: windows (6, 1, 7601, 2, 'Service Pack 1') BOOST_LIB_VERSION=1_42
Tue Dec 13 09:31:39 [initandlisten] options: { dbpath: "c:\mongodb\data", directoryperdb: true, journal: true, logappend: true, logpath: "c:\mongodb\mongod.log", noauth: true, rest: true, service: true }
Tue Dec 13 09:31:39 [initandlisten] journal dir=c:/mongodb/data/journal
Tue Dec 13 09:31:39 [initandlisten] recover begin
Tue Dec 13 09:31:39 [initandlisten] recover lsn: 1490690287
Tue Dec 13 09:31:39 [initandlisten] recover c:/mongodb/data/journal/j._6
Tue Dec 13 09:31:39 [initandlisten] recover skipping application of section seq:1488245664 < lsn:1490690287
Tue Dec 13 09:31:39 [initandlisten] recover skipping application of section seq:1488283604 < lsn:1490690287
Tue Dec 13 09:31:39 [initandlisten] recover skipping application of section seq:1488321524 < lsn:1490690287
Tue Dec 13 09:31:39 [initandlisten] recover skipping application of section seq:1488359454 < lsn:1490690287
Tue Dec 13 09:31:40 [initandlisten] recover skipping application of section seq:1488397298 < lsn:1490690287
Tue Dec 13 09:31:40 [initandlisten] recover skipping application of section seq:1488435234 < lsn:1490690287
Tue Dec 13 09:31:40 [initandlisten] recover skipping application of section seq:1488473198 < lsn:1490690287
Tue Dec 13 09:31:40 [initandlisten] recover skipping application of section seq:1488511059 < lsn:1490690287
Tue Dec 13 09:31:40 [initandlisten] recover skipping application of section seq:1488548991 < lsn:1490690287
Tue Dec 13 09:31:40 [initandlisten] recover skipping application of section more...
Tue Dec 13 09:31:45 [initandlisten] recover c:/mongodb/data/journal/j._7
Tue Dec 13 09:31:49 [initandlisten] recover cleaning up
Tue Dec 13 09:31:49 [initandlisten] removeJournalFiles
Tue Dec 13 09:31:49 [initandlisten] recover done
Tue Dec 13 09:31:50 [initandlisten] query local.system.namespaces reslen:20 171ms
Tue Dec 13 09:31:50 [initandlisten] waiting for connections on port 27017
Tue Dec 13 09:31:50 [websvr] admin web console waiting for connections on port 28017
Tue Dec 13 09:32:50 [clientcursormon] mem (MB) res:20 virt:61 mapped:0
Tue Dec 13 09:33:36 [initandlisten] connection accepted from 127.0.0.1:49226 #1
Tue Dec 13 09:33:39 [conn1] command admin.$cmd command: { listDatabases: 1.0 } ntoreturn:1 reslen:175 922ms
Tue Dec 13 09:33:50 [clientcursormon] mem (MB) res:36 virt:32722 mapped:16329
Tue Dec 13 09:33:52 [conn1] command Atom.$cmd command: { collstats: "Moreover", scale: undefined } ntoreturn:1 reslen:256 484ms
Tue Dec 13 09:36:20 [conn1] end connection 127.0.0.1:49226
Tue Dec 13 09:38:50 [clientcursormon] mem (MB) res:37 virt:32719 mapped:16329
Tue Dec 13 09:40:12 [initandlisten] connection accepted from 127.0.0.1:49230 #2
Tue Dec 13 09:41:04 [conn2] assertion 10068 invalid operator: $eq ns:Atom.Moreover query:{ DuplicateId: { $eq: "3888384356" } }
Tue Dec 13 09:41:50 [clientcursormon] mem (MB) res:3390 virt:32720 mapped:16329
Tue Dec 13 09:42:50 [clientcursormon] mem (MB) res:5095 virt:32720 mapped:16329
Tue Dec 13 09:42:50 [PeriodicTask::Runner] task: DBConnectionPool-cleaner took: 15ms
Tue Dec 13 09:42:50 [PeriodicTask::Runner] task: WriteBackManager::cleaner took: 15ms
Tue Dec 13 09:43:48 [conn2] query Atom.Moreover nscanned:3961932 nreturned:6 reslen:23542 155387ms
Tue Dec 13 09:47:36 [conn2] command Atom.$cmd command: { collstats: "Moreover", scale: undefined } ntoreturn:1 reslen:256 171ms
Tue Dec 13 09:47:50 [clientcursormon] mem (MB) res:5086 virt:32720 mapped:16329
Tue Dec 13 09:47:57 [initandlisten] connection accepted from 192.168.4.2:31957 #3
Tue Dec 13 09:47:57 [initandlisten] connection accepted from 192.168.4.2:31958 #4
Tue Dec 13 09:47:57 [initandlisten] connection accepted from 192.168.4.2:31959 #5
Tue Dec 13 09:47:57 [initandlisten] connection accepted from 192.168.4.2:31960 #6
Tue Dec 13 09:47:57 [initandlisten] connection accepted from 192.168.4.2:31961 #7
Tue Dec 13 09:47:57 [initandlisten] connection accepted from 192.168.4.2:31962 #8
Tue Dec 13 09:47:57 [initandlisten] connection accepted from 192.168.4.2:31963 #9
Tue Dec 13 09:47:57 [initandlisten] connection accepted from 192.168.4.2:31965 #10
Tue Dec 13 09:47:57 [initandlisten] connection accepted from 192.168.4.2:31964 #11
Tue Dec 13 09:47:57 [initandlisten] connection accepted from 192.168.4.2:31966 #12

Collection details:

C:\mongodb\mongodb-win32-x86_64-2.0.1\bin>mongo
MongoDB shell version: 2.0.1
connecting to: test
> show dbs
Atom    15.9462890625GB
local   (empty)
> use Atom
switched to db Atom
> show collections
Moreover
system.indexes
> db.Moreover.stats();
{
        "ns" : "Atom.Moreover",
        "count" : 3961932,
        "size" : 12043437732,
        "avgObjSize" : 3039.7891059210506,
        "storageSize" : 12880310256,
        "numExtents" : 32,
        "nindexes" : 1,
        "lastExtentSize" : 2146426864,
        "paddingFactor" : 1,
        "flags" : 1,
        "totalIndexSize" : 170976512,
        "indexSizes" : {
                "_id_" : 170976512
        },
        "ok" : 1
}



 Comments   
Comment by Tad Marshall [ 04/Mar/12 ]

Collapsing closely related tickets into one.

Comment by Tad Marshall [ 26/Jan/12 ]

Thanks. The VMMap suggestion is helpful from a couple of perspectives: seeing what VMMap says gives us information about where the memory issues are, and seeing if using VMMap's Empty Working Set command helps indicates how much control we could gain by doing the same thing ourselves.

Comment by Andre' Hazelwood [ 26/Jan/12 ]

I've been on paternity leave for the past few weeks. I should be able to look at this in the next week or so.

Comment by Tad Marshall [ 23/Dec/11 ]

Can you try running VMMap ( http://technet.microsoft.com/en-us/sysinternals/dd535533 ) and see what it says about mongod.exe's memory usage? If you use VMMap's Empty Working Set command from the View menu, does this drop the Working Set dramatically (or at least significantly)? Can you also issue a serverStatus command when mongod.exe is in a high memory usage state and post the result? Thanks!

Comment by Tad Marshall [ 13/Dec/11 ]

We are investigating memory usage in Windows and have open Jira tickets to improve things. See https://jira.mongodb.org/browse/SERVER-538 for one possible solution. One comment-er found that the Windows System Resource Manager was helpful ... see http://www.captaincodeman.com/2011/02/27/limit-mongodb-memory-use-windows/ and http://technet.microsoft.com/en-us/library/cc732553.aspx for details. Others have reported that manually emptying the working set of the mongod.exe process relieves the problem until the working set grows overlarge again. The VMMap utility from the Sysinternals suites has an Empty Working Set command on its View menu, for example. See http://technet.microsoft.com/en-us/sysinternals/dd535533 to download VMMap.

Microsoft has given us instructions for gathering more information about these issues. See https://jira.mongodb.org/browse/SERVER-4301?focusedCommentId=70050&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-70050 for their suggestion.

These suggestions are not the final answer, we're still working on that.

Generated at Thu Feb 08 03:06:06 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.