arthas + mongo慢日志排查接口性能问题

最新推荐文章于 2024-05-02 01:06:04 发布
最新推荐文章于 2024-05-02 01:06:04 发布
阅读量586 收藏 1
点赞数 1
分类专栏： mongo 大数据
版权声明：本文为博主原创文章，遵循 CC 4.0 BY-SA 版权协议，转载请附上原文出处链接和本声明。
本文链接：https://blog.csdn.net/u012772803/article/details/110892589
版权

问题描述

线上生产环境某个接口，调用一次需要2s才能返回数据，严重影响客户端体验

排查过程

1. arthas 定位接口请求耗时

下载安装arthas
启动arthas

执行命令：./as.sh
在这里插入图片描述

选择对应的进程号 对应的序号

在这里插入图片描述

跟踪trace

在arthas命令框中执行命令：trace
按TAB键，控台会将报名给列出来
在这里插入图片描述
选择指定要跟踪的接口入口方法
在这里插入图片描述
一致追踪下去，知道能定位主要耗时在哪里，耗时最高的方法会已红色进行标注
在这里插入图片描述
从图中我们可以看到，这个耗时最高的地方是查询mongo
arthas 详细使用方法：https://arthas.aliyun.com/doc/start-arthas.html

mongo 慢日志定位

登录mongo

注意：不能登录mongos， 而要登录到mongo的某个主分片上

开启慢日志

在mongo命令行中，输入命令db.setProfilingLevel(1, 200)
第一个参数可以取 0，1，2 三个值，他们表示的意义如下：
　　0 – 不开启
　　1 – 记录慢命令 (默认为>100ms)
　　2 – 记录所有命令
第二个参数表示大于该时间的操作记录到慢日志当中（单位ms）

慢查询(system.profile)分析

慢查询(system.profile)分析
在mongo的客户端中通过

 sh3:PRIMARY> db.system.profile.find()

查看当前所有的慢查询日志，下面的例子说明各个参数的含义，更多信息见：http://docs.mongodb.org/manual/reference /database-profiler/

3.1：参数含义 – (这是一个query 类型的 慢查询)
{
	"op" : "query",  #操作类型，有insert、query、update、remove、getmore、command   
	"ns" : "onroad.route_model", #操作的集合
	"query" : {
		"$query" : {
			"user_id" : 314436841,
			"data_time" : {
				"$gte" : 1436198400
			}
		},
		"$orderby" : {
			"data_time" : 1
		}
	},
	"ntoskip" : 0, #指定跳过skip()方法 的文档的数量。
	"nscanned" : 2, #为了执行该操作，MongoDB在 index 中浏览的文档数。 一般来说，如果 nscanned 值高于 nreturned 的值，说明数据库为了找到目标文档扫描了很多文档。这时可以考虑创建索引来提高效率。
	"nscannedObjects" : 1,  #为了执行该操作，MongoDB在 collection中浏览的文档数。
	"keyUpdates" : 0, #索引更新的数量，改变一个索引键带有一个小的性能开销，因为数据库必须删除旧的key，并插入一个新的key到B-树索引
	"numYield" : 1,  #该操作为了使其他操作完成而放弃的次数。通常来说，当他们需要访问还没有完全读入内存中的数据时，操作将放弃。这使得在MongoDB为了放弃操作进行数据读取的同时，还有数据在内存中的其他操作可以完成
	"lockStats" : {  #锁信息，R：全局读锁；W：全局写锁；r：特定数据库的读锁；w：特定数据库的写锁
		"timeLockedMicros" : {  #该操作获取一个级锁花费的时间。对于请求多个锁的操作，比如对 local 数据库锁来更新 oplog ，该值比该操作的总长要长（即 millis ）
			"r" : NumberLong(1089485),
			"w" : NumberLong(0)
		},
		"timeAcquiringMicros" : {  #该操作等待获取一个级锁花费的时间。
			"r" : NumberLong(102),
			"w" : NumberLong(2)
		}
	},
	"nreturned" : 1,  // 返回的文档数量
	"responseLength" : 1669, // 返回字节长度，如果这个数字很大，考虑值返回所需字段
	"millis" : 544, #消耗的时间（毫秒）
	"execStats" : {  #一个文档,其中包含执行 查询 的操作，对于其他操作,这个值是一个空文件， system.profile.execStats 显示了就像树一样的统计结构，每个节点提供了在执行阶段的查询操作情况。
		"type" : "LIMIT", ##使用limit限制返回数  
		"works" : 2,
		"yields" : 1,
		"unyields" : 1,
		"invalidates" : 0,
		"advanced" : 1,
		"needTime" : 0,
		"needFetch" : 0,
		"isEOF" : 1,  #是否为文件结束符
		"children" : [
			{
				"type" : "FETCH",  #根据索引去检索指定document
				"works" : 1,
				"yields" : 1,
				"unyields" : 1,
				"invalidates" : 0,
				"advanced" : 1,
				"needTime" : 0,
				"needFetch" : 0,
				"isEOF" : 0,
				"alreadyHasObj" : 0,
				"forcedFetches" : 0,
				"matchTested" : 0,
				"children" : [
					{
						"type" : "IXSCAN", #扫描索引键
						"works" : 1,
						"yields" : 1,
						"unyields" : 1,
						"invalidates" : 0,
						"advanced" : 1,
						"needTime" : 0,
						"needFetch" : 0,
						"isEOF" : 0,
						"keyPattern" : "{ user_id: 1.0, data_time: -1.0 }",
						"boundsVerbose" : "field #0['user_id']: [314436841, 314436841], field #1['data_time']: [1436198400, inf.0]",
						"isMultiKey" : 0,
						"yieldMovedCursor" : 0,
						"dupsTested" : 0,
						"dupsDropped" : 0,
						"seenInvalidated" : 0,
						"matchTested" : 0,
						"keysExamined" : 2,
						"children" : [ ]
					}
				]
			}
		]
	},
	"ts" : ISODate("2015-10-15T07:41:03.061Z"), #该命令在何时执行
	"client" : "10.10.86.171", #链接ip或则主机
	"allUsers" : [
		{
			"user" : "martin_v8",
			"db" : "onroad"
		}
	],
	"user" : "martin_v8@onroad"
}
问题分析

如果发现 millis 值比较大，那么就需要作优化。

1 如果nscanned数很大，或者接近记录总数（文档数），那么可能没有用到索引查询，而是全表扫描。
2 如果 nscanned 值高于 nreturned 的值，说明数据库为了找到目标文档扫描了很多文档。这时可以考虑创建索引来提高效率。

3.3 system.profile补充
‘type’的返回参数说明：

COLLSCAN  #全表扫描
IXSCAN  #索引扫描
FETCH  #根据索引去检索指定document
SHARD_MERGE  #将各个分片返回数据进行merge
SORT  #表明在内存中进行了排序（与老版本的scanAndOrder:true一致）
LIMIT  #使用limit限制返回数
SKIP  #使用skip进行跳过
IDHACK  #针对_id进行查询
SHARDING_FILTER  #通过mongos对分片数据进行查询
COUNT  #利用db.coll.explain().count()之类进行count运算
COUNTSCAN  #count不使用Index进行count时的stage返回
COUNT_SCAN  #count使用了Index进行count时的stage返回
SUBPLA  #未使用到索引的$or查询的stage返回
TEXT  #使用全文索引进行查询时候的stage返回
PROJECTION  #限定返回字段时候stage的返回

对于普通查询，我们最希望看到的组合有这些：

Fetch+IDHACK
Fetch+ixscan
Limit+（Fetch+ixscan）
PROJECTION+ixscan
SHARDING_FILTER+ixscan

不希望看到包含如下的type：

COLLSCAN（全表扫），
SORT（使用 sort 但是无index），
不合理的SKIP，SUBPLA（未用到index的$or）

对于count查询，希望看到的有：

COUNT_SCAN

不希望看到的有:

COUNTSCAN
性能（explain）分析
sh3:PRIMARY> db.route_model.find({ "user_id" : 313830621, "data_time" : { "$lte" : 1443715200, "$gte" : 1443542400 } }).explain()
{
	"cursor" : "BtreeCursor user_id_1_data_time_-1",  #返回游标类型，有BasicCursor和BtreeCursor，后者意味着使用了索引。
	"isMultiKey" : false,
	"n" : 23, #返回的文档行数。
	"nscannedObjects" : 23,  #这是MongoDB按照索引指针去磁盘上查找实际文档的次数。如果查询包含的查询条件不是索引的一部分，或者说要求返回不在索引内的字段，MongoDB就必须依次查找每个索引条目指向的文档。
	"nscanned" : 23,  #如果有使用索引，那么这个数字就是查找过的索引条目数量，如果本次查询是一次全表扫描，那么这个数字就代表检查过的文档数目
	"nscannedObjectsAllPlans" : 46,
	"nscannedAllPlans" : 46,
	"scanAndOrder" : false,  #MongoDB是否在内存中对结果集进行了排序
	"indexOnly" : false, #MongoDB是否只使用索引就能完成此次查询
	"nYields" : 1,  #为了让写入请求能够顺利执行，本次查询暂停暂停的次数。如果有写入请求需求处理，查询会周期性的释放他们的锁，以便写入能够顺利执行
	"nChunkSkips" : 0,
	"millis" : 1530,  #数据库执行本次查询所耗费的毫秒数。这个数字越小，说明效率越高
	"indexBounds" : {  #这个字段描述了索引的使用情况，给出了索引的遍历范围
		"user_id" : [
			[
				313830621,
				313830621
			]
		],
		"data_time" : [
			[
				1443715200,
				1443542400
			]
		]
	},
	"server" : "a7cecd4f9295:27017",
	"filterSet" : false,
	"stats" : {
		"type" : "FETCH",
		"works" : 25,
		"yields" : 1,
		"unyields" : 1,
		"invalidates" : 0,
		"advanced" : 23,
		"needTime" : 0,
		"needFetch" : 0,
		"isEOF" : 1,
		"alreadyHasObj" : 0,
		"forcedFetches" : 0,
		"matchTested" : 0,
		"children" : [
			{
				"type" : "IXSCAN",#这里使用了索引
				"works" : 23,
				"yields" : 1,
				"unyields" : 1,
				"invalidates" : 0,
				"advanced" : 23,
				"needTime" : 0,
				"needFetch" : 0,
				"isEOF" : 1,
				"keyPattern" : "{ user_id: 1.0, data_time: -1.0 }",
				"boundsVerbose" : "field #0['user_id']: [313830621.0, 313830621.0], field #1['data_time']: [1443715200.0, 1443542400.0]",
				"isMultiKey" : 0,
				"yieldMovedCursor" : 0,
				"dupsTested" : 0,
				"dupsDropped" : 0,
				"seenInvalidated" : 0,
				"matchTested" : 0,
				"keysExamined" : 23,
				"children" : [ ]
			}
		]
	}
}

详细解释 : https://docs.mongodb.org/manual/reference/database-profiler/

日常使用的慢日志（system.profile）查询

返回最近的10条记录

db.system.profile. find ().limit(10). sort ({ ts : -1 }).pretty()

#返回所有的操作，除command类型的


db.system.profile. find ( {  op : { $ ne  : 'command'}}).pretty()
## command = "query"/ "insert"/ "delete"

#返回特定集合


db.system.profile. find ( { ns : 'mydb. test' } ).pretty()

#返回大于500毫秒慢的操作


db.system.profile. find ({ millis : { $gt : 500 } } ).pretty()

#从一个特定的时间范围内返回信息

    
db.system.profile. find (
 {
    ts : {
          $gt : new ISODate( "2015-10-18T03:00:00Z" ),
          $lt : new ISODate( "2015-10-19T03:40:00Z" )
         }
   }
  ).pretty()

#查看最新的 Profile 记录：

db.system.profile. find (). sort ({$natural:-1}).limit(1)

显示5个最近的事件

show profile
浙里起杭
关注
  • 1
    点赞
  • 踩
  • 1
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
专栏目录
资料-线上问题排查利器-Alibaba Arthas.zip
06-11
博客地址： https://blog.csdn.net/lydms/article/details/125238249 Xmind整理： https://download.csdn.net/download/weixin_44624117/8561266 相关资料： ...
lambda 表达式导致 Arthas 无法 redefine 的问题
10-15
3. **利用Arthas的其他功能**：尽管`redefine`命令遇到Lambda表达式可能存在问题，但Arthas还有其他命令如`execute`、`watch`等可以用来观察和修改运行时的行为，不一定非要依赖`redefine`。 4. **使用其他诊断工具...
记录一次MongoDB查询优化
yannankai0709的博客
09-12 443
因为本接口主要负责以统计为主，对于复合查询的场景并不多，因此，在复合索引的优化、排序等等方面不够完善，想要学习的朋友可以查询：https://developer.aliyun.com/article/74635，对于复合索引的优先级有详细的解释。多多查阅官方文档，会有很多意外收获。
mongodb慢查询了怎么办
weixin_35756892的博客
01-03 2236
如果你的 MongoDB 数据库中出现了慢查询，你可以尝试以下几种方法来解决问题： 找出导致慢查询的原因： 使用 MongoDB 的 explain() 方法来分析查询的执行计划，找出导致慢查询的原因。 启用 MongoDB 的慢查询日志功能，记录慢查询的详细信息，并分析日志中出现的问题。 优化查询： 尽量使用索引来优化查询，避免使用全表扫描。 尽量减少查询中的返回字段数量，只...
Nginx查找耗时的接口
最新发布
高性价比服务器就选：蓝易云
05-02 139
例如我们可以创建一个以$request_time为Y轴、以$request_uri为X轴的柱状图，这样就可以一目了然地看出哪些接口的平均响应时间较长。在日常的开发和运维工作中，我们经常需要对服务器的性能进行监控和优化，其中一个重要的环节就是找出那些耗时较长、可能成为性能瓶颈的接口。总结一下，查找Nginx中耗时接口主要有两步：首先是配置Nginx记录请求处理时间，然后是分析这些记录找出耗时较长的请求。这个命令会打印出请求URL和对应的处理时间，并按照处理时间降序排序，最后取前10条记录。
Arthas 定位接口慢，从9s优化到1s左右
yiwenti9793的博客
12-01 1754
arthas定位接口RT高问题，进行优化
关于MongoDB使用的优化总结
B_e_a_u_tiful1205的博客
11-03 1379
在画像平台人群圈选模块中，人群包的计算和存储是在CilckHouse引擎中完成的。但是基于CilckHouse在并发查询、集群压力方面的考虑，在数据输出模块中，并不是直接从CilckHouse中查询获取数据，而是在人群包数据计算完成后，通过数据同步模块将数据从CilckHouse同步到MongoDB中。MongoDB作为数据输出模块的底层数据存储和查询引擎，需要满足高效的数据写入和读取性能。同时人群包并不必保存全部的历史数据，mongoDB中只需保留最近N个版本的人群包数据即可，所以为了删除无效数据，还需要
db.setProfilingLevel()---用于采集与分析慢操作的数据库请求
let懒的博客
12-30 1865
db.setProfilingLevel() mongodb的profiler设置，默认该设置是关闭的，profiler可用于采集与分析慢操作的数据库请求。 db.setProfilingLevel(<level>, <options>); Parameters 参数：level Type： integer Description：配置数据库profiler级别 level Description 0 profiler已关闭，并且不收集任何数据。这是默认的profi
Java诊断利器Arthas排查问题实践.pptx
10-13
Java 诊断利器 Arthas 排查问题实践 Arthas 是 Alibaba 开源的 Java 诊断工具，于 2018 年 9 月开源，目前在 Github 上获得了 11,000 多个星标。 Arthas 的主要功能特性包括查看类加载情况、反编译类、热更新类、...
arthas-bin.zip 性能检测工具
07-04
总之，Arthas是一款强大的Java诊断工具，通过其丰富的命令集和便捷的启动脚本，使得开发者能够高效地对Java应用程序进行性能监控和问题排查，从而提升开发效率和产品质量。对于任何处理复杂Java应用的开发者来说，...
Arthas-boot.zip
06-23
Arthas-boot.zip是一个包含Arthas-boot相关jar包的压缩文件，主要用于Java应用程序的问题排查。Arthas，全称为 Alibaba Arthas，是阿里巴巴开源的一款强大的Java诊断工具，它可以帮助开发者在不重启服务的情况下进行...
MongoDB查询优化和执行计划
互联网知识分享
08-23 654
通过选择合适的索引、使用投影、分页、排序等方式来优化查询，通过执行计划来了解查询的执行过程和优化效果。在实际应用中，根据具体的查询需求和数据特点，选择合适的优化策略和索引类型，可以显著提高查询性能。执行计划是指查询的执行过程和查询优化器如何选择执行计划的一种解释。通过以上示例，我们可以根据执行计划中的信息进行查询优化，如添加索引、修改查询条件等来提高查询性能。执行计划中包含了索引的使用情况、扫描的文档数、扫描的索引数等信息。提供了一种查询优化和执行计划的机制，可以帮助我们优化查询性能并理解查询的执行过程。
MongoDB 数据库性能优化技巧
xiaocxyczh的博客
09-01 1936
最后，合理设置操作系统和MongoDB的一些参数，如打开的文件限制、网络接口配置、日志设置等。索引是MongoDB查询性能优化的关键。使用explain()方法可以查看查询执行计划，帮助我们了解索引的使用情况和性能瓶颈。综上所述，通过合理使用索引、优化查询、良好的数据模型设计和合适的硬件配置，我们可以提高MongoDB数据库的性能。根据具体场景，适时地调整相关编码和配置，可以进一步优化数据库的性能和可扩展性。本文将介绍一些MongoDB性能优化的关键点，包括索引的使用、查询优化、数据模型设计和硬件优化等。
【arthas】使用arthas定位接口耗时问题、无日志情况下排查问题
wht_0217的博客
06-29 4432
Arthas使用
【Mongodb】 MongoDB 查询优化原则
wjianwei666的专栏
08-14 462
MongoDB 查询优化原则
MongoDB数据库优化：Mongo Database Profiler
baiyunl的专栏
07-07 386
在MySQL中，慢查询日志是经常作为我 们优化数据库的依据，那在MongoDB中是否有类似的功能呢?答案是肯定的，那就是Mongo Database Profiler.不仅有，而且还有一些比MySQL的Slow Query Log更详细的信息。它就是我们这篇文章的主题。 　　开启 Profiling 功能 　　有两种方式可以控制 Profiling 的开关和级别，第一种是直接在启动参...
硬卷 NoSQL 数据库系列（十四）：MongoDB 查询聚合性能优化
民工哥的博客
05-19 725
点关注公众号，回复“1024”获取2TB学习资源！前面介绍了复制集、分片技术、集群部署与管理维护、备份与恢复、状态检测与性能追踪、客户端工具、日志分析工具等相关的知识点。今天我将详细的为大家介绍 MongoDB 查询聚合优化的相关知识，希望大家能够从中收获多多！如有帮助，请点在看、转发支持一波！！！在MongoDB中通过查询聚合语句分析定位慢查询/聚合分析。更多关于 MongoDB 数据库的学习文...
mongo大数据处理优化
乾复道
08-04 5147
大数据查询缓慢的优化方案
mongodb4.2.8 认证集群分片模式开启慢查询
h952520296的博客
08-23 1227
mongdb官方文档有点语焉不详 网上的流程没有关于开启了认证或者分片模式的 特记录如下 mongodb默认情况下是不开启慢查询的 需要开启慢查询的话可以在启动命令后面添加参数 --profile 1 --slowms 3000 完整的命令就像这样 mongod -f /data/mongodb-4.2.8/conf/shard3.conf --profile 1 --slowms 3000 --profile 1 1的意思是开启慢查询分析器 同样的还有0 和2 两个参数 0是关闭 2...
java虚拟机报oom，如何使用arthas排查问题所在
05-25
当 虚拟机抛出 OutOfMemoryError（OOM）异常时，一种可能的原因是应用程序中存在内存泄漏或者内存使用过量的问题。要定位这个问题，可以使用阿里巴巴开源的 Java 诊断工具 Arthas。 下面是使用 Arthas 排查内存泄漏问题的一般步骤： 1. 在出现 OOM 异常时，使用 jps 命令查看应用程序的进程 ID。 ``` jps ``` 2. 使用 arthas-boot 命令启动 Arthas。 ``` java -jar arthas-boot.jar ``` 3. 在 Arthas 控制台中，使用 attach 命令连接到应用程序进程。 ``` attach <pid> ``` 4. 使用 dashboard 命令查看 JVM 的运行状况，包括堆内存、非堆内存和线程数等信息。 ``` dashboard ``` 5. 使用 heapdump 命令导出堆内存快照，保存为 hprof 文件。 ``` heapdump /tmp/dump.hprof ``` 6. 使用 jhat 命令打开 hprof 文件，查看对象占用内存的情况。例如，可以查看对象的数量、大小和引用关系等信息。 ``` jhat /tmp/dump.hprof ``` 7. 根据内存快照和 jhat 工具的分析结果，查找可能存在内存泄漏或者内存占用过多的代码。例如，可以查看对象的引用路径，找到可能的引用泄漏点。 ``` jhat http://localhost:7000/ ``` 8. 根据分析结果，进行代码优化或者修复内存泄漏问题。 注意：在使用 Arthas 进行诊断时，需要谨慎操作，避免对系统造成不必要的影响。同时，也需要注意保护敏感信息，避免泄露重要数据。

“相关推荐”对你有帮助么？

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

个

红包个数最小为10个

元

红包金额最低5元

当前余额3.43元 前往充值 >
需支付：10.00元
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付元
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明：

1.余额是钱包充值的虚拟货币，按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载，可以购买VIP、付费专栏及课程。

余额充值