第1页
@MongoDB @asya999 #askAsya
Diagnostics and Debugging
Asya Kamsky
Principal Solutions Architect, MongoDB
第2页
#MongoDB @asya999 #askAsya
Diagnostics and Debugging
Asya Kamsky
Principal Solutions Architect, MongoDB
第7页
Understanding Crime Scene
第8页
Understanding Crime Scene
第10页
“Data! Data! Data!
I can't make bricks without clay.”
-- Sherlock Holmes,
The Adventure of the Copper Beeches
第11页
Gathering Data
第12页
“It is a capital mistake to
theorize before one has data.
Insensibly one begins to twist
facts to suit theories, instead
of theories to suit facts.”
-- Sherlock Holmes, A Scandal in Bohemia
第14页
“There is nothing like first-hand evidence.”
-- Sherlock Holmes, A Study in Scarlet
第15页
Available Tools: OS
% iostat % free % blockdev --report % dmesg % ulimit -a % ifconfig, ip <...>, iptables % top, ...
第16页
Available Tools:
第17页
Available Tools: OS for MongoDB
% mongostat % mongotop
第18页
Available Tools: MongoDB shell
% mongostat % mongotop > db.currentOp( ), db.serverStatus( ) > rs.status( ) > sh.status( )
第19页
Available Tools:
% mongostat % mongotop > db.currentOp( ), db.serverStatus( ) > rs.status( ) > sh.status( )
MongoDB Management Service (MMS) Monitoring
第20页
Available Tools:
第21页
Available Tools:
第22页
Available Tools:
MongoDB Management Service (MMS) Monitoring
第23页
Available Tools:
第24页
mongod logs
第25页
mongod logs
Tue Jul 30 19:15:27.898 [conn2] query test.docs query: { query: { _id: { $gt: ObjectId('51da44a8a4435e3d7174b696') } }, orderby: { ts: 1.0 } } ntoreturn:10 ntoskip:0 nscanned:9235093 scanAndOrder:1 keyUpdates:0 numYields:5 locks(micros) r:6919962 nreturned:1 reslen:360 3578ms
第26页
mongod logs
第27页
mongod logs
第28页
"It is of the highest importance ... to be able to recognize, out of a number of facts, which are incidental and which vital. "
Sherlock Holmes, The Reigate Puzzle
第31页
https://github.com/rueckstiess/mtools
by Thomas Rückstieß
第32页
mtools
• mloginfo • mlogfilter • mplotqueries • mlogvis • mlaunch
第33页
mtools
• mloginfo • mlogfilter • mplotqueries
第34页
mloginfo
source: logs/mongodb.log.2014-05-04T15-52-59 start: 2014 May 02 00:29:21 end: 2014 May 04 15:52:59
date format: iso8601-local length: 17091234 binary: mongod
version: 2.6.0
------------------------------------------
source: logs/mongodb.log.2014-05-04T15-53-06 start: 2014 May 02 00:29:25 end: 2014 May 04 15:53:06
date format: iso8601-local length: 13696471 binary: mongod
version: 2.6.0
第35页
mplotqueries
$ mplotqueries --help usage: mplotqueries [OPTIONS] [logfile [logfile ...]]
A script to plot various information from logfiles. ...
第36页
mplotqueries
$ mplotqueries --help usage: mplotqueries [OPTIONS] [logfile [logfile ...]]
A script to plot various information from logfiles. ... optional arguments:
--type {nscanned/n,rsstate,connchurn,durline,histogram,range,scatter,event} type of plot (default=scatter with --yaxis duration)
第37页
mplotqueries
$ mplotqueries --help usage: mplotqueries [OPTIONS] [logfile [logfile ...]]
A script to plot various information from logfiles. ... optional arguments:
--type {nscanned/n,rsstate,connchurn,durline,histogram,range,scatter,event} type of plot (default=scatter with --yaxis duration)
第38页
mplotqueries
$ mplotqueries --help usage: mplotqueries [OPTIONS] [logfile [logfile ...]]
A script to plot various information from logfiles. ... optional arguments:
--type {nscanned/n,rsstate,connchurn,durline,histogram,range,scatter,event} type of plot (default=scatter with --yaxis duration)
第39页
mplotqueries
$ mplotqueries --help usage: mplotqueries [OPTIONS] [logfile [logfile ...]]
A script to plot various information from logfiles. ... optional arguments:
--type {nscanned/n,rsstate,connchurn,durline,histogram,range,scatter,event} type of plot (default=scatter with --yaxis duration)
第40页
mplotqueries
$ mplotqueries --help usage: mplotqueries [OPTIONS] [logfile [logfile ...]]
A script to plot various information from logfiles. ... optional arguments:
--type {nscanned/n,rsstate,connchurn,durline,histogram,range,scatter,event} type of plot (default=scatter with --yaxis duration)
第41页
mplotqueries
$ mplotqueries --help usage: mplotqueries [OPTIONS] [logfile [logfile ...]]
A script to plot various information from logfiles. ... optional arguments:
--type {nscanned/n,rsstate,connchurn,durline,histogram,range,scatter,event} type of plot (default=scatter with --yaxis duration)
第42页
mplotqueries
$ mplotqueries --help usage: mplotqueries [OPTIONS] [logfile [logfile ...]]
A script to plot various information from logfiles. ... optional arguments:
--type {nscanned/n,rsstate,connchurn,durline,histogram,range,scatter,event} type of plot (default=scatter with --yaxis duration)
第43页
mplotqueries
$ mplotqueries --help usage: mplotqueries [OPTIONS] [logfile [logfile ...]]
A script to plot various information from logfiles. ...
optional arguments:
--type {nscanned/n,rsstate,connchurn,durline,histogram,range,scatter,event} type of plot (default=scatter with --yaxis duration)
--group GROUP
specify value to group on. All basic plot types can group on 'namespace', 'operation', 'thread', 'pattern' ...
第45页
"... what is out of the common is usually a guide rather than a hindrance."
— Sherlock Holmes, A Study in Scarlet
第46页
The Adventure of the Missing Three-Quarter (Indexes)
第47页
mloginfo
$ mloginfo firstmongo.log source: firstmongo.log start: 2014 Jun 10 11:19:54 end: 2014 Jun 17 17:14:15
date format: iso8601-local length: 14170668 binary: mongod
version: 2.6.1
mloginfo firstmongo.log --queries
第48页
mloginfo
$ mloginfo firstmongo.log source: firstmongo.log
start: 2014 Jun 10 11:19:54
end: 2014 Jun 17 17:14:15
date format: iso8601-local
length: 14170668 binary: mongod
version: 2.6.1
mloginfo firstmongo.log –-queries
namespace
pattern
count
db1.request {"requestSender": 1}
db1.request {"curRoute": 1,"isAdv": 1 } 169
db1.report {"deliveryTime": 1}
db2.report {"deliveryTime": 1}
db3.report {"deliveryTime": 1}
db1.pending {"sentTime": 1, "status": 1} 9
max (ms)
350161 9585
111421 85267 72071
mean (ms)
93828 3942
71536 60363 53062
95%-ile (ms)
339441.2 6324.2
106609.4 81508.15
70781.3
88470.4
sum (ms)
2721018 666302
643829 603634 530624
第49页
mplotqueries
% mplotqueries firstmongo.log --type nscanned/n
第50页
mplotqueries
% mplotqueries firstmongo.log --type nscanned/n
第51页
mplotqueries
% mplotqueries firstmongo.log --type nscanned/n 2014-06-17T17:13:34.235 [conn1569841] query db1.coll query: { time: { $lt: "2014-06-17 17:13:31", $gte: "2014-06-17 17:04:31" } } planSummary: COLLSCAN ntoreturn:0 ntoskip:0 nscanned:5169727 nscannedObjects: 5169727 keyUpdates:0 numYields:12492 locks(micros) r:37736571 nreturned:72 reslen:32707 30129ms
第52页
mplotqueries
% mplotqueries firstmongo.log --type nscanned/n 2014-06-17T17:13:34.235 [conn1569841] query db1.coll query: { time: { $lt: "2014-06-17 17:13:31", $gte: "2014-06-17 17:04:31" } } planSummary: COLLSCAN ntoreturn:0 ntoskip:0 nscanned:5169727 nscannedObjects: 5169727 keyUpdates:0 numYields:12492 locks(micros) r:37736571 nreturned:72 reslen:32707 30129ms
第53页
mplotqueries
% mplotqueries firstmongo.log --type nscanned/n 2014-06-17T17:13:34.235 [conn1569841] query db1.coll query: { time: { $lt: "2014-06-17 17:13:31", $gte: "2014-06-17 17:04:31" } } planSummary: COLLSCAN ntoreturn:0 ntoskip:0 nscanned:5169727 nscannedObjects: 5169727 keyUpdates:0 numYields:12492 locks(micros) r:37736571 nreturned:72 reslen:32707 30129ms
第54页
mplotqueries
% mplotqueries firstmongo.log --type nscanned/n 2014-06-17T17:13:34.235 [conn1569841] query db1.coll query: { time: { $lt: "2014-06-17 17:13:31", $gte: "2014-06-17 17:04:31" } } planSummary: COLLSCAN ntoreturn:0 ntoskip:0 nscanned:5169727 nscannedObjects: 5169727 keyUpdates:0 numYields:12492 locks(micros) r:37736571 nreturned:72 reslen:32707 30129ms 2014-06-17T17:13:47.607 [conn1569990] query db2.coll query: { time: { $lt: "2014-06-17 17:14:05", $gte: "2014-06-17 17:05:05" }, status: 8 } planSummary: COLLSCAN ntoreturn:0 ntoskip:0 nscanned:2057564 nscannedObjects:2057564 keyUpdates:0 numYields:5008 locks(micros) r:11557172 nreturned:56 reslen:18745 13086ms
第55页
mplotqueries
% mplotqueries firstmongo.log --type nscanned/n 2014-06-17T17:13:34.235 [conn1569841] query db1.coll query: { time: { $lt: "2014-06-17 17:13:31", $gte: "2014-06-17 17:04:31" } } planSummary: COLLSCAN ntoreturn:0 ntoskip:0 nscanned:5169727 nscannedObjects: 5169727 keyUpdates:0 numYields:12492 locks(micros) r:37736571 nreturned:72 reslen:32707 30129ms 2014-06-17T17:13:47.607 [conn1569990] query db2.coll query: { time: { $lt: "2014-06-17 17:14:05", $gte: "2014-06-17 17:05:05" }, status: 8 } planSummary: COLLSCAN ntoreturn:0 ntoskip:0 nscanned:2057564 nscannedObjects:2057564 keyUpdates:0 numYields:5008 locks(micros) r:11557172 nreturned:56 reslen:18745 13086ms
第56页
mplotqueries
% mplotqueries firstmongo.log --type nscanned/n 2014-06-17T17:13:34.235 [conn1569841] query db1.coll query: { time: { $lt: "2014-06-17 17:13:31", $gte: "2014-06-17 17:04:31" } } planSummary: COLLSCAN ntoreturn:0 ntoskip:0 nscanned:5169727 nscannedObjects: 5169727 keyUpdates:0 numYields:12492 locks(micros) r:37736571 nreturned:72 reslen:32707 30129ms 2014-06-17T17:13:47.607 [conn1569990] query db2.coll query: { time: { $lt: "2014-06-17 17:14:05", $gte: "2014-06-17 17:05:05" }, status: 8 } planSummary: COLLSCAN ntoreturn:0 ntoskip:0 nscanned:2057564 nscannedObjects:2057564 keyUpdates:0 numYields:5008 locks(micros) r:11557172 nreturned:56 reslen:18745 13086ms
第57页
The Sign of Four (Shards)
第58页
% mplotqueries updates?.log
第59页
% mplotqueries updates?.log
第60页
% mplotqueries updates?.log
第61页
% mplotqueries updates?.log
第62页
% mplotqueries updates?.log
第63页
"Eliminate all other factors, and the
one which remains must be the truth."
Sherlock Holmes -The Sign of Four
第64页
The Case of Identity
第68页
% mplotqueries –type histogram –group namespace –bucketSize 3600
第75页
The Stockbroker's Clerk's Query
第77页
% mplotqueries –type connchurn
第90页
"We balance probabilities and choose the most likely. It is the scientific use of the imagination."
Sherlock Holmes, The Hound of the Baskervilles
With profound thanks to:
Sir Arthur Conan Doyle (1859-1930)
第91页
#MongoDB @asya999 #askAsya
Thank You
Asya Kamsky
MongoDB, Inc.
http://askasya.com/ http://www.kamsky.org/