[SERVER-18613] We can double the WiredTiger YCSB load throughput on windows by eliminate the expensive timer operations Created: 21/May/15  Updated: 03/Jun/19  Resolved: 03/Jun/19

Status: Closed
Project: Core Server
Component/s: Internal Code
Affects Version/s: None
Fix Version/s: None

Type: Bug Priority: Critical - P2
Reporter: Eitan Klein Assignee: DO NOT USE - Backlog - Platform Team
Resolution: Done Votes: 0
Labels: 32qa, platforms-re-triaged
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: Text File M3-Benchmark.txt     PNG File ycsbload.png    
Issue Links:
Depends
depends on SERVER-18922 Choose time source for measuring shor... Closed
Related
is related to SERVER-18562 YCSB load phase (insert only) push 1... Closed
Operating System: ALL
Participants:

 Description   

Environment:

  • v3.1.4-pre-
  • AWS C4.XL environment
  • WiredTiger default configuration

Initial throughput w/ original binaries used to be ~ 10 K ops/sec during the load phase

I removed two timer operations described below and i doubled the throughput and reduce the CPU utilization by 2/3 (60% to 20%)

0000030`185ef7c8 00007ff7`070d15bf ntdll!RtlQueryPerformanceCounter
00000030`185ef7d0 00007ff7`07088b29 mongod!mongo::`anonymous namespace'::timerNowWindows+0xf [c:\src\mongo\src\mongo\util\timer.cpp @ 79]
00000030`185ef800 00007ff7`070897c6 mongod!mongo::`anonymous namespace'::PeriodicTaskRunner::_runTask+0x39 [c:\src\mongo\src\mongo\util\background.cpp @ 352]
00000030`185ef910 00007ff7`070892a4 mongod!mongo::`anonymous namespace'::PeriodicTaskRunner::run+0x186 [c:\src\mongo\src\mongo\util\background.cpp @ 336]
00000030`185efa10 00007ff7`070f2a61 mongod!mongo::BackgroundJob::jobBody+0x194 [c:\src\mongo\src\mongo\util\background.cpp @ 160]
00000030`185efba0 00007ff7`07406c83 mongod!boost::`anonymous namespace'::thread_start_function+0x21 [c:\src\mongo\src\third_party\boost-1.56.0\libs\thread\src\win32\thread.cpp @ 215]
00000030`185efbe0 00007ff7`07406e2a mongod!_callthreadstartex+0x17 [f:\dd\vctools\crt\crtw32\startup\threadex.c @ 376]
00000030`185efc10 00007ffd`c20c13d2 mongod!_threadstartex+0x102 [f:\dd\vctools\crt\crtw32\startup\threadex.c @ 354]
00000030`185efc40 00007ffd`c25fe954 KERNEL32!BaseThreadInitThunk+0x22
00000030`185efc70 00000000`00000000 ntdll!RtlUserThreadStart+0x34

2nd stack

000000b4`eee7ba38 00007ffd`c25f41c3 ntdll!RtlQueryPerformanceCounter
000000b4`eee7ba40 00007ffd`bfaa942f ntdll!RtlGetSystemTimePrecise+0x53
*** WARNING: Unable to verify checksum for c:\NoTimer\mongod.exe
000000b4`eee7ba90 00007ff7`0624d4c7 KERNELBASE!GetSystemTimePreciseAsFileTime+0xf
000000b4`eee7bac0 00007ff7`05e0271f mongod!mongo::curTimeMicros64+0x17 [c:\src\mongo\src\mongo\util
 
\time_support.cpp @ 981]
000000b4`eee7baf0 00007ff7`05e01cb8 mongod!mongo::finishCurrentOp+0x4f [c:\src\mongo\src\mongo\db\commands
 
\write_commands\batch_executor.cpp @ 592]
000000b4`eee7c0b0 00007ff7`05e0097d mongod!mongo::WriteBatchExecutor::execUpdate+0x238 [c:\src\mongo\src\mongo\db
 
\commands\write_commands\batch_executor.cpp @ 930]
000000b4`eee7d660 00007ff7`05e020e0 mongod!mongo::WriteBatchExecutor::bulkExecute+0x14d [c:\src\mongo\src\mongo
 
\db\commands\write_commands\batch_executor.cpp @ 757]
000000b4`eee7d760 00007ff7`05e07db3 mongod!mongo::WriteBatchExecutor::executeBatch+0x390 [c:\src\mongo\src\mongo
 
\db\commands\write_commands\batch_executor.cpp @ 246]
000000b4`eee7da70 00007ff7`05e20e43 mongod!mongo::WriteCmd::run+0x263 [c:\src\mongo\src\mongo\db\commands
 
\write_commands\write_commands.cpp @ 152]
000000b4`eee7dcb0 00007ff7`05e19b42 mongod!mongo::Command::run+0x3f3 [c:\src\mongo\src\mongo\db\dbcommands.cpp @ 
 
1465]
000000b4`eee7dfd0 00007ff7`05e1c83c mongod!mongo::_execCommand+0x42 [c:\src\mongo\src\mongo\db\dbcommands.cpp @ 
 
1129]
000000b4`eee7e0f0 00007ff7`05e1a053 mongod!mongo::Command::execCommand+0x118c [c:\src\mongo\src\mongo\db
 
\dbcommands.cpp @ 1410]
000000b4`eee7e910 00007ff7`05e2153c mongod!mongo::`anonymous namespace'::_runCommands+0x4f3 [c:\src\mongo\src
 
\mongo\db\dbcommands.cpp @ 1548]
000000b4`eee7ed70 00007ff7`05ecd29e mongod!mongo::runCommands+0x1c [c:\src\mongo\src\mongo\db\dbcommands.cpp @ 
 
1575]
000000b4`eee7ede0 00007ff7`05ec95e1 mongod!mongo::receivedCommand+0x3ee [c:\src\mongo\src\mongo\db\instance.cpp @ 
 
267]
000000b4`eee7f0e0 00007ff7`06558138 mongod!mongo::assembleResponse+0x821 [c:\src\mongo\src\mongo\db\instance.cpp @ 
 
548]
000000b4`eee7f7f0 00007ff7`0621b390 mongod!mongo::MyMessageHandler::process+0xa8 [c:\src\mongo\src\mongo\db\db.cpp 
 
@ 167]
000000b4`eee7f9d0 00007ff7`06272aa1 mongod!mongo::PortMessageServer::handleIncomingMsg+0x550 [c:\src\mongo\src
 
\mongo\util\net\message_server_port.cpp @ 229]
000000b4`eee7fbf0 00007ff7`06586c73 mongod!boost::`anonymous namespace'::thread_start_function+0x21 [c:\src\mongo
 
\src\third_party\boost-1.56.0\libs\thread\src\win32\thread.cpp @ 215]
000000b4`eee7fc30 00007ff7`06586e1a mongod!_callthreadstartex+0x17 [f:\dd\vctools\crt\crtw32\startup\threadex.c @ 
 
376]
000000b4`eee7fc60 00007ffd`c20c13d2 mongod!_threadstartex+0x102 [f:\dd\vctools\crt\crtw32\startup\threadex.c @ 
 
354]
000000b4`eee7fc90 00007ffd`c25fe954 KERNEL32!BaseThreadInitThunk+0x22
000000b4`eee7fcc0 00000000`00000000 ntdll!RtlUserThreadStart+0x34
 



 Comments   
Comment by Andy Schwerin [ 21/May/15 ]

Also, it appears that the M3 family of AWS instances has fixed the TSC problem, so rerunning your test on an M3 instance would also be very informative.

Comment by Andy Schwerin [ 21/May/15 ]

Eitan, for point of comparison, can you run this test on unvirtualized hardware? I suspect this behavior is a result of the slow implementation of either the RDTSCP instruction or the instructions that read the virtualized HPET in AWS. If that is the case, we'll have to make a hard decision about what timings we measure.

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