![77caa1794ef7cc21c700a55dfa6d9273.png](https://i-blog.csdnimg.cn/blog_migrate/b92e0a3bb65da4e092eb53db8466ce13.jpeg)
关于作者
前滴滴出行技术专家,现任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