[SERVER-9242] serverStatus workingSet and indexCounters not working on Windows Created: 04/Apr/13  Updated: 11/Jul/16  Resolved: 26/Apr/13

Status: Closed
Project: Core Server
Component/s: Performance
Affects Version/s: 2.4.1
Fix Version/s: 2.4.4, 2.5.0

Type: Bug Priority: Critical - P2
Reporter: David Verdejo Assignee: Tad Marshall
Resolution: Done Votes: 0
Labels: workingset
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

db version v2.4.1
sys info: windows sys.getwindowsversion(major=6, minor=1, build=7601, platform=2, service_pack='Service Pack 1') BOOST_LIB_VERSION=1_49
Intel Core i5 2410M (dual core) - 4 GB RAM


Issue Links:
Duplicate
is duplicated by SERVER-9455 mongodump'ing on Windows: performance... Closed
is duplicated by SERVER-9458 Very slow page faulting on windows on... Closed
is duplicated by SERVER-9549 Initial Sync much slower with 2.4 (Wi... Closed
Related
Backwards Compatibility: Fully Compatible
Operating System: Windows
Steps To Reproduce:

rs:PRIMARY> db.serverStatus(

{ workingSet: 1 }

)

Participants:

 Description   

Output commnad db.serverStatus(

{ workingSet: 1 }

): workingSet info not supported

rs:PRIMARY> db.serverStatus( { workingSet: 1 } )
{
        "host" : "ext023",
        "version" : "2.4.1",
        "process" : "mongod",
        "pid" : 4920,
        "uptime" : 1039,
        "uptimeMillis" : NumberLong(1039518),
        "uptimeEstimate" : 1027,
        "localTime" : ISODate("2013-04-04T15:43:26.656Z"),
        "asserts" : {
                "regular" : 0,
                "warning" : 0,
                "msg" : 0,
                "user" : 11,
                "rollovers" : 0
        },
        "backgroundFlushing" : {
                "flushes" : 17,
                "total_ms" : 3009,
                "average_ms" : 177,
                "last_ms" : 5,
                "last_finished" : ISODate("2013-04-04T15:43:07.183Z")
        },
        "connections" : {
                "current" : 7,
                "available" : 19993,
                "totalCreated" : NumberLong(76)
        },
        "cursors" : {
                "totalOpen" : 2,
                "clientCursors_size" : 2,
                "timedOut" : 2
        },
        "dur" : {
                "commits" : 30,
                "journaledMB" : 0,
                "writeToDataFilesMB" : 0,
                "compression" : 0,
                "commitsInWriteLock" : 0,
                "earlyCommits" : 0,
                "timeMs" : {
                        "dt" : 3060,
                        "prepLogBuffer" : 0,
                        "writeToJournal" : 0,
                        "writeToDataFiles" : 0,
                        "remapPrivateView" : 0
                }
        },
        "extra_info" : {
                "note" : "fields vary by platform",
                "page_faults" : 17275,
                "usagePageFileMB" : 75,
                "totalPageFileMB" : 7893,
                "availPageFileMB" : 4481,
                "ramMB" : 3947
        },
        "globalLock" : {
                "totalTime" : NumberLong(1039518000),
                "lockTime" : NumberLong(9288950),
                "currentQueue" : {
                        "total" : 0,
                        "readers" : 0,
                        "writers" : 0
                },
                "activeClients" : {
                        "total" : 0,
                        "readers" : 0,
                        "writers" : 0
                }
        },
        "indexCounters" : {
                "note" : "not supported on this platform"
        },
        "locks" : {
                "." : {
                        "timeLockedMicros" : {
                                "R" : NumberLong(24472),
                                "W" : NumberLong(9288950)
                        },
                        "timeAcquiringMicros" : {
                                "R" : NumberLong(264019),
                                "W" : NumberLong(1133)
                        }
                },
                "admin" : {
                        "timeLockedMicros" : {
                                "r" : NumberLong(9667),
                                "w" : NumberLong(0)
                        },
                        "timeAcquiringMicros" : {
                                "r" : NumberLong(123),
                                "w" : NumberLong(0)
                        }
                },
                "local" : {
                        "timeLockedMicros" : {
                                "r" : NumberLong(35848),
                                "w" : NumberLong(812)
                        },
                        "timeAcquiringMicros" : {
                                "r" : NumberLong(4389895),
                                "w" : NumberLong(259)
                        }
                },
                "test" : {
                        "timeLockedMicros" : {
                                "r" : NumberLong(587),
                                "w" : NumberLong(286499)
                        },
                        "timeAcquiringMicros" : {
                                "r" : NumberLong(32),
                                "w" : NumberLong(12)
                        }
                }
        },
        "network" : {
                "bytesIn" : 159141,
                "bytesOut" : 180696,
                "numRequests" : 1613
        },
        "opcounters" : {
                "insert" : 4,
                "query" : 65,
                "update" : 9,
                "delete" : 0,
                "getmore" : 413,
                "command" : 1188
        },
        "opcountersRepl" : {
                "insert" : 0,
                "query" : 0,
                "update" : 0,
                "delete" : 0,
                "getmore" : 0,
                "command" : 0
        },
        "recordStats" : {
                "accessesNotInMemory" : 20,
                "pageFaultExceptionsThrown" : 2,
                "admin" : {
                        "accessesNotInMemory" : 8,
                        "pageFaultExceptionsThrown" : 1
                },
                "local" : {
                        "accessesNotInMemory" : 4,
                        "pageFaultExceptionsThrown" : 1
                },
                "test" : {
                        "accessesNotInMemory" : 5,
                        "pageFaultExceptionsThrown" : 0
                }
        },
        "repl" : {
                "setName" : "rs",
                "ismaster" : true,
                "secondary" : false,
                "hosts" : [
                        "ext023:27017",
                        "ext023:27019",
                        "ext023:27018"
                ],
                "primary" : "ext023:27017",
                "me" : "ext023:27017"
        },
        "workingSet" : {
                "info" : "not supported"
        },
        "writeBacksQueued" : false,
        "mem" : {
                "bits" : 64,
                "resident" : 45,
                "virtual" : 931,
                "supported" : true,
                "mapped" : 368,
                "mappedWithJournal" : 736
        },
        "metrics" : {
                "document" : {
                        "deleted" : NumberLong(0),
                        "inserted" : NumberLong(4),
                        "returned" : NumberLong(40),
                        "updated" : NumberLong(0)
                },
                "getLastError" : {
                        "wtime" : {
                                "num" : 3,
                                "totalMillis" : 0
                        },
                        "wtimeouts" : NumberLong(0)
                },
                "operation" : {
                        "fastmod" : NumberLong(0),
                        "idhack" : NumberLong(0),
                        "scanAndOrder" : NumberLong(0)
                },
                "queryExecutor" : {
                        "scanned" : NumberLong(98)
                },
                "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(25)
                        },
                        "oplog" : {
                                "insert" : {
                                        "num" : 3,
                                        "totalMillis" : 0
                                },
                                "insertBytes" : NumberLong(297)
                        },
                        "preload" : {
                                "docs" : {
                                        "num" : 0,
                                        "totalMillis" : 0
                                },
                                "indexes" : {
                                        "num" : 0,
                                        "totalMillis" : 0
                                }
                        }
                },
                "ttl" : {
                        "deletedDocuments" : NumberLong(0),
                        "passes" : NumberLong(17)
                }
        },
        "ok" : 1
}
rs:PRIMARY>



 Comments   
Comment by auto [ 30/Apr/13 ]

Author:

{u'date': u'2013-04-26T14:29:10Z', u'name': u'Tad Marshall', u'email': u'tad@10gen.com'}

Message: SERVER-9242 Do not show warnings for mongod --help

Remove the call to show_warnings() from show_help_text().

Showing startup warnings in response to a request for information on
available command line options seems wrong, but it also crashes now
because the check for blockCheckSupported() hasn't been set up yet
when command line options are parsed.
Branch: v2.4
https://github.com/mongodb/mongo/commit/0ca298d847d1b38b39147d702dcc162da4872d76

Comment by auto [ 30/Apr/13 ]

Author:

{u'date': u'2013-04-22T17:10:00Z', u'name': u'Tad Marshall', u'email': u'tad@10gen.com'}

Message: SERVER-9242 Change expected test results for unnamed OS (e.g. Solaris)

Until SERVER-9325 is fixed, we don't get good values back from
Solaris/SmartOS, so treat any platform with a blank name (as returned
by db.hostInfo().os.name) as equivalent to Windows XP; test for
the "not supported" set of results.
Branch: v2.4
https://github.com/mongodb/mongo/commit/c557a1a66f1e5747769ee3eccbc0fb58e53884d4

Comment by auto [ 30/Apr/13 ]

Author:

{u'date': u'2013-04-11T09:10:38Z', u'name': u'Tad Marshall', u'email': u'tad@10gen.com'}

Message: SERVER-9242 Do not run block_check_supported.js against mongos
Branch: v2.4
https://github.com/mongodb/mongo/commit/db4d82a844946a0ed1d6fe4dc1ed775ce37190f6

Comment by auto [ 30/Apr/13 ]

Author:

{u'date': u'2013-04-11T09:08:25Z', u'name': u'Tad Marshall', u'email': u'tad@10gen.com'}

Message: SERVER-9242 Whitespace (CRLF)
Branch: v2.4
https://github.com/mongodb/mongo/commit/e33f50c94983be97d8dee41f69cc04c65dada6e3

Comment by auto [ 30/Apr/13 ]

Author:

{u'date': u'2013-04-05T19:25:04Z', u'name': u'Tad Marshall', u'email': u'tad@10gen.com'}

Message: SERVER-9242 Add jstest for blockCheckSupported() features

Add test to make sure that db.serverStatus() returns workingSet and
indexCounters values as expected on all platforms. Windows XP is
expected to give different ("not supported") return values, make
sure that they are as expected.
Branch: v2.4
https://github.com/mongodb/mongo/commit/0610711458cd64ad667ac49aceab9140b1932b09

Comment by auto [ 30/Apr/13 ]

Author:

{u'date': u'2013-04-05T19:28:24Z', u'name': u'Tad Marshall', u'email': u'tad@10gen.com'}

Message: SERVER-9242 Use MONGO_INITIALIZERs to cache blockCheckSupported

Only cache values for blockCheckSupported() after the value has been
determined (for platforms, i.e. Windows, where this is a runtime test).
Branch: v2.4
https://github.com/mongodb/mongo/commit/2c1c529f66491e0eb7fb62ac242d1131393b3380

Comment by auto [ 26/Apr/13 ]

Author:

{u'date': u'2013-04-26T14:29:10Z', u'name': u'Tad Marshall', u'email': u'tad@10gen.com'}

Message: SERVER-9242 Do not show warnings for mongod --help

Remove the call to show_warnings() from show_help_text().

Showing startup warnings in response to a request for information on
available command line options seems wrong, but it also crashes now
because the check for blockCheckSupported() hasn't been set up yet
when command line options are parsed.
Branch: master
https://github.com/mongodb/mongo/commit/78177599d1ea6e4e89337e527f50bd84f367ad3c

Comment by Tad Marshall [ 22/Apr/13 ]

Author:

{u'date': u'2013-04-22T13:10:00Z', u'name': u'Tad Marshall', u'email': u'tad@10gen.com'}

Message: SERVER-9242 Change expected test results for unnamed OS (e.g. Solaris)
Branch: master
https://github.com/mongodb/mongo/commit/ead9f3b6baaab0845348acc3760ba094d74dd884

(This comment added by hand – Github hook didn't run for some reason).

Comment by Tad Marshall [ 22/Apr/13 ]

Windows "mongod.exe --help" crashes because command line options are processed before MONGO_INITIALIZERs run and the --help option tries to display startup warnings, which depend on the psapiGlobal being set by the "SystemInfo" initializer.

Log:

C:\Users\Tad\Documents\Visual Studio 2010\Projects\mongodev>mongod --help
Mon Apr 22 09:08:38.502
Mon Apr 22 09:08:38.502 ** NOTE: This is a development version (2.5.0-pre-) of MongoDB.
Mon Apr 22 09:08:38.518 **       Not recommended for production.
Mon Apr 22 09:08:38.518 *** unhandled exception (access violation) at 0x000000013FFFDAF9, terminating
Mon Apr 22 09:08:38.518 *** access violation was a read from 0x0000000000000000
Mon Apr 22 09:08:38.533 *** stack trace for unhandled exception:
Mon Apr 22 09:08:42.768 mongod.exe    ...\src\mongo\util\processinfo_win32.cpp(205)            mongo::ProcessInfo::blockCheckSupported+0x9
Mon Apr 22 09:08:42.768 mongod.exe    ...\src\mongo\util\version.cpp(201)                      mongo::show_warnings+0x2d4
Mon Apr 22 09:08:42.768 mongod.exe    ...\src\mongo\db\db.cpp(724)                             show_help_text+0x2c
Mon Apr 22 09:08:42.783 mongod.exe    ...\src\mongo\db\db.cpp(890)                             processCommandLineOptions+0x1ec
Mon Apr 22 09:08:42.783 mongod.exe    ...\src\mongo\db\db.cpp(1289)                            mongoDbMain+0x194
Mon Apr 22 09:08:42.783 mongod.exe    ...\src\mongo\db\db.cpp(737)                             wmain+0x78
Mon Apr 22 09:08:42.783 mongod.exe    f:\dd\vctools\crt_bld\self_64_amd64\crt\src\crt0.c(278)  __tmainCRTStartup+0xe2
Mon Apr 22 09:08:42.783 mongod.exe    f:\dd\vctools\crt_bld\self_64_amd64\crt\src\crt0.c(189)  wmainCRTStartup+0xe
Mon Apr 22 09:08:42.783 kernel32.dll                                                           BaseThreadInitThunk+0xd
Mon Apr 22 09:08:42.783 writing minidump diagnostic file mongo.dmp
Mon Apr 22 09:08:42.846 *** immediate exit due to unhandled exception

Stack trace from debugger:

>Debug.ListCallStack
 Index  Function
--------------------------------------------------------------------------------
*1      mongod.exe!mongo::ProcessInfo::blockCheckSupported() 
 2      mongod.exe!mongo::show_warnings() 
 3      mongod.exe!show_help_text(boost::program_options::options_description * options=0x00000000001cf558) 
 4      mongod.exe!processCommandLineOptions(const std::vector<std::basic_string<char,std::char_traits<char>,std::allocator<char> >,std::allocator<std::basic_string<char,std::char_traits<char>,std::allocator<char> > > > & argv=[2]("C:\Users\Tad\Documents\Visual Studio 2010\Projects\mongodev\mongod.exe","--help")) 
 5      mongod.exe!mongoDbMain(int argc=2, char * * argv=0x000000000375f180, char * * envp=0x00000000037fc610) 
 6      mongod.exe!wmain(int argc=2, wchar_t * * argvW=0x0000000001e33150, wchar_t * * envpW=0x0000000001e33240) 
 7      mongod.exe!__tmainCRTStartup() 
 8      mongod.exe!wmainCRTStartup() 
 9      kernel32.dll!BaseThreadInitThunk() 
 10     ntdll.dll!RtlUserThreadStart() 
 
>

Comment by auto [ 11/Apr/13 ]

Author:

{u'date': u'2013-04-11T09:10:38Z', u'name': u'Tad Marshall', u'email': u'tad@10gen.com'}

Message: SERVER-9242 Do not run block_check_supported.js against mongos
Branch: master
https://github.com/mongodb/mongo/commit/31ee545e444d89b85566685f45ab27bf48766a06

Comment by auto [ 11/Apr/13 ]

Author:

{u'date': u'2013-04-11T09:08:25Z', u'name': u'Tad Marshall', u'email': u'tad@10gen.com'}

Message: SERVER-9242 Whitespace (CRLF)
Branch: master
https://github.com/mongodb/mongo/commit/1038d524de8d36ca17d73c39a1880fa13066e47c

Comment by auto [ 10/Apr/13 ]

Author:

{u'date': u'2013-04-05T19:25:04Z', u'name': u'Tad Marshall', u'email': u'tad@10gen.com'}

Message: SERVER-9242 Add jstest for blockCheckSupported() features

Add test to make sure that db.serverStatus() returns workingSet and
indexCounters values as expected on all platforms. Windows XP is
expected to give different ("not supported") return values, make
sure that they are as expected.
Branch: master
https://github.com/mongodb/mongo/commit/0519832fd3916d78bb283903586f53afd477f54c

Comment by auto [ 05/Apr/13 ]

Author:

{u'date': u'2013-04-05T19:28:24Z', u'name': u'Tad Marshall', u'email': u'tad@10gen.com'}

Message: SERVER-9242 Use MONGO_INITIALIZERs to cache blockCheckSupported

Only cache values for blockCheckSupported() after the value has been
determined (for platforms, i.e. Windows, where this is a runtime test).
Branch: master
https://github.com/mongodb/mongo/commit/7d96d614c9b91a668a65992115c12b3ede51faea

Comment by Tad Marshall [ 05/Apr/13 ]

Btree indexCounters has the same problem. The state of blockCheckSupported() is cached before it is ready.

> db.serverStatus().indexCounters
{ "note" : "not supported on this platform" }

Waiting until the value is ready before caching it fixes this:

> db.serverStatus({workingSet:1}).workingSet
{
        "note" : "thisIsAnEstimate",
        "pagesInMemory" : 3,
        "computationTimeMicros" : 5488,
        "overSeconds" : 11
}
> db.serverStatus().indexCounters
{
        "accesses" : 0,
        "hits" : 0,
        "misses" : 0,
        "resets" : 0,
        "missRatio" : 0
}

Comment by Tad Marshall [ 04/Apr/13 ]

This is worse than just losing the workingSet feature; it also prevents the Windows QueryWSEx() API from being used to see if a data page is in the working set, so it could affect performance as well.

Comment by Tad Marshall [ 04/Apr/13 ]

I verified that this is true and it is a bug.

The actual value for "blockCheckSupported()" and a constant holding a copy of that value are both statically initialized, meaning that the order in which they are initialized is unspecified.

In this case, the constant "blockSupported" is first set to the unitialized value of "blockCheckSupported()" and then the correct value of blockCheckSupported is determined.

This bug only affects Windows because Windows is the only platform where the availability of the "blockCheckSupported()" feature is a runtime check. Linux and the Mac just return "true", for example.

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