事物的开始和结束命令分别是什么_mongodb内核源码实现、性能调优、最佳运维实践系列-command命令处理模块源码实现四...

关于作者

前滴滴出行技术专家，现任OPPO文档数据库mongodb负责人，负责oppo千万级峰值TPS/十万亿级数据量文档数据库mongodb内核研发及运维工作，一直专注于分布式缓存、高性能服务端、数据库、中间件等相关研发。后续持续分享《MongoDB内核源码设计、性能优化、最佳运维实践》，Github账号地址:https://github.com/y123456yz

慢日志、时延统计

每次客户端请求执行实践如果超过了log level配置的最大慢日志时间，则会把该操作详细信息记录下来，同时把本操作执行时间添加到对应的读或者写计数及时延统计中。命令处理模块中，时延相关统计包括以下两种统计：

①　慢日志统计

②　读写计数及时延统计

1. 慢日志统计

当启用了慢日志记录功能后，mongod会把执行时间超过指定阀值的慢日志记录下来。慢日志默认记录到服务日志文件(systemLog.path配置项设置)，同时会记录日志到”system.profile”集合中。慢日志核心代码实现如下:

1.DbResponse ServiceEntryPointMongod::handleRequest(...) {  
2.    ......  
3.    //记录开始时间  
4.    //获取当前操作对应curop  
5.    CurOp& currentOp = *CurOp::get(opCtx);  
6.  
7.    ......  
8.    //执行请求对应命令  
9.    runCommands(opCtx, m);  
10.    ......  
11.  
12.    //记录结束时间  
13.    currentOp.ensureStarted();  
14.    currentOp.done();   
15.    //获取开始和结束时间差，也就是命令执行时间  
16.    debug.executionTimeMicros = durationCount<Microseconds>  
17.                 (currentOp.elapsedTimeExcludingPauses());  
18.    //记录超过阀值的慢日志到日志文件  
19.    if (shouldLogOpDebug || (shouldSample && debug.executionTimeMicros > logThresholdMs * 1000LL)) {  
20.        ......  
21.    //记录慢日志到日志文件  
22.        log() << debug.report(&c, currentOp, lockerInfo.stats);   
23.    }  
24.    //记录慢日志到system.profile集合   
25.    if (currentOp.shouldDBProfile(shouldSample)) {  
26.        ......  
27.        //记录慢日志到system.profile集合中  
28.        profile(opCtx, op);  
29.    }  
30.    ......  
31.}  

2. 读写操作计数及时延统计

根据请求command命令类型(包含读命令、写命令、command命令)，以及命令执行时间，可以计算出不同类型命令的读写执行时间，从而计算出集群的读时延、写时延、command时延。mongodb所有命令可以归纳为读、写、command三类，核心代码如下：

1.//获取操作类型  
2.Command::ReadWriteType CurOp::getReadWriteType() const {  
3.    ......  
4.    switch (_logicalOp) {  
5.    //getmore find归纳为读  
6.        case LogicalOp::opGetMore:  
7.        case LogicalOp::opQuery:  
8.            return Command::ReadWriteType::kRead;  
9.    //增删改统一归纳为写  
10.        case LogicalOp::opUpdate:  
11.        case LogicalOp::opInsert:  
12.        case LogicalOp::opDelete:  
13.            return Command::ReadWriteType::kWrite;  
14.    //增删改以外的归纳为command  
15.        default:  
16.            return Command::ReadWriteType::kCommand;  
17.    }  
18.}  

从上面的代码可以看出，读、写、command分别对应以下命令：

读(read)：包含getMore、find。

写(write)：包含insert、delete、update。

command：读和写以外的所有命令。

命令执行完计算出命令运行时间后，mongod实例会记录下这个时延，累加到历史统计OperationLatencyHistogram中，读、写、command操作计数及时延统计分别记录到_reads、_writes、_commands三个变量成员中。该统计核心代码实现如下：

1.//Top::_incrementHistogram调用  
2.//操作和时延计数操作  
3.void OperationLatencyHistogram::increment(uint64_t latency, Command::ReadWriteType type) {  
4.    int bucket = _getBucket(latency);  
5.    switch (type) {  
6.        //读时延累加，读计数自增  
7.        case Command::ReadWriteType::kRead:  
8.            _incrementData(latency, bucket, &_reads);  
9.            break;  
10.        //写时延累加，写计数自增    
11.        case Command::ReadWriteType::kWrite:  
12.            _incrementData(latency, bucket, &_writes);  
13.            break;  
14.        //command时延累加，command计数自增    
15.        case Command::ReadWriteType::kCommand:  
16.            _incrementData(latency, bucket, &_commands);  
17.            break;  
18.        default:  
19.            MONGO_UNREACHABLE;  
20.    }  
21.}  

命令请求执行过程及其对应的读写请求操作计数、时延累加衔接代码实现如下：

1.DbResponse ServiceEntryPointMongod::handleRequest(...) {  
2.    ......  
3.    //记录开始时间  
4.    //获取当前操作对应curop  
5.    CurOp& currentOp = *CurOp::get(opCtx);  
6.  
7.    ......  
8.    //执行请求对应命令  
9.    runCommands(opCtx, m);  
10.    ......  
11.  
12.    //记录结束时间  
13.    currentOp.ensureStarted();  
14.    currentOp.done();   
15.    //获取开始和结束时间差，也就是命令执行时间  
16.    debug.executionTimeMicros = durationCount<Microseconds>  
17.                 (currentOp.elapsedTimeExcludingPauses());  
18.    ......  
19.    //记录慢日志到system.profile集合   
20.    //mongod读写的时间延迟统计  db.serverStatus().opLatencies获取   
21.    Top::get(opCtx->getServiceContext())  
22.        .incrementGlobalLatencyStats(   //读写统计
23.            opCtx,  
24.                        //时延             
25.            durationCount<Microseconds>(currentOp.elapsedTimeExcludingPauses()),  
26.            currentOp.getReadWriteType());  //读写类型
27.    ......  
28.}  

mongod实例读、写、command操作计数及其各自时延统计可以通过db.serverStatus()接口获取，用户可用采样来计算对应的tps和平均时延信息。获取操作统计和时延统计的命令如下:

db.serverStatus().opLatencies