MongoDB中如何找出慢查询

calendar Sep 29, 2016 · 3 min read · MongoDB performance-tuning  ·
Share on: linkedin copy

MongoDB是目前最为流行的NoSQL数据库之一。V秘的后台数据就是保存在MongoDB中的哦;)

尽管MongoDB的性能为业界称道，但任何数据库系统使用中都存在着慢查询的问题。慢查询的性能问题，可能是由于使用非最优的查询语句，不正确的索引或其他配置原因导致的。但开发人员或数据库维护人员首先要找出这些低效的查询，才能做出对应的查询优化。

在MongoDB中实现慢查询的profile是非常容易，因为MongoDB内置了profile开关来记录执行时间触发了profile条件的查询。

参照db.setProfileLevel()的文档，通过以下命令就可以记录执行时长超过300ms的查询。

1db.setProfilingLevel(1, 300)

当慢查询被重现后，可以通过查找system.profile collection来查看执行时长超过300ms的查询。

被profiler记录下来慢查询record看起来如下，

 1{       
 2        "op" : "query",
 3        "ns" : "myCollection",
 4        "query" : {     
 5                "builds" : {    
 6                        "$elemMatch" : {
 7                                "builtTime" : null,
 8                                "$and" : [      
 9                                        {               
10                                                "createdTime" : {
11                                                        "$lt" : ISODate("2016-09-20T20:07:00.796Z")
12                                                }
13                                        }
14                                ]
15                        }
16                }
17        },
18        "ntoreturn" : 0,
19        "ntoskip" : 0,
20        "nscanned" : 0,
21        "nscannedObjects" : 18231,
22        "keyUpdates" : 0,
23        "writeConflicts" : 0,
24        "numYield" : 577,
25        "locks" : {     
26                "Global" : {    
27                        "acquireCount" : {
28                                "r" : NumberLong(1156)
29                        }
30                },      
31                "Database" : {  
32                        "acquireCount" : {
33                                "r" : NumberLong(578)
34                        }
35                },      
36                "Collection" : {
37                        "acquireCount" : {
38                                "r" : NumberLong(578)
39                        }
40                }
41        },
42        "nreturned" : 2,
43        "responseLength" : 98076,
44        "millis" : 11161,
45        "execStats" : {
46                "stage" : "COLLSCAN",
47                "filter" : {
48                        "builds" : {
49                                "$elemMatch" : {
50                                        "$and" : [
51                                                {
52                                                        "$and" : [
53                                                                {
54                                                                        "createdTime" : {
55                                                                                "$lt" : ISODate("2016-09-20T20:07:00.796Z")
56                                                                        }
57                                                                }
58                                                        ]
59                                                },
60                                                {
61                                                        "builtTime" : {
62                                                                "$eq" : null
63                                                        }
64                                                }
65                                        ]
66                                }
67                        }
68                },
69                "nReturned" : 2,
70                "executionTimeMillisEstimate" : 11080,
71                "works" : 18233,
72                "advanced" : 2,
73                "needTime" : 18230,
74                "needFetch" : 0,
75                "saveState" : 577,
76                "restoreState" : 577,
77                "isEOF" : 1,
78                "invalidates" : 0,
79                "direction" : "forward",
80                "docsExamined" : 18231
81        },      
82        "ts" : ISODate("2016-09-20T23:07:14.313Z"),
83        "client" : "10.171.127.66",
84        "allUsers" : [
85                {
86                        "user" : "dbuser",
87                        "db" : "mydb"
88                }
89        ],
90        "user" : "dbuser@mydb"
91}

上面的数据具体解读如下，

  1. op: 'query'表示执行的是查询，
  2. ns是指查询的collection，
  3. query是具体的查询语句，
  4. 核心部分是execStats，给出了的查询语句具体执行统计，跟**.explain('execStats')**的内容是一致的。上面的统计是说，这个query执行了整个collection的扫描(总计扫描了18231个文档)，最终返回了2条文档，花费了11080ms，也就是11s还多的时间！这表明被记录下的慢查询跟collection的索引设置有问题，该查询没有用上索引。解决方案很简单，改善查询语句使用存在的索引或者设置合理的索引。
  5. ts是查询开始请求的时间，
  6. allUsers和user都是MongoDB client连接所使用的用户。