-
Type: Improvement
-
Resolution: Fixed
-
Priority: Major - P3
-
Affects Version/s: None
-
Component/s: None
-
None
-
Fully Compatible
-
Execution Team 2022-06-13, Execution Team 2022-06-27, Execution Team 2022-07-11, Execution Team 2022-07-25
We found that waiting for write concerns will cause RPUs in HELP-33863 when reading the top of the oplog. HELP-33863 has more details about the behavior. It's surprising to customers and chris.shum@mongodb.com confirmed that we need to change the behavior.
We should test {w: 1} and {w: "majority"} with "j" unspecified, "true" and "false".
Here's the stack trace of incrementing RPUs on waiting for write concerns.
#0 mongo::ResourceConsumption::MetricsCollector::incrementOneDocRead (this=0x7fee240c5678, docBytesRead=167) at src/mongo/db/query/server_status.h:240 #1 0x00005591399a4a6c in mongo::WiredTigerRecordStoreCursorBase::next (this=0x7fee2cc15b20) at src/mongo/db/storage/idle_thread_block.h:2243 #2 0x000055913998dc9e in mongo::WiredTigerOplogManager::waitForAllEarlierOplogWritesToBeVisible (this=0x7fee2ce66fe0, oplogRecordStore=0x7fee247ce020, opCtx=0x7fee25ecd6e0) at src/mongo/bson/idle_thread_block.h:134 #3 0x00005591399a2309 in mongo::WiredTigerRecordStore::waitForAllEarlierOplogWritesToBeVisibleImpl (this=0x7fee247ce020, opCtx=0x7fee25ecd6e0) at src/mongo/db/storage/idle_thread_block.h:1881 #4 0x000055913b1bb26a in mongo::RecordStore::waitForAllEarlierOplogWritesToBeVisible (this=0x7fee247ce020, opCtx=0x7fee25ecd6e0) at src/mongo/bson/operation_context.h:112 #5 0x0000559138a6a8e2 in mongo::repl::StorageInterfaceImpl::waitForAllEarlierOplogWritesToBeVisible (this=0x7fee2c7b82c0, opCtx=0x7fee25ecd6e0, primaryOnly=true) at src/mongo/bson/storage_interface.h:1512 #6 0x000055913a8efecf in mongo::waitForNoOplogHolesIfNeeded (opCtx=0x7fee25ecd6e0) at src/third_party/variant-1.4.0/include/mpark/log_options.h:260 #7 0x000055913a8f0357 in mongo::waitForWriteConcern (opCtx=0x7fee25ecd6e0, replOpTime=..., writeConcern=..., result=0x7fee01920f40) at src/third_party/variant-1.4.0/include/mpark/log_options.h:318 #8 0x000055913888db72 in mongo::ServiceEntryPointMongod::Hooks::waitForWriteConcern(mongo::OperationContext*, mongo::CommandInvocation const*, mongo::repl::OpTime const&, mongo::BSONObjBuilder&) const::{lambda()#1}::operator()() const (__closure=0x7fee01921060) at build/debug/mongo/s/shard_cannot_refresh_due_to_locks_held_exception.h:133 #9 0x000055913888dd58 in mongo::ServiceEntryPointMongod::Hooks::waitForWriteConcern (this=0x7fee24fc19e0, opCtx=0x7fee25ecd6e0, invocation=0x7fee26797da0, lastOpBeforeRun=..., commandResponseBuilder=...) at build/debug/mongo/s/shard_cannot_refresh_due_to_locks_held_exception.h:140 #10 0x000055913889bbad in mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_waitForWriteConcern (this=0x7fee26cd0ba0, bb=...) at src/mongo/db/stats/tracking_metadata.h:1171 #11 0x000055913889d8a8 in mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_checkWriteConcern (this=0x7fee26cd0ba0) at src/mongo/db/stats/tracking_metadata.h:1273 #12 0x000055913889bc52 in operator() (__closure=0x7fee019214e8, status=...) at src/mongo/db/stats/tracking_metadata.h:1178 #13 0x000055913889bd2b in mongo::future_details::call<mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_runImpl()::<lambda(mongo::Status)>&>(struct {...} &, mongo::StatusWith<mongo::future_details::FakeVoid>) (func=..., sw=...) at src/mongo/util/status_with.h:260 #14 0x000055913889bdca in mongo::future_details::throwingCall<mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_runImpl()::<lambda(mongo::Status)>, mongo::StatusWith<mongo::future_details::FakeVoid> >(struct {...} &&) (func=...) at src/mongo/util/status_with.h:308 #15 0x000055913889be73 in operator() (__closure=0x7fee01921430, val=...) at src/mongo/util/status_with.h:977 #16 0x000055913889c5f4 in mongo::future_details::FutureImpl<mongo::future_details::FakeVoid>::generalImpl<mongo::future_details::FutureImpl<mongo::future_details::FakeVoid>::onCompletion<mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_runImpl()::<lambda(mongo::Status)> >(mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_runImpl()::<lambda(mongo::Status)>&&) &&::<lambda(mongo::future_details::FakeVoid&&)>, mongo::future_details::FutureImpl<mongo::future_details::FakeVoid>::onCompletion<mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_runImpl()::<lambda(mongo::Status)> >(mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_runImpl()::<lambda(mongo::Status)>&&) &&::<lambda(mongo::Status&&)>, mongo::future_details::FutureImpl<mongo::future_details::FakeVoid>::onCompletion<mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_runImpl()::<lambda(mongo::Status)> >(mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_runImpl()::<lambda(mongo::Status)>&&) &&::<lambda()> >(struct {...} &&, struct {...} &&, struct {...} &&) (this=0x7fee019214f0, success=..., fail=..., notReady=...) at src/mongo/util/status_with.h:1184 #17 0x000055913889c7a8 in mongo::future_details::FutureImpl<mongo::future_details::FakeVoid>::onCompletion<mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_runImpl()::<lambda(mongo::Status)> >(struct {...} &&) (this=0x7fee019214f0, func=...) at src/mongo/util/status_with.h:1015 #18 0x000055913889c847 in mongo::Future<void>::onCompletion<mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_runImpl()::<lambda(mongo::Status)> >(struct {...} &&) (this=0x7fee019214f0, func=...) at src/mongo/bson/write_concern_options.h:418 #19 0x000055913889c8e1 in mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern::_runImpl (this=0x7fee26cd0ba0) at src/mongo/db/stats/tracking_metadata.h:1182 #20 0x0000559138895ea2 in operator() (__closure=0x7fee019215b8) at src/mongo/db/stats/tracking_metadata.h:656 #21 0x00005591388a9bb6 in mongo::makeReadyFutureWith<mongo::(anonymous namespace)::RunCommandImpl::run()::<lambda()> >(struct {...} &&) (func=...) at src/mongo/bson/write_concern_options.h:1225 #22 0x00005591388973e4 in mongo::(anonymous namespace)::RunCommandImpl::run (this=0x7fee26cd0ba0) at src/mongo/db/stats/tracking_metadata.h:654 #23 0x00005591388a087a in operator()<mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern> (__closure=0x7fee0192178f, runner=0x7fee26cd0ba0) at src/mongo/db/stats/tracking_metadata.h:1639 #24 0x00005591388a08fc in operator() (__closure=0x7fee01921740) at src/mongo/rpc/api_parameters_gen.h:827 #25 0x00005591388ac738 in mongo::makeReadyFutureWith<mongo::future_util::AsyncState<mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern>::thenWithState<mongo::(anonymous namespace)::ExecCommandDatabase::_commandExec()::<lambda()>::<lambda(auto:81*)> >(mongo::(anonymous namespace)::ExecCommandDatabase::_commandExec()::<lambda()>::<lambda(auto:81*)>&&) &&::<lambda()> >(struct {...} &&) (func=...) at src/mongo/bson/write_concern_options.h:1225 #26 0x00005591388a0a4e in mongo::future_util::AsyncState<mongo::(anonymous namespace)::RunCommandAndWaitForWriteConcern>::thenWithState<mongo::(anonymous namespace)::ExecCommandDatabase::_commandExec()::<lambda()>::<lambda(auto:81*)> >(struct {...} &&) ( this=0x7fee019217a0, launcher=...) at src/mongo/rpc/api_parameters_gen.h:832 #27 0x00005591388a0f69 in operator() (__closure=0x7fee01921800) at src/mongo/db/stats/tracking_metadata.h:1639 #28 0x00005591388a1f51 in mongo::(anonymous namespace)::ExecCommandDatabase::_commandExec (this=0x7fee240de020) at src/mongo/db/stats/tracking_metadata.h:1646 #29 0x0000559138894b6e in operator() (__closure=0x7fee01921920) at src/mongo/db/stats/tracking_metadata.h:536 #30 0x00005591388a97df in mongo::makeReadyFutureWith<mongo::(anonymous namespace)::ExecCommandDatabase::run()::<lambda()> >(struct {...} &&) (func=...) at src/mongo/bson/write_concern_options.h:1225 #31 0x0000559138895770 in mongo::(anonymous namespace)::ExecCommandDatabase::run (this=0x7fee240de020) at src/mongo/db/stats/tracking_metadata.h:534 #32 0x00005591388a4204 in operator()<mongo::(anonymous namespace)::ExecCommandDatabase> (__closure=0x7fee01921adf, runner=0x7fee240de020) at src/mongo/db/stats/tracking_metadata.h:1917 #33 0x00005591388a4286 in operator() (__closure=0x7fee01921a90) at src/mongo/rpc/api_parameters_gen.h:827 #34 0x00005591388ae118 in mongo::makeReadyFutureWith<mongo::future_util::AsyncState<mongo::(anonymous namespace)::ExecCommandDatabase>::thenWithState<mongo::(anonymous namespace)::executeCommand(std::shared_ptr<mongo::(anonymous namespace)::HandleRequest::ExecutionContext>)::<lambda()> mutable::<lambda(auto:83*)> >(mongo::(anonymous namespace)::executeCommand(std::shared_ptr<mongo::(anonymous namespace)::HandleRequest::ExecutionContext>)::<lambda()> mutable::<lambda(auto:83*)>&&) &&::<lambda()> >(struct {...} &&) (func=...) at src/mongo/bson/write_concern_options.h:1225 #35 0x00005591388a43d8 in mongo::future_util::AsyncState<mongo::(anonymous namespace)::ExecCommandDatabase>::thenWithState<mongo::(anonymous namespace)::executeCommand(std::shared_ptr<mongo::(anonymous namespace)::HandleRequest::ExecutionContext>)::<lambda()> mutable::<lambda(auto:83*)> >(struct {...} &&) (this=0x7fee01921ae0, launcher=...) at src/mongo/rpc/api_parameters_gen.h:832 #36 0x00005591388a4446 in operator() (__closure=0x7fee23f5d018) at src/mongo/db/stats/tracking_metadata.h:1917 #37 0x00005591388a44bb in mongo::future_details::call<mongo::(anonymous namespace)::executeCommand(std::shared_ptr<mongo::(anonymous namespace)::HandleRequest::ExecutionContext>)::<lambda()>&>(struct {...} &, mongo::future_details::FakeVoid) (func=...) ...