Loading...

Type: Improvement
Resolution: Fixed
Priority: Major - P3
Fix Version/s: 6.1.0-rc0
Affects Version/s: None
Component/s: None
Labels:
None

Backwards Compatibility:
Fully Compatible
Sprint:
Execution Team 2022-06-13, Execution Team 2022-06-27, Execution Team 2022-07-11, Execution Team 2022-07-25
Confidence Status:
None
Work Order:
3

Aha! Reference:
None
Tracking Level:
None
Risk Status:
None
Exec Notes:
None
Goal Name:
None
Goal Link:
None

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=...)
...

Details

Description

Attachments

Activity

People

Dates