[SERVER-47179] Requesting 'oplog' serverStatus section crashes mongod when there is no oplog Created: 30/Mar/20  Updated: 29/Oct/23  Resolved: 07/Apr/20

Status: Closed
Project: Core Server
Component/s: Replication
Affects Version/s: 4.3.5
Fix Version/s: 4.4.0-rc0, 4.7.0

Type: Bug Priority: Critical - P2
Reporter: Dennis Kuczynski Assignee: Lingzhi Deng
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File mongodb.log.2020-03-30T14-35-18    
Issue Links:
Backports
Problem/Incident
is caused by SERVER-30883 Fast-path caching of oldest oplog entry Closed
Backwards Compatibility: Fully Compatible
Operating System: ALL
Backport Requested:
v4.4
Steps To Reproduce:

Our end to end suite is reproducing this regularly. They use a single windows-64-vs2017-compile host.

  • Create a 4.3.5 Replica Set using Cloud Manager
  • Wait for the item to be monitored by the MongoDB Agent.

Our tests are failing since we do not receive the expected monitoring data within our usual timeframe.

Sprint: Repl 2020-04-20
Participants:

 Description   

We're seeing backtraces during our windows testing of 4.3.5.

The tests use a single windows-64-vs2017 host to create standalones, replica sets, and sharded clusters with the latest version of MongoDB 4.3. The crash seems to occur periodically while those items are being monitored by the Cloud Manager MongoDB Agent.

Snippet of logs:

{"t":{"$date":"2020-03-30T14:35:15.623+00:00"},"s":"I", "c":"CONTROL", "id":31380,"ctx":"conn103","msg":"BACKTRACE: {bt}","attr":{"bt":{"backtrace":[{"a":"7FF6F768FDBD","module":"mongod.exe","file":".../src/mongo/db/repl/replication_info.cpp","line":267,"s":"mongo::repl::`anonymous namespace'::OplogInfoServerStatus::generateSection","s+":"1FD"},{"a":"7FF6F7566F31","module":"mongod.exe","file":".../src/mongo/db/commands/server_status.h","line":100,"s":"mongo::ServerStatusSection::appendSection","s+":"21"},{"a":"7FF6F7CEA6A9","module":"mongod.exe","file":".../src/mongo/db/commands/server_status.cpp","line":127,"s":"mongo::CmdServerStatus::run","s+":"6A9"},{"a":"7FF6F762C817","module":"mongod.exe","file":".../src/mongo/db/commands.h","line":803,"s":"mongo::BasicCommand::runWithReplyBuilder","s+":"57"},{"a":"7FF6F7E7E8F1","module":"mongod.exe","file":".../src/mongo/db/commands.cpp","line":771,"s":"mongo::BasicCommandWithReplyBuilderInterface::Invocation::run","s+":"111"},{"a":"7FF6F7E7ED03","module":"mongod.exe","file":".../src/mongo/db/commands.cpp","line":187,"s":"mongo::CommandHelpers::runCommandInvocation","s+":"83"},{"a":"7FF6F762B335","module":"mongod.exe","file":".../src/mongo/db/service_entry_point_common.cpp","line":803,"s":"mongo::`anonymous namespace'::runCommandImpl","s+":"145"},{"a":"7FF6F7626387","module":"mongod.exe","file":".../src/mongo/db/service_entry_point_common.cpp","line":1126,"s":"mongo::`anonymous namespace'::execCommandDatabase","s+":"19B7"},{"a":"7FF6F7621240","module":"mongod.exe","file":".../src/mongo/db/service_entry_point_common.cpp","line":1299,"s":"<lambda_058cab8c39a04572e0ffda27b896392f>::operator()","s+":"580"},{"a":"7FF6F76293E8","module":"mongod.exe","file":".../src/mongo/db/service_entry_point_common.cpp","line":1321,"s":"mongo::`anonymous namespace'::receivedCommands","s+":"A8"},{"a":"7FF6F7627F2C","module":"mongod.exe","file":".../src/mongo/db/service_entry_point_common.cpp","line":1609,"s":"mongo::ServiceEntryPointCommon::handleRequest","s+":"91C"},{"a":"7FF6F7616A02","module":"mongod.exe","file":".../src/mongo/db/service_entry_point_mongod.cpp","line":288,"s":"mongo::ServiceEntryPointMongod::handleRequest","s+":"32"},{"a":"7FF6F761913E","module":"mongod.exe","file":".../src/mongo/transport/service_state_machine.cpp","line":470,"s":"mongo::ServiceStateMachine::_processMessage","s+":"1BE"},{"a":"7FF6F761964E","module":"mongod.exe","file":".../src/mongo/transport/service_state_machine.cpp","line":549,"s":"mongo::ServiceStateMachine::_runNextInGuard","s+":"9E"},{"a":"7FF6F7618874","module":"mongod.exe","file":"C:/Program Files (x86)/Microsoft Visual Studio/2019/Professional/VC/Tools/MSVC/14.25.28610/include/functional","line":926,"s":"std::_Func_impl_no_alloc<<lambda_b23af5efc3b61ab25bff0c3bcd13382b>,void>::_Do_call","s+":"54"},{"a":"7FF6F85BF3C6","module":"mongod.exe","file":".../src/mongo/transport/service_executor_synchronous.cpp","line":108,"s":"mongo::transport::ServiceExecutorSynchronous::schedule","s+":"106"},{"a":"7FF6F761982A","module":"mongod.exe","file":".../src/mongo/transport/service_state_machine.cpp","line":595,"s":"mongo::ServiceStateMachine::_scheduleNextWithGuard","s+":"CA"},{"a":"7FF6F7619EC9","module":"mongod.exe","file":".../src/mongo/transport/service_state_machine.cpp","line":373,"s":"mongo::ServiceStateMachine::_sourceCallback","s+":"A9"},{"a":"7FF6F76173CC","module":"mongod.exe","file":".../src/mongo/util/future_impl.h","line":237,"s":"mongo::future_details::call<<lambda_666573ec54ca1c645fa7bbc72952f9b3> &,mongo::StatusWith<mongo::Message> >","s+":"BC"},{"a":"7FF6F761853D","module":"mongod.exe","file":".../src/mongo/util/future_impl.h","line":851,"s":"<lambda_ffb7fc866e28718edba5fd77072ab046>::operator()","s+":"4D"},{"a":"7FF6F7617934","module":"mongod.exe","file":".../src/mongo/util/future_impl.h","line":1163,"s":"mongo::future_details::FutureImpl<mongo::Message>::generalImpl<<lambda_ffb7fc866e28718edba5fd77072ab046>,<lambda_7f7540703838fafe7784f645352ec5c4>,<lambda_8f9bb8790eb696dc1ef642ec835e8067> >","s+":"34"},{"a":"7FF6F761A4BA","module":"mongod.exe","file":".../src/mongo/transport/service_state_machine.cpp","line":324,"s":"mongo::ServiceStateMachine::_sourceMessage","s+":"12A"},{"a":"7FF6F761967A","module":"mongod.exe","file":".../src/mongo/transport/service_state_machine.cpp","line":545,"s":"mongo::ServiceStateMachine::_runNextInGuard","s+":"CA"},{"a":"7FF6F7618874","module":"mongod.exe","file":"C:/Program Files (x86)/Microsoft Visual Studio/2019/Professional/VC/Tools/MSVC/14.25.28610/include/functional","line":926,"s":"std::_Func_impl_no_alloc<<lambda_b23af5efc3b61ab25bff0c3bcd13382b>,void>::_Do_call","s+":"54"},{"a":"7FF6F85BF002","module":"mongod.exe","file":".../src/mongo/transport/service_executor_synchronous.cpp","line":125,"s":"<lambda_472996f9e6b00ec91d31b43a6cde81f7>::operator()","s+":"152"},{"a":"7FF6F8736FC6","module":"mongod.exe","file":"C:/Program Files (x86)/Microsoft Visual Studio/2019/Professional/VC/Tools/MSVC/14.25.28610/include/thread","line":43,"s":"std::thread::_Invoke<std::tuple<<lambda_30130984df28a890937aeb9eb32385d9> >,0>","s+":"36"},{"a":"7FFF60E9F4A0","module":"ucrtbase.dll","s":"o__realloc_base","s+":"60"},{"a":"7FFF617284D4","module":"KERNEL32.DLL","s":"BaseThreadInitThunk","s+":"14"}]}}}
{"t":{"$date":"2020-03-30T14:35:15.623+00:00"},"s":"I", "c":"CONTROL", "id":31445,"ctx":"conn103","msg":"  Frame: {frame}","attr":{"frame":{"a":"7FF6F768FDBD","module":"mongod.exe","file":".../src/mongo/db/repl/replication_info.cpp","line":267,"s":"mongo::repl::`anonymous namespace'::OplogInfoServerStatus::generateSection","s+":"1FD"}}}
{"t":{"$date":"2020-03-30T14:35:15.623+00:00"},"s":"I", "c":"CONTROL", "id":31445,"ctx":"conn103","msg":"  Frame: {frame}","attr":{"frame":{"a":"7FF6F7566F31","module":"mongod.exe","file":".../src/mongo/db/commands/server_status.h","line":100,"s":"mongo::ServerStatusSection::appendSection","s+":"21"}}}
{"t":{"$date":"2020-03-30T14:35:15.623+00:00"},"s":"I", "c":"CONTROL", "id":31445,"ctx":"conn103","msg":"  Frame: {frame}","attr":{"frame":{"a":"7FF6F7CEA6A9","module":"mongod.exe","file":".../src/mongo/db/commands/server_status.cpp","line":127,"s":"mongo::CmdServerStatus::run","s+":"6A9"}}}
{"t":{"$date":"2020-03-30T14:35:15.623+00:00"},"s":"I", "c":"CONTROL", "id":31445,"ctx":"conn103","msg":"  Frame: {frame}","attr":{"frame":{"a":"7FF6F762C817","module":"mongod.exe","file":".../src/mongo/db/commands.h","line":803,"s":"mongo::BasicCommand::runWithReplyBuilder","s+":"57"}}}
{"t":{"$date":"2020-03-30T14:35:15.623+00:00"},"s":"I", "c":"CONTROL", "id":31445,"ctx":"conn103","msg":"  Frame: {frame}","attr":{"frame":{"a":"7FF6F7E7E8F1","module":"mongod.exe","file":".../src/mongo/db/commands.cpp","line":771,"s":"mongo::BasicCommandWithReplyBuilderInterface::Invocation::run","s+":"111"}}}
{"t":{"$date":"2020-03-30T14:35:15.623+00:00"},"s":"I", "c":"CONTROL", "id":31445,"ctx":"conn103","msg":"  Frame: {frame}","attr":{"frame":{"a":"7FF6F7E7ED03","module":"mongod.exe","file":".../src/mongo/db/commands.cpp","line":187,"s":"mongo::CommandHelpers::runCommandInvocation","s+":"83"}}}



 Comments   
Comment by Githook User [ 07/Apr/20 ]

Author:

{'name': 'Lingzhi Deng', 'email': 'lingzhi.deng@mongodb.com', 'username': 'ldennis'}

Message: SERVER-47179: Fix crash when requesting serverStatus oplog before the oplog collection is created

(cherry picked from commit d34b92cb31a147cf29fe676081978f3ff7acd79f)
Branch: v4.4
https://github.com/mongodb/mongo/commit/a488e5a035a4824067a1b61005177f87539d614a

Comment by Githook User [ 07/Apr/20 ]

Author:

{'name': 'Lingzhi Deng', 'email': 'lingzhi.deng@mongodb.com', 'username': 'ldennis'}

Message: SERVER-47179: Fix crash when requesting serverStatus oplog before the oplog collection is created
Branch: master
https://github.com/mongodb/mongo/commit/d34b92cb31a147cf29fe676081978f3ff7acd79f

Comment by Lingzhi Deng [ 06/Apr/20 ]

I think this was caused by SERVER-30883. https://github.com/mongodb/mongo/commit/e561492b2547bc8247692731f0682da499bacc8f#diff-617f44adff03c217e246db80993fd65dR251

Prior to that commit, this used to return an error:

{
        "operationTime" : Timestamp(0, 0),
        "ok" : 0,
        "errmsg" : "Problem reading earliest entry from oplog",
        "code" : 17347,
        "codeName" : "Location17347",
        "$clusterTime" : {
                "clusterTime" : Timestamp(0, 0),
                "signature" : {
                        "hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
                        "keyId" : NumberLong(0)
                }
        }
}

Comment by Eric Milkie [ 04/Apr/20 ]

To reproduce this:
1. start mongod on an empty dbpath

./mongod --dbpath=./ --replSet foo

2. run serverStatus with oplog section (oplog section is not displayed by default)

./mongo
> db.runCommand({serverStatus:1, oplog:1})

This will trigger a crash.

Generated at Thu Feb 08 05:13:30 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.