行業案例| 千億級高併發MongoDB叢集在某頭部金融機構中的應用及效能優化實踐(上)

root@:/data1/xxxx/xxxx/db# ls  TencetDTSData  WiredTiger.lock  WiredTiger.wt  _mdb_catalog.wt  area  diagnostic.data  local  mongod.lock  mongoshake  storage.bson  WiredTiger   WiredTiger.turtle  WiredTigerLAS.wt  admin  config  journal   maicai  mongod.pid  sizeStorer.wt  test  root@:/data1/xxxx/xxxx/db#   root@:/data1/xxxx/xxxx/db#   root@:/data1/xxxx/xxxx/db#   root@:/data1/xxxx/xxxx/db#

root@:/data1/xxxx/xxx/db/diagnostic.data#   root@:/data1/xxxx/xxxx/db/diagnostic.data# ls  metrics.xxxx-12-27T02-28-58Z-00000  metrics.xxxx-12-28T14-33-57Z-00000  metrics.xxxx-12-30T04-28-57Z-00000  metrics.xxxx-12-31T17-08-57Z-00000  metrics.xxxx-01-02T05-28-57Z-00000  metrics.xxxx-12-27T09-18-58Z-00000  metrics.xxxx-12-28T23-13-57Z-00000  metrics.xxxx-12-30T11-23-57Z-00000  metrics.xxxx-01-01T00-53-57Z-00000  metrics.interim  metrics.xxxx-12-27T16-28-57Z-00000  metrics.xxxx-12-29T06-08-57Z-00000  metrics.xxxx-12-30T19-18-57Z-00000  metrics.xxxx-01-01T07-23-57Z-00000  metrics.xxxx-12-28T00-48-57Z-00000  metrics.xxxx-12-29T12-58-57Z-00000  metrics.xxxx-12-31T02-58-57Z-00000  metrics.xxxx-01-01T14-18-57Z-00000  metrics.xxxx-12-28T07-38-57Z-00000  metrics.xxxx-12-29T21-18-57Z-00000  metrics.xxxx-12-31T09-48-57Z-00000  metrics.xxxx-01-01T22-38-57Z-00000  root@:/data1/xxx/xxxx/db/diagnostic.data#   root@:/data1/xxxx/xxxx/db/diagnostic.data#

Xxxx 12 22:51:28.891 F -        [conn7625] Failed to mlock: Cannot allocate memory  Xxxx 12 22:51:28.891 F -        [conn7625] Fatal Assertion 28832 at src/mongo/base/secure_allocator.cpp 246  Xxxx 12 22:51:28.891 F -        [conn7625]  ***aborting after fassert() failure  Xxxx 12 22:51:28.918 F -        [conn7625] Got signal: 6 (Aborted).  ..........  ----- BEGIN BACKTRACE -----  {"backtrace":   libc.so.6(abort+0x148) [0x7fccf1b898c8]   mongod(_ZN5mongo32fassertFailedNoTraceWithLocationEiPKcj+0x0) [0x7fccf3b33ed2]   mongod(_ZN5mongo24secure_allocator_details8allocateEmm+0x59D) [0x7fccf51d6d6d]   mongod(_ZN5mongo31SaslSCRAMServerConversationImplINS_8SHABlockINS_15SHA1BlockTraitsEEEE26initAndValidateCredentialsEv+0x167) [0x7fccf4148ca7]   mongod(_ZN5mongo27SaslSCRAMServerConversation10_firstStepENS_10StringDataEPNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE+0x959) [0x7fccf414dcd9]   mongod(_ZN5mongo27SaslSCRAMServerConversation4stepENS_10StringDataEPNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE+0x9B) [0x7fccf414eecb]   mongod(_ZN5mongo31NativeSaslAuthenticationSession4stepENS_10StringDataEPNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE+0x3C) [0x7fccf414731c]   mongod(+0xF355CD) [0x7fccf41405cd]   mongod(+0xF37D3A) [0x7fccf4142d3a]   mongod(_ZN5mongo12BasicCommand11enhancedRunEPNS_16OperationContextERKNS_12OpMsgRequestERNS_14BSONObjBuilderE+0x76) [0x7fccf4cefde6]

//disabledSecureAllocatorDomains配置初始化配置  

ExportedServerParameter<std::vector<std::string>, ServerParameterType::kStartupOnly>  

    SecureAllocatorDomains(ServerParameterSet::getGlobal(),  

"disabledSecureAllocatorDomains",  

                           &serverGlobalParams.disabledSecureAllocatorDomains);  





template <typename NameTrait>  

struct TraitNamedDomain {

//該介面在SecureAllocatorDomain類中的相關介面中生效，決定走mlock流程還是普通malloc流程  

static bool peg() {  

const auto& dsmd = serverGlobalParams.disabledSecureAllocatorDomains;  

const auto contains = [&](StringData dt) {  

return std::find(dsmd.begin(), dsmd.end(), dt) != dsmd.end();  

        };  





//注意這裡，如果disabledSecureAllocatorDomains配置為*，直接false  

static const bool ret = !(contains("*"_sd) || contains(NameTrait::DomainType));  

return ret;  

    }  

};  





void deallocate(pointer ptr, size_type n) {  

return secure_allocator_details::deallocateWrapper(  

//peg()決定是走mlock流程還是普通malloc流程  

static_cast<void*>(ptr), sizeof(value_type) * n, DomainTraits::peg());  

}  





inline void* allocateWrapper(std::size_t bytes, std::size_t alignOf, bool secure) {  

if (secure) {  

//最終走mlock流程  

return allocate(bytes, alignOf);  

    } else {  

//走std::malloc普通記憶體分配流程  

return mongoMalloc(bytes);  

    }  

}

setParameter:    disabledSecureAllocatorDomains: '*'

Xxxx 11 12:02:19.125 I ASIO     [NetworkInterfaceASIO-RS-0] Ending connection to host x.x.x.x:11200 due to bad connection status; 2 connections to that host remain open  Xxxx 11 12:02:19.125 I REPL     [replication-18302] Restarting oplog query due to error: NetworkInterfaceExceededTimeLimit: error in fetcher batch callback :: caused by :: Operation timed out. Last fetched optime (with hash): { ts: Timestamp(1649926929, 5296), t: 31 }[-1846165485094137853]. Restarts remaining: 3  Xxxx 11 12:02:19.125 I REPL     [replication-18302] Scheduled new oplog query Fetcher source: x.x.x.x:11200 database: local query: { find: "oplog.rs", filter: { ts: { $gte: Timestamp(1649926929, 5296) } }, tailable: true, oplogReplay: true, awaitData: true, maxTimeMS: 60000, batchSize: 13981010, term: 31, readConcern: { afterClusterTime: Timestamp(1649926929, 5296) } } query metadata: { $replData: 1, $oplogQueryData: 1, $readPreference: { mode: "secondaryPreferred" } } active: 1 findNetworkTimeout: 65000ms getMoreNetworkTimeout: 10000ms shutting down?: 0 first: 1 firstCommandScheduler: RemoteCommandRetryScheduler request: RemoteCommand 3332431257 -- target:x.x.x.x:11200 db:local cmd:{ find: "oplog.rs", filter: { ts: { $gte: Timestamp(1649926929, 5296) } }, tailable: true, oplogReplay: true, awaitData: true, maxTimeMS: 60000, batchSize: 13981010, term: 31, readConcern: { afterClusterTime: Timestamp(1649926929, 5296) } } active: 1 callbackHandle.valid: 1 callbackHandle.cancelled: 0 attempt: 1 retryPolicy: RetryPolicyImpl maxAttempts: 1 maxTimeMillis: -1ms  Xxxx 11 12:02:20.211 I REPL     [replexec-4628] Starting an election, since we've seen no PRIMARY in the past 10000ms  Xxxx 11 12:02:20.211 I REPL     [replexec-4628] conducting a dry run election to see if we could be elected. current term: 31  Xxxx 11 12:02:20.215 I ASIO     [NetworkInterfaceASIO-Replication-0] Connecting to x.x.x.x:11200  Xxxx 11 12:02:20.393 I REPL     [replexec-4620] VoteRequester(term 31 dry run) received a yes vote from 10.22.13.85:11200; response message: { term: 31, voteGranted: true, reason: "", ok: 1.0, operationTime: Timestamp(1649926929, 5296), $gleStats: { lastOpTime: Timestamp(0, 0), electionId: ObjectId('7fffffff000000000000001b') }, $clusterTime: { clusterTime: Timestamp(1649926932, 3), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $configServerState: { opTime: { ts: Timestamp(1649926932, 3), t: 1 } } }  Xxxx 11 12:02:20.393 I REPL     [replexec-4620] dry election run succeeded, running for election in term 32  Xxxx 11 12:02:20.474 I REPL_HB  [replexec-4628] Error in heartbeat (requestId: 3332431247) to x.x.x.x:11200, response status: NetworkInterfaceExceededTimeLimit: Operation timed out  Xxxx 11 12:02:20.474 I REPL     [replexec-4628] Member x.x.x.x:11200 is now in state RS_DOWN  Xxxx 11 12:02:20.477 I REPL     [replexec-4628] VoteRequester(term 32) received a no vote from x.x.x.x:11200 with reason "candidate's data is staler than mine. candidate's last applied OpTime: { ts: Timestamp(1649926929, 5296), t: 31 }, my last applied OpTime: { ts: Timestamp(1649926940, 5), t: 31 }"; response message: { term: 31, voteGranted: false, reason: "candidate's data is staler than mine. candidate's last applied OpTime: { ts: Timestamp(1649926929, 5296), t: 31 }, my last applied OpTime: { ts: Times...", ok: 1.0, operationTime: Timestamp(1649926940, 5), $gleStats: { lastOpTime: Timestamp(0, 0), electionId: ObjectId('7fffffff000000000000001f') }, $clusterTime: { clusterTime: Timestamp(1649926940, 6), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $configServerState: { opTime: { ts: Timestamp(1649926937, 2), t: 1 } } }  Xxxx 11 12:02:20.629 I REPL     [replexec-4620] election succeeded, assuming primary role in term 32  Xxxx 11 12:02:20.630 I REPL     [replexec-4620] transition to PRIMARY from SECONDARY

cfg = rs.conf()  cfg.settings.heartbeatTimeoutSecs=20  cfg.settings.electionTimeoutMillis=20000  rs.reconfig(cfg)

Xxxx 11 10:08:22.107 I COMMAND  [conn15350423] command xx.xxx command:  find ........................... protocol:op_msg 92417ms  .............  Xxxx 11 10:08:22.108 I COMMAND  [conn15271960] serverStatus was very slow: { after basic: 0, after asserts: 0, after backgroundFlushing: 0, after connections: 0, after dur: 0, after extra_info: 0, after globalLock: 0, after locks: 0, after logicalSessionRecordCache: 0, after network: 0, after opLatencies: 0, after opcounters: 0, after opcountersRepl: 0, after repl: 0, after sharding: 0, after shardingStatistics: 0, after storageEngine: 0, after tcmalloc: 11515, after transactions: 11515, after wiredTiger: 11565, at end: 11565 }  .........  Xxxx 11 10:08:22.109 I COMMAND  [conn15350423] command xx.xxxx command:  find ........................... protocol:op_msg 112417ms  Xxxx 11 10:08:22.109 I COMMAND  [conn15350423] command xxx.xxx command:  find ........................... protocol:op_msg 116417ms

db.adminCommand( { setParameter: 1, tcmallocReleaseRate: 5.0 } )

db.adminCommand({setParameter:1,tcmallocAggressiveMemoryDecommit:1})

Xxx xxx  8 23:43:28.043 I REPL     [replication-4655] Restarting oplog query due to error: NetworkInterfaceExceededTimeLimit: error in fetcher batch callback :: caused by :: Operation timed out. Last fetched optime (with hash): { ts: Timestamp(1644334998, 110), t: 10 }[3906139038645227612]. Restarts remaining: 3  Xxx xxx  8 23:43:36.439 I REPL     [replexec-8667] Starting an election, since we've seen no PRIMARY in the past 10000ms  Xxx xxx  8 23:43:36.439 I REPL     [replexec-8667] conducting a dry run election to see if we could be elected. current term: 10  .....  Xxx xxx  8 23:43:44.260 I REPL     [replexec-8666] election succeeded, assuming primary role in term 11  .....  Xxx xxx  8 23:43:44.261 I REPL     [replexec-8666] transition to PRIMARY from SECONDARY  Xxx xxx  8 23:43:44.261 I REPL     [replexec-8666] Entering primary catch-up mode.

Xxxx  9 00:16:22.728 I COMMAND  [conn359980] command db_xx.collection_xx command: find ....... ,shardVersion: [ Timestamp(42277, 3330213) ,ObjectId('61a355b18444860129c524ec') ] numYields:0 ok:0 errMsg:"shard version not ok: version epoch mismatch detected for DBXX.COLLECTIONXX, the collection may have been dropped and recreated" errName:StaleConfig errCode:13388 reslen:570 timeAcquiringMicros: { r: 1277246 }  protocol:op_msg 1941243ms  Xxxx  9 00:16:22.728 I COMMAND  [conn359980] command db_xx.collection_xx command: find ....... ,shardVersion: [ Timestamp(42277, 3330213) ,ObjectId('61a355b18444860129c524ec') ] numYields:0 ok:0 errMsg:"shard version not ok: version epoch mismatch detected for DBXX.COLLECTIONXX, the collection may have been dropped and recreated" errName:StaleConfig errCode:13388 reslen:570 timeAcquiringMicros: { r: 1277246 }  protocol:op_msg 1923443ms  Xxxx  9 00:16:22.728 I COMMAND  [conn359980] command db_xx.collection_xx command: find ....... ,shardVersion: [ Timestamp(42277, 3330213) ,ObjectId('61a355b18444860129c524ec') ]numYields:0 ok:0 errMsg:"shard version not ok: version epoch mismatch detected for DBXX.COLLECTIONXX, the collection may have been dropped and recreated" errName:StaleConfig errCode:13388 reslen:570 timeAcquiringMicros: { r: 1277246 }  protocol:op_msg 1831553ms  Xxxx  9 00:16:22.728 I COMMAND  [conn359980] command db_xx.collection_xx command: find ....... ,shardVersion: [ Timestamp(42277, 3330213) ,ObjectId('61a355b18444860129c524ec') ] numYields:0 ok:0 errMsg:"shard version not ok: version epoch mismatch detected for DBXX.COLLECTIONXX, the collection may have been dropped and recreated" errName:StaleConfig errCode:13388 reslen:570 timeAcquiringMicros: { r: 1277246 }  protocol:op_msg 1751243ms  Xxxx  9 00:16:22.728 I COMMAND  [conn359980] command db_xx.collection_xx command: find ....... ,shardVersion: [ Timestamp(42277, 3330213) ,ObjectId('61a355b18444860129c524ec') ]numYields:0 ok:0 errMsg:"shard version not ok: version epoch mismatch detected for DBXX.COLLECTIONXX, the collection may have been dropped and recreated" errName:StaleConfig errCode:13388 reslen:570 timeAcquiringMicros: { r: 1277246 }  protocol:op_msg 1954243ms

Xxx xxx  8 23:43:53.306 I SHARDING [conn357594] Refreshing chunks for collection db_xx.collection_xx based on version 0|0||000000000000000000000000  Xxxx  9 00:15:47.486 I SHARDING [ConfigServerCatalogCacheLoader-0] Cache loader remotely refreshed for collection db_xx.collection_xx from collection version 42227|53397||ada355b18444860129css4ec  and found collection version 42277|53430||ada355b18444860129css4ec   Xxxx  9 00:16:06.352 I SHARDING [ConfigServerCatalogCacheLoader-0] Cache loader found enqueued metadata from 42227|53397||ada355b18444860129css4ec  to 42277|53430||ada355b18444860129css4ec  and persisted metadata from 185|504||ada355b18444860129css4ec  to 42277|53430||ada355b18444860129css4ec , GTE cache version 0|0||000000000000000000000000Xxxx  9 00:16:21.550 I SHARDING [ConfigServerCatalogCacheLoader-0] Refresh for collection db_xx.collection_xx took 1948243 ms and found version 42277|53430||ada355b18444860129css4ec

Status ShardServerCatalogCacheLoader::_ensureMajorityPrimaryAndScheduleTask(  

    OperationContext* opCtx, const NamespaceString& nss, Task task) {  





//寫一個noop到多數派節點成功才返回，如果這時候主從延遲過高，則這裡會卡頓  

    Status linearizableReadStatus = waitForLinearizableReadConcern(opCtx);  

if (!linearizableReadStatus.isOK()) {  

return {linearizableReadStatus.code(),  

          str::stream() << "Unable to schedule routing table update because this is not the"

             << " majority primary and may not have the latest data. Error: "

              << linearizableReadStatus.reason()};  

    }  





//繼續處理後續邏輯

   ......  

}

void execCommandDatabase(…) {  

        ......  

if (!opCtx->getClient()->isInDirectClient() &&  

          readConcernArgs.getLevel() != repl::ReadConcernLevel::kAvailableReadConcern &&  

            (iAmPrimary ||  

             ((serverGlobalParams.featureCompatibility.getVersion() ==  

               ServerGlobalParams::FeatureCompatibility::Version::kFullyUpgradedTo36) &&  

//如果是從節點，則需要請求攜帶readConcern: { level: <level> }配置

//  或者請求攜帶afterClusterTime引數資訊  

       (readConcernArgs.hasLevel() || readConcernArgs.getArgsClusterTime())))) {  

//獲取版本資訊，並記錄下來  

        oss.initializeShardVersion(NamespaceString(command>parseNs  

                 (dbname, request.body)),   shardVersionFieldIdx);  

        ......  

}  





//重新整理後設資料資訊，例如表對應chunk路由資訊等  

Status ShardingState::onStaleShardVersion(…) {  

    ......  

//本地的shardversion和代理mongos傳送過來的做比較，如果本地快取的

//版本號比mongos的高，則啥也不做不用重新整理後設資料  

if (collectionShardVersion.epoch() == expectedVersion.epoch() &&  

        collectionShardVersion >= expectedVersion) {  

return Status::OK();  

    }  





//如果本地路由版本比接收到的低，則直接進入路由重新整理流程  

    refreshMetadata(opCtx, nss);  

    ......  

}

use dbxx  db.getMongo().setReadPref('secondary')  //訪問分片1從節點資料  db.collectionxx.find({"_id" : ObjectId("xxx")}).readConcern("local")  ......  //訪問分片n從節點資料  db.collectionxx.find({"_id" : ObjectId("xxx")}).readConcern("local")