zoukankan      html  css  js  c++  java
  • Ubuntu系统查看mongo得慢日志,及一些操作

    摘要

      在MySQL中,慢查询日志是经常作为我们优化查询的依据,那在MongoDB中是否有类似的功能呢?答案是肯定的,那就是开启Profiling功能。该工具在运行的实例上收集有关MongoDB的写操作,游标,数据库命令等,可以在数据库级别开启该工具,也可以在实例级别开启。该工具会把收集到的所有都写入到system.profile集合中,该集合是一个capped collection。更多的信息见:http://docs.mongodb.org/manual/tutorial/manage-the-database-profiler/

      1  慢查询分析流程

     

       慢查询日志一般作为优化步骤里的第一步。通过慢查询日志,定位每一条语句的查询时间。比如超过了200ms,那么查询超过200ms的语句需要优化。然后它通过 .explain() 解析影响行数是不是过大,所以导致查询语句超过200ms

       所以优化步骤一般就是:

        1.用慢查询日志(system.profile)找到超过200ms的语句

        2.然后再通过.explain()解析影响行数,分析为什么超过200ms 

        3.决定是不是需要添加索引

      2  开启慢查询

    2.1  Profiling级别说明

    1
    2
    3
    0:关闭,不收集任何数据。
    1:收集慢查询数据,默认是100毫秒。
    2:收集所有数据

    2.2  开启Profiling和设置

    1:通过mongo shell:

       需要进入server 

       mongo 而不是路由器mongoos

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    #查看状态:级别和时间
    PRIMARY> db.getProfilingStatus()
    "was" : 1, "slowms" : 200 }
    #查看级别
    PRIMARY> db.getProfilingLevel()
    1
    #设置级别
    PRIMARY> db.setProfilingLevel(2)
    "was" : 1, "slowms" : 100, "ok" : 1 }
    #设置级别和时间
    PRIMARY> db.setProfilingLevel(1,200)
    "was" : 2, "slowms" : 100, "ok" : 1 }

    注意:

      1  以上要操作要是在test集合下面的话,只对该集合里的操作有效,要是需要对整个实例有效,则需要在所有的集合下设置或则在开启的时候开启参数

      2 每次设置之后返回给你的结果是修改之前的状态(包括级别、时间参数)。


    2:不通过mongo shell:

    在mongoDB启动的时候

    1
    mongod --profile=1  --slowms=200

    或则在配置文件里添加2行:

    1
    2
    profile = 1
    slowms = 200

    3:关闭Profiling

    1
    2
    3
    # 关闭
    PRIMARY> db.setProfilingLevel(0)
    "was" : 1, "slowms" : 200, "ok" : 1 }

    4:修改“慢查询日志”的大小

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    #关闭Profiling
    PRIMARY> db.setProfilingLevel(0)
    "was" : 0, "slowms" : 200, "ok" : 1 }
    #删除system.profile集合
    PRIMARY> db.system.profile.drop()
    true
    #创建一个新的system.profile集合 --- 4M
    PRIMARY> db.createCollection( "system.profile", { capped: true, size:4000000 } )
    "ok" : 1 }
    #重新开启Profiling
    PRIMARY> db.setProfilingLevel(1)
    "was" : 0, "slowms" : 200, "ok" : 1 }

    注意:要改变Secondary的system.profile的大小,你必须停止Secondary,运行它作为一个独立的mongodb,然后再执行上述步骤。完成后,重新启动加入副本集。


      2.3  Profile 效率

      Profiling功能肯定是会影响效率的,但是不太严重,原因是他使用的是system.profile 来记录,而system.profile 是一个capped collection, 这种collection 在操作上有一些限制和特点,但是效率更高。

    3   慢查询(system.profile)分析

    通过 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"
    }


     

     3.2: 分析

    millis  1  如果nscanned数很大,或者接近记录总数(文档数),那么可能没有用到索引查询,而是全表扫描。

    2  如果 nscanned 值高于 nreturned 的值,说明数据库为了找到目标文档扫描了很多文档。这时可以考虑创建索引来提高效率。

     3.3  system.profile补充

    ‘type’的返回参数说明:

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    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的返回

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

    1
    2
    3
    4
    5
    6
    Fetch+IDHACK
    Fetch+ixscan
    Limit+(Fetch+ixscan)
    PROJECTION+ixscan
    SHARDING_FILTER+ixscan

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

    1
    COLLSCAN(全表扫),SORT(使用sort但是无index),不合理的SKIP,SUBPLA(未用到index的$or)

    对于count查询,希望看到的有:

    1
    COUNT_SCAN

    不希望看到的有:

    1
    COUNTSCAN

     

    4  性能(explain)分析

     

    SECONDARY> 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 

    5  日常使用的慢日志(system.profile)查询

     

    #返回最近的10条记录

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

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

    1
    db.system.profile.find( { op: { $ne : ‘command‘ } }).pretty()

    #返回特定集合

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

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

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

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

    1
    2
    3
    4
    5
    6
    7
    8
    db.system.profile.find(
                          {
                           ts : {
                                 $gt : new ISODate("2015-10-18T03:00:00Z"),
                                 $lt : new ISODate("2015-10-19T03:40:00Z")
                                }
                          }
                         ).pretty()

    #特定时间,限制用户,按照消耗时间排序

    1
    2
    3
    4
    5
    6
    7
    8
    9
    db.system.profile.find(
                          {
                            ts : {
                                  $gt : newISODate("2015-10-12T03:00:00Z") ,
                                  $lt : newISODate("2015-10-12T03:40:00Z")
                                 }
                          },
                          { user : 0 }
                         ).sort( { millis : -1 } )

    #查看最新的 Profile  记录: 

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

    # 显示5个最近的事件

    1
    show profile

    6  对慢查询语句建索引

  • 相关阅读:
    matplotlib学习之(四)设置线条颜色、形状
    Python 安装matplotlib,six,dateutil,pyparsing 完整过程
    Python中的Numpy、SciPy、MatPlotLib安装与配置
    pip --upgrade批量更新过期的python库
    Python模块常用的几种安装方式
    python文件目录操作
    Python调用(运行)外部程序
    使用CreateProcess函数运行其他程序
    Python中四种运行其他程序的方式
    Python对Excel操作详解
  • 原文地址:https://www.cnblogs.com/xingyunfashi/p/8718911.html
Copyright © 2011-2022 走看看