10 Key Performance Indicators - Brendan McAdams, 10gen

MongoMunich 2011

That's right: you too can learn to read the omens and ensure that your MongoDB deployment stays in tip-top shape. We'll look at memory usage, file... sizes, flushing, journaling, and all the special incantations that reveal MongoDB's true inner self. By the end of the talk, you'll have ten concrete steps you can take to address performance degradation before it happens. You'll also get a few tips on application design and pointers on remote monitoring.

Transcript

1. 10 MongoDB Performance Indicators Brendan McAdams 10gen, Inc. brendan@10gen.com @rit Monday, October 10, 11
2. MongoDB is new and shiny... Monday, October 10, 11
3. MongoDB is new and shiny... But it doesn’t have to play you for the fool ... Monday, October 10, 11
4. MongoDB is new and shiny... But it doesn’t have to play you for the fool ... Monday, October 10, 11
5. Staying Sane & Stable in Uncharted Territory • Tools • Performance Indicators • Remedies •“Watch me saw a live Oracle DBA in half right here on stage!” •“Take two SSDs and call me in the morning” •“And now for something completely non-relational...” Monday, October 10, 11
6. Tools (a prelude) Monday, October 10, 11
7. • Free tool which comes with MongoDB • Shows I/O counters, time spent in locks, etc MongoStat Monday, October 10, 11
8. db.serverStatus() 1 > db.serverStatus() 2 { 3 "host" : "b-mac", 4 "version" : "1.8.0", 5 "process" : "mongod", 6 "uptime" : 845952, 7 "uptimeEstimate" : 355978, 8 "localTime" : ISODate("2011-04-26T17:04:40.938Z"), 9 "globalLock" : { 10 "totalTime" : 845952742184, 11 "lockTime" : 5154824, 12 "ratio" : 0.0000060935129623101254, 13 "currentQueue" : { 14 "total" : 0, 15 "readers" : 0, 16 "writers" : 0 17 }, 18 "activeClients" : { 19 "total" : 0, 20 "readers" : 0, 21 "writers" : 0 22 } 23 }, // ... and many more pages of useful stats Monday, October 10, 11
9. Database Profiler • Works like MongoDB slow query log; logs queries and their profile information • 3 Modes • ( 0 ) Disabled • ( 1 ) “Slow Queries” (configurable threshhold, default >100ms) • ( 2 ) All Queries Monday, October 10, 11
10. Database Profiler > db.setProfilingLevel(2) { "was" : 0, "slowms" : 100, "ok" : 1 } Monday, October 10, 11
11. Database Profiler > db.system.profile.find().sort({$natural: -1}) { "ts" : ISODate("2011-05-24T14:20:09.711Z"), "info" : "query docs.spreadsheets reslen:257 nscanned:1805535 query: { query: {}, $explain: true } nreturned:1 1407ms", "millis" : 1407 } Monday, October 10, 11
12. Monitoring Monday, October 10, 11
13. Monitoring “Now the reason the enlightened prince and the wise general conquer the enemy whenever they move and their achievements surpass those of ordinary men is foreknowledge.” - Sun Tzu Monday, October 10, 11
14. Monitoring “Now the reason the enlightened prince and the wise general conquer the enemy whenever they move and their achievements surpass those of ordinary men is foreknowledge.” - Sun Tzu Monday, October 10, 11
15. Monitoring “Now the reason the enlightened prince and the wise general conquer the enemy whenever they move and their achievements surpass those of ordinary men is foreknowledge.” - Sun Tzu • Nagios Monday, October 10, 11
16. Monitoring “Now the reason the enlightened prince and the wise general conquer the enemy whenever they move and their achievements surpass those of ordinary men is foreknowledge.” - Sun Tzu • Nagios • Munin Monday, October 10, 11
17. Monitoring “Now the reason the enlightened prince and the wise general conquer the enemy whenever they move and their achievements surpass those of ordinary men is foreknowledge.” - Sun Tzu • Nagios • Munin • 10gen’s MMS Monday, October 10, 11
18. Indicators (signs & portents) Monday, October 10, 11
19. ( # 1 ) Slow Operations • MongoDB logs slow queries to its on-disk logfile... Sun May 22 19:01:47 [conn10] query docs.spreadsheets ntoreturn:100 reslen:510436 nscanned:19976 { username: "Minner, Cori" } nreturned:100 147ms Monday, October 10, 11
20. ( # 2 ) Replication Lag test-rs:PRIMARY> rs.status() { "set" : "test-rs", "date" : ISODate("2011-05-24T14:19:35Z"), "myState" : 1, "members" : [ { "_id" : 0, "name" : "localhost:30000", "stateStr" : "PRIMARY", "optimeDate" : ISODate("2011-05-22T19:19:26Z"), }, { "_id" : 1, "name" : "localhost:30001", "stateStr" : "SECONDARY", "optimeDate" : ISODate("2011-05-18T14:14:29Z"), } } Monday, October 10, 11
21. ( # 3 ) Resident Memory > db.serverStatus().mem { "bits" : 64, // Need 64, not 32 "resident" : 7151, // Physical memory "virtual" : 14248, // Files + heap "mapped" : 6942 // Datafiles } Monday, October 10, 11
22. ( # 3 ) Resident Memory Monday, October 10, 11
23. ( # 3 ) Resident Memory > use docs > db.stats() { "db" : "docs", "collections" : 3, "objects" : 805543, "avgObjSize" : 5107.312096312674, "dataSize" : 4114159508, // ~4GB "storageSize" : 4282908160, // ~4GB "numExtents" : 33, "indexes" : 3, "indexSize" : 126984192, // ~126MB "fileSize" : 8519680000, // ~8.5GB "ok" : 1 } Monday, October 10, 11
24. ( # 3 ) Resident Memory • fileSize includes pre-allocation • storageSize + indexSize = ~5GB Monday, October 10, 11
25. ( # 4 ) Page Faults > db.serverStatus().extra_info { "note" : "fields vary by platform", "heap_usage_bytes" : 210656, "page_faults" : 2381 } Monday, October 10, 11
26. ( # 5 ) Write Lock Time > db.serverStatus().globalLock { "totalTime" : 194616196335, "lockTime" : 53865711, "ratio" : 0.000276779178785711, } Monday, October 10, 11
27. “Did Someone Say Concurrency?” • One writer *or* many readers. • Global Lock • Yields on Long-Running Ops • MongoDB 2.0 improves some of this ... ( # 5 ) Write Lock Time Monday, October 10, 11
28. Δ lockTime / Δ totalTime ( # 5 ) Write Lock Time Monday, October 10, 11
29. Text (mongodb  web  console) ( # 5 ) Write Lock Time Monday, October 10, 11
30. High Lock Percentages frequently are caused by paging. ( # 5 ) Write Lock Time Monday, October 10, 11
31. ( # 6 ) Reader & Writer Queues > db.serverStatus().globalLock "globalLock" : { "totalTime" : 430154769, "lockTime" : 17547681, "ratio" : 0.0407938776101306, "currentQueue" : { "total" : 1, "readers" : 1, "writers" : 0 }, "activeClients" : { "total" : 2, "readers" : 1, "writers" : 1 } } Monday, October 10, 11
32. ( # 6 ) Reader & Writer Queues > db.currentOp() { "inprog" : [ { "opid" : 194285, "active" : true, "lockType" : "read", "waitingForLock" : true, "secs_running" : 0, "op" : "query", "ns" : "docs.spreadsheets", "query" : { "username" : "Auxier, Han" }, "client" : "127.0.0.1:64918", "desc" : "conn" } ] } Monday, October 10, 11
33. ( # 6 ) Reader & Writer Queues •Dozens of ops waiting on locks indicate a problem. • Queued Read Ops? Send Reads to Slaves. • Queued Write Ops? Scale Up, or Scale Out (Vertical - Hardware / Horizontal - Sharding) Monday, October 10, 11
34. ( # 7 ) Background Flushing > db.serverStatus().backgroundFlushing { "flushes" : 5634, "total_ms" : 83556, "average_ms" : 14.830670926517572, "last_ms" : 4, "last_finished" : ISODate("2011-05-24T14:30:00.863Z") } Monday, October 10, 11
35. ( # 7 ) Background Flushing • RAID • SSD • SAN Monday, October 10, 11
36. ( # 8 ) Connections > db.serverStatus().connections { "current" : 2, "available" : 202 } Monday, October 10, 11
37. ( # 9 ) Network > db.serverStatus().network { "bytesIn" : 1132782538, "bytesOut" : 5181752122, "numRequests" : 240323 } Monday, October 10, 11
38. ( # 10 ) Fragmentation        >  db.spreadsheets.stats()        {            "ns"  :  "docs.spreadsheets",            "size"  :  8200046932,  //  8GB            "storageSize"  :  11807223808,  //  11GB            //  Extra  space  for  new  documents.            "paddingFactor"  :  1.4302,            //  Does  index  size  seem  reasonable?            "totalIndexSize"  :  345964544,            "indexSizes"  :  {                "_id_"  :  66772992,                "username_1_filename_1"  :  146079744,                "username_1_updated_at_1"  :  133111808            },            "ok"  :  1        } Monday, October 10, 11
39. ( # 10 ) Fragmentation 2 is the magic number! Monday, October 10, 11
40. ( # 10 ) Fragmentation storageSize / size < 2 Monday, October 10, 11
41. ( # 10 ) Fragmentation Might not be reclaiming free space as quickly as needed. Padding might not be correctly calibrated. Monday, October 10, 11
42. ( # 10 ) Fragmentation Is it greater than 2? You might have the wrong data model. Too many growing embedded documents? See MongoDB Schema Design. Monday, October 10, 11
43. ( # 10 ) Fragmentation 2.0+ Compact Command // In MongoDB 1.9+ db.runCommand({ compact : 'spreadsheets' }); Monday, October 10, 11
44. @mongodb German  Translators  Needed  for  MongoDB  Docs! conferences,  appearances,  and  meetups http://www.10gen.com/events http://bit.ly/mongoZ   Facebook                    |                  Twitter                  |                  LinkedIn http://linkd.in/joinmongo download at mongodb.org mms.10gen.com (Free MongoDB Monitoring by 10gen) We’re Hiring ! brendan@10gen.com (twitter: @rit) Monday, October 10, 11