M312: Diagnostics and Debugging chapter 3 Slow Queries Learning Records
Running environment
Operating System: windows 10 Home Chinese Edition
Mongodb : Mongodb 3.4
Mongodb installation path: E:> MongoDB Server 3.4 bin\
Mongodb storage path: E:> MongoDB data
After-school questions
lab Building an Index in the Foreground in Production
Download Handouts:
m312/building_index_in_foreground.py
m312/set_up_building_index_in_foreground.sh
In this lab, you're going to simulate a foreground index build, in production.
Setup:
- Download the handouts, and unpack. Place the following in your vagrant VM's shared directory:
- set_up_building_index_in_foreground.sh
- building_index_in_foreground.py
- Download and unpack the employees.zip dataset and place it in your vagrant's /shared directory.
- Run set_up_building_index_in_foreground.sh from the /shared directory within your VM, which will do each of the following:
- Kill any mongod server processes running in the VM
- Delete the ~/data directory
- Start a replica set listening on ports 30000, 30001, and 30002.
- Ensure that the server on port 30000 has the highest priority
- Sleep for 20 seconds to ensure that a Primary has been elected
- mongoimport the employees.json file into the m312.employees namespace.
- Next, you'll want to simulate your application, and trigger your index build. If you've set everything up as described here, run building_index_in_foreground.py.
While this is going on, feel free to run mongostat against your server to get a feel for what's going on while your "application" is running.
The python script will do the following:
Your job is to go in and find the index build, plus any evidence of long-running read/update operations that occur as a result of the index build. Be careful not to mistake other operations (such as the mongoimport) for the index build.
Note:
You may find it helpful to rotate your log files , expecially if you run the python script more than once.
To demonstrate that you've identified both the index build, and the long-running operations, answer the following question:
When do the long-running operations begin to appear in the log files, based on their timestamps?
- More than a minute before the index build began
- Less than one second before the index build began
- Less than one second after the index build began
- More than one second after the index build began,and also more than one second before the index build ended
- Less than one second before the index build ended
- Less than one second after the index build ended
- More than one second after the index build ended
- More than a minute after the index build ended
Answer
Download the relevant files as required and extract them to path E: MongoDB m312 chapter_3_slow_queries m312
C:\Users\Shinelon>e:
E:\>cd MongoDB\m312\chapter_3_slow_queries\m312\m312-vagrant-env
E:\MongoDB\m312\chapter_3_slow_queries\m312\m312-vagrant-env>vagrant up
The installation package network is walled off. Change the network path in the provision-m312 file to one of the following connections (or manually download and rewrite the installation method in the provision-m312):
Enter relevant scripts into share folder:
E:\>copy MongoDB\m312\chapter_3_slow_queries\m312\building_index_in_foreground.py MongoDB\m312\chapter_3_slow_queries\m312\m312-vagrant-env\shared\
Already copied One document.
E:\>copy MongoDB\m312\chapter_3_slow_queries\m312\set_up_building_index_in_foreground.sh MongoDB\m312\chapter_3_slow_queries\m312\m312-vagrant-env\shared\
Already copied One document.
Manually download the employees.zip file and extract it to directory E: MongoDB m312 chapter_3_slow_queries m312 m312-vagrant-env shared
Execute the set_up_building_index_in_foreground.sh script as required by the title: ImportError: No module named psutil
root@m312:/home/vagrant# /shared/set_up_building_index_in_foreground.sh
mongod: no process found
rm: cannot remove Holmium?root/data Holmium? No such file or directoryry
Traceback (most recent call last):
File "/usr/local/bin/mlaunch", line 7, in <module>
from mtools.mlaunch.mlaunch import main
File "/usr/local/lib/python2.7/dist-packages/mtools/mlaunch/mlaunch.py", line 6, in <module>
import psutil
ImportError: No module named psutil
MongoDB shell version v3.4.2
connecting to: mongodb://127.0.0.1:30000/
2018-04-24T07:46:35.135+0000 W NETWORK [thread1] Failed to connect to 127.0.0.1:30000, in(checking socket for error after poll), reason: Connection refused
2018-04-24T07:46:35.136+0000 E QUERY [thread1] Error: couldn't connect to server 127.0.0.1:30000, connection attempt failed :
connect@src/mongo/shell/mongo.js:237:13
@(connect):1:6
exception: connect failed
This is due to the lack of psutil packages. Install psutil packages:
root@m312:/home/vagrant# sudo apt-get install python-psutil
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following NEW packages will be installed:
python-psutil
0 upgraded, 1 newly installed, 0 to remove and 15 not upgraded.
Need to get 50.2 kB of archives.
After this operation, 299 kB of additional disk space will be used.
Get:1 http://archive.ubuntu.com/ubuntu/ trusty/main python-psutil amd64 1.2.1-1ubuntu2 [50.2 kB]
Fetched 50.2 kB in 7s (6,994 B/s)
Selecting previously unselected package python-psutil.
(Reading database ... 65034 files and directories currently installed.)
Preparing to unpack .../python-psutil_1.2.1-1ubuntu2_amd64.deb ...
Unpacking python-psutil (1.2.1-1ubuntu2) ...
Setting up python-psutil (1.2.1-1ubuntu2) ...
Execute the set_up_building_index_in_foreground.sh script again:
root@m312:/home/vagrant# /shared/set_up_building_index_in_foreground.sh
mongod: no process found
rm: cannot remove Holmium?root/data Holmium? No such file or directoryry
launching: mongod on port 30000
launching: mongod on port 30001
launching: mongod on port 30002
replica set 'm312RS' initialized.
MongoDB shell version v3.4.2
connecting to: mongodb://127.0.0.1:30000/
MongoDB server version: 3.4.2
{ "ok" : 1 }
bye
2018-04-24T07:48:23.243+0000 connected to: m312RS/m312:30000,m312:30001,m312:30002
2018-04-24T07:48:23.245+0000 dropping: m312.employees
2018-04-24T07:48:26.233+0000 [........................] m312.employees 13.5MB/395MB (3.4%)
2018-04-24T07:48:29.233+0000 [#.......................] m312.employees 29.0MB/395MB (7.3%)
2018-04-24T07:48:32.233+0000 [##......................] m312.employees 43.3MB/395MB (11.0%)
2018-04-24T07:48:35.232+0000 [###.....................] m312.employees 58.4MB/395MB (14.8%)
2018-04-24T07:48:38.233+0000 [####....................] m312.employees 72.8MB/395MB (18.4%)
2018-04-24T07:48:41.233+0000 [#####...................] m312.employees 86.2MB/395MB (21.8%)
2018-04-24T07:48:44.233+0000 [######..................] m312.employees 101MB/395MB (25.5%)
2018-04-24T07:48:47.232+0000 [#######.................] m312.employees 115MB/395MB (29.2%)
2018-04-24T07:48:50.233+0000 [#######.................] m312.employees 117MB/395MB (29.7%)
2018-04-24T07:48:53.233+0000 [#######.................] m312.employees 118MB/395MB (29.8%)
2018-04-24T07:48:56.234+0000 [#######.................] m312.employees 122MB/395MB (30.8%)
2018-04-24T07:48:59.237+0000 [#######.................] m312.employees 128MB/395MB (32.4%)
2018-04-24T07:49:02.232+0000 [########................] m312.employees 134MB/395MB (34.0%)
2018-04-24T07:49:05.233+0000 [########................] m312.employees 139MB/395MB (35.2%)
2018-04-24T07:49:08.234+0000 [########................] m312.employees 145MB/395MB (36.8%)
2018-04-24T07:49:11.233+0000 [#########...............] m312.employees 152MB/395MB (38.5%)
2018-04-24T07:49:14.234+0000 [#########...............] m312.employees 158MB/395MB (40.0%)
2018-04-24T07:49:17.233+0000 [#########...............] m312.employees 164MB/395MB (41.6%)
2018-04-24T07:49:20.233+0000 [##########..............] m312.employees 171MB/395MB (43.2%)
2018-04-24T07:49:23.233+0000 [##########..............] m312.employees 177MB/395MB (44.9%)
2018-04-24T07:49:26.233+0000 [###########.............] m312.employees 183MB/395MB (46.4%)
2018-04-24T07:49:29.232+0000 [###########.............] m312.employees 188MB/395MB (47.6%)
2018-04-24T07:49:32.234+0000 [###########.............] m312.employees 189MB/395MB (48.0%)
2018-04-24T07:49:35.233+0000 [###########.............] m312.employees 196MB/395MB (49.5%)
2018-04-24T07:49:38.235+0000 [############............] m312.employees 201MB/395MB (51.0%)
2018-04-24T07:49:41.233+0000 [############............] m312.employees 207MB/395MB (52.5%)
2018-04-24T07:49:44.232+0000 [############............] m312.employees 213MB/395MB (54.0%)
2018-04-24T07:49:47.235+0000 [#############...........] m312.employees 219MB/395MB (55.5%)
2018-04-24T07:49:50.233+0000 [#############...........] m312.employees 226MB/395MB (57.1%)
2018-04-24T07:49:53.233+0000 [##############..........] m312.employees 232MB/395MB (58.7%)
2018-04-24T07:49:56.233+0000 [##############..........] m312.employees 238MB/395MB (60.2%)
2018-04-24T07:49:59.233+0000 [##############..........] m312.employees 244MB/395MB (61.9%)
2018-04-24T07:50:02.234+0000 [###############.........] m312.employees 251MB/395MB (63.5%)
2018-04-24T07:50:05.233+0000 [###############.........] m312.employees 254MB/395MB (64.3%)
2018-04-24T07:50:08.234+0000 [###############.........] m312.employees 254MB/395MB (64.4%)
2018-04-24T07:50:11.233+0000 [###############.........] m312.employees 260MB/395MB (65.9%)
2018-04-24T07:50:14.233+0000 [################........] m312.employees 266MB/395MB (67.4%)
2018-04-24T07:50:17.232+0000 [################........] m312.employees 272MB/395MB (69.0%)
2018-04-24T07:50:20.233+0000 [################........] m312.employees 278MB/395MB (70.5%)
2018-04-24T07:50:23.234+0000 [#################.......] m312.employees 284MB/395MB (72.1%)
2018-04-24T07:50:26.232+0000 [#################.......] m312.employees 290MB/395MB (73.5%)
2018-04-24T07:50:29.235+0000 [##################......] m312.employees 297MB/395MB (75.1%)
2018-04-24T07:50:32.235+0000 [##################......] m312.employees 303MB/395MB (76.8%)
2018-04-24T07:50:35.240+0000 [##################......] m312.employees 309MB/395MB (78.3%)
2018-04-24T07:50:38.233+0000 [###################.....] m312.employees 316MB/395MB (80.0%)
2018-04-24T07:50:41.233+0000 [###################.....] m312.employees 317MB/395MB (80.4%)
2018-04-24T07:50:44.233+0000 [###################.....] m312.employees 323MB/395MB (81.8%)
2018-04-24T07:50:47.233+0000 [###################.....] m312.employees 326MB/395MB (82.7%)
2018-04-24T07:50:50.233+0000 [####################....] m312.employees 332MB/395MB (84.1%)
2018-04-24T07:50:53.233+0000 [####################....] m312.employees 338MB/395MB (85.7%)
2018-04-24T07:50:56.233+0000 [####################....] m312.employees 344MB/395MB (87.2%)
2018-04-24T07:50:59.234+0000 [#####################...] m312.employees 351MB/395MB (88.8%)
2018-04-24T07:51:02.233+0000 [#####################...] m312.employees 357MB/395MB (90.4%)
2018-04-24T07:51:05.234+0000 [######################..] m312.employees 363MB/395MB (92.0%)
2018-04-24T07:51:08.232+0000 [######################..] m312.employees 369MB/395MB (93.6%)
2018-04-24T07:51:11.233+0000 [######################..] m312.employees 371MB/395MB (94.0%)
2018-04-24T07:51:14.233+0000 [######################..] m312.employees 375MB/395MB (94.9%)
2018-04-24T07:51:17.233+0000 [#######################.] m312.employees 380MB/395MB (96.3%)
2018-04-24T07:51:20.236+0000 [#######################.] m312.employees 386MB/395MB (97.8%)
2018-04-24T07:51:23.233+0000 [#######################.] m312.employees 391MB/395MB (99.1%)
2018-04-24T07:51:25.282+0000 [########################] m312.employees 395MB/395MB (100.0%)
2018-04-24T07:51:25.282+0000 imported 1010893 documents
Run the script build_index_in_foreground.py:
root@m312:/home/vagrant# /shared/building_index_in_foreground.py
Looks like the employees collection is already present.
Not going to re-import it. Dropping indexes... done.
Spawning a set of processes to do lots of reads and writes while I create an index. The processes will simulate your many application clients.
... ok. While your 'application' clients are running, I'm going to create an index on {last_name: 1, first_name: 1}.
... ok, done.
Your log files should be ready for you to look at!
Enter the replica set environment:
vagrant@m312:~$ mongo --port 30000
MongoDB shell version v3.4.2
connecting to: mongodb://127.0.0.1:30000/
MongoDB server version: 3.4.2
Welcome to the MongoDB shell.
For interactive help, type "help".
For more comprehensive documentation, see
http://docs.mongodb.org/
Questions? Try the support group
http://groups.google.com/group/mongodb-user
Server has startup warnings:
2018-04-24T07:48:01.748+0000 I STORAGE [initandlisten]
2018-04-24T07:48:01.748+0000 I STORAGE [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2018-04-24T07:48:01.748+0000 I STORAGE [initandlisten] ** See http://dochub.mongodb.org/core/prodnotes-filesystem
2018-04-24T07:48:01.884+0000 I CONTROL [initandlisten]
2018-04-24T07:48:01.884+0000 I CONTROL [initandlisten] ** WARNING: Access control is not enabled for the database.
2018-04-24T07:48:01.884+0000 I CONTROL [initandlisten] ** Read and write access to data and configuration is unrestricted.
2018-04-24T07:48:01.884+0000 I CONTROL [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
2018-04-24T07:48:01.884+0000 I CONTROL [initandlisten]
View logs:
MongoDB Enterprise m312RS:PRIMARY> use local
switched to db local
MongoDB Enterprise m312RS:PRIMARY> db.oplog.rs.find()
{ "ts" : Timestamp(1524556082, 1), "h" : NumberLong("4463326453374821604"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "initiating set" } }
{ "ts" : Timestamp(1524556094, 2), "t" : NumberLong(1), "h" : NumberLong("8377794278341915314"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "new primary" } }
{ "ts" : Timestamp(1524556103, 1), "t" : NumberLong(1), "h" : NumberLong("-8950094261114613335"), "v" : 2, "op" : "c", "ns" : "m312.$cmd", "o" : { "create" : "employees", "idIndex" : { "v" : 2, "key" : { "_id" : 1 }, "name" : "_id_", "ns" : "m312.employees" } } }
{ "ts" : Timestamp(1524556103, 2), "t" : NumberLong(1), "h" : NumberLong("510266152817245486"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857c5"), "last_name" : "Pham", "quote" : "Aliquam est reiciendis alias neque ad.", "job" : "Counselling psychologist", "ssn" : "401-31-6615", "address" : { "city" : "Lake Meaganton", "state" : "Idaho", "street" : "83248 Woods Extension", "zip" : "10914-3394" }, "first_name" : "Yvonne", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2011-04-17T21:19:28Z"), "email" : "murillobrian@cox.net" } }
{ "ts" : Timestamp(1524556103, 3), "t" : NumberLong(1), "h" : NumberLong("2272078709834620109"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857c6"), "last_name" : "Nelson", "quote" : "A eveniet iusto dicta quis sed tenetur eius illo.", "job" : "Conservator, furniture", "ssn" : "671-16-1433", "address" : { "city" : "Lake Meaganton", "state" : "Idaho", "street" : "699 Ryan Branch Apt. 371", "zip" : "10914-3394" }, "first_name" : "Mary", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2016-04-27T11:04:11Z"), "email" : "cindy93@gmail.com" } }
{ "ts" : Timestamp(1524556103, 4), "t" : NumberLong(1), "h" : NumberLong("-3423843438153384604"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857c7"), "last_name" : "Hull", "quote" : "Sunt consectetur harum maxime qui.", "job" : "Private music teacher", "ssn" : "042-41-2995", "address" : { "city" : "Phelpston", "street" : "11869 Stewart Ports Apt. 924", "zip" : "89388" }, "first_name" : "Carrie", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2017-03-06T08:40:34Z"), "email" : "csmith@hall.biz" } }
{ "ts" : Timestamp(1524556103, 5), "t" : NumberLong(1), "h" : NumberLong("-2748583038735912885"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857c8"), "last_name" : "Frazier", "quote" : "Minus quo corporis nemo id provident eius.", "job" : "Investment banker, corporate", "ssn" : "683-46-9400", "address" : { "city" : "Lake Meaganton", "state" : "Idaho", "street" : "7526 David Island Apt. 404", "zip" : "10914-3394" }, "first_name" : "John", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2014-05-26T00:14:02Z"), "email" : "ythompson@hotmail.com" } }
{ "ts" : Timestamp(1524556103, 6), "t" : NumberLong(1), "h" : NumberLong("-4272853794543634317"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857c9"), "last_name" : "Herrera", "quote" : "Sit perferendis nostrum suscipit cumque mollitia.", "job" : "Theatre stage manager", "ssn" : "261-99-7098", "address" : { "city" : "Brewershire", "street" : "9069 Bailey Ferry Suite 423", "zip" : "51376" }, "first_name" : "Elizabeth", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2016-05-23T05:14:41Z"), "email" : "elizabeth35@mccarty.com" } }
{ "ts" : Timestamp(1524556103, 7), "t" : NumberLong(1), "h" : NumberLong("-4160213891465004502"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857ca"), "last_name" : "Liu", "quote" : "Voluptatum aspernatur illo inventore fuga eius fugiat similique corrupti.", "job" : "Physiotherapist", "ssn" : "273-71-8889", "address" : { "city" : "Leeport", "street" : "59105 Adkins Ramp Apt. 451", "zip" : "89662" }, "first_name" : "Anthony", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2015-05-23T02:21:50Z"), "email" : "asimmons@hotmail.com" } }
{ "ts" : Timestamp(1524556103, 8), "t" : NumberLong(1), "h" : NumberLong("-5526899559426671528"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857cb"), "last_name" : "Stevens", "quote" : "Doloribus sequi temporibus eveniet.", "job" : "Engineer, civil (contracting)", "ssn" : "081-78-3110", "address" : { "city" : "Anthonyhaven", "street" : "1914 Madison Fords", "zip" : "53666" }, "first_name" : "Richard", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2010-03-28T14:20:13Z"), "email" : "david58@yahoo.com" } }
{ "ts" : Timestamp(1524556103, 9), "t" : NumberLong(1), "h" : NumberLong("-1001455799138112190"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857cc"), "last_name" : "Perry", "quote" : "Tempore sunt quae temporibus in nostrum.", "job" : "Environmental consultant", "ssn" : "248-70-8696", "address" : { "city" : "Jamesfurt", "street" : "4961 Obrien Keys", "zip" : "19133" }, "first_name" : "Trevor", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2013-05-27T13:24:31Z"), "email" : "teresabrown@yahoo.com" } }
{ "ts" : Timestamp(1524556103, 10), "t" : NumberLong(1), "h" : NumberLong("7319744338376850087"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857cd"), "last_name" : "Gibson", "quote" : "Temporibus accusamus cupiditate tempore atque.", "job" : "Artist", "ssn" : "572-94-3935", "address" : { "city" : "Debrafurt", "street" : "06878 Chapman Pine", "zip" : "32933" }, "first_name" : "Sara", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2016-12-17T19:09:18Z"), "email" : "mhall@sims-moss.info" } }
{ "ts" : Timestamp(1524556103, 11), "t" : NumberLong(1), "h" : NumberLong("-8254524138374999338"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857ce"), "last_name" : "Turner", "quote" : "Vero iste odit voluptas sunt harum totam.", "job" : "Purchasing manager", "ssn" : "579-34-3243", "address" : { "city" : "Kellyhaven", "street" : "3096 Jones Parkway Suite 928", "zip" : "09697" }, "first_name" : "Nicholas", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2013-09-25T07:20:41Z"), "email" : "steven03@hancock.info" } }
{ "ts" : Timestamp(1524556103, 12), "t" : NumberLong(1), "h" : NumberLong("915927080282861600"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857cf"), "last_name" : "Johnson", "quote" : "Dolorum odio molestias harum sunt sint.", "job" : "Special effects artist", "ssn" : "067-63-2867", "address" : { "city" : "Lake Meaganton", "state" : "Idaho", "street" : "55634 Scott Springs", "zip" : "10914-3394" }, "first_name" : "Keith", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2012-08-30T05:41:55Z"), "email" : "mjones@walker.com" } }
{ "ts" : Timestamp(1524556103, 13), "t" : NumberLong(1), "h" : NumberLong("-5092246712154353018"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857d0"), "last_name" : "Tucker", "quote" : "Enim rerum perspiciatis pariatur ipsam sed.", "job" : "Scientist, forensic", "ssn" : "333-53-2162", "address" : { "city" : "Lake Meaganton", "state" : "Idaho", "street" : "9307 Christopher Street Suite 319", "zip" : "10914-3394" }, "first_name" : "Kristine", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2011-06-20T12:02:25Z"), "email" : "usalazar@yahoo.com" } }
{ "ts" : Timestamp(1524556103, 14), "t" : NumberLong(1), "h" : NumberLong("-2206896415529188900"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857d1"), "last_name" : "Combs", "quote" : "Laborum perferendis dolorum rerum eius ipsa odit.", "job" : "Accountant, chartered certified", "ssn" : "136-13-3672", "address" : { "city" : "Lake Meaganton", "state" : "Idaho", "street" : "262 Donna Ports", "zip" : "10914-3394" }, "first_name" : "Jacqueline", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2016-01-06T01:47:09Z"), "email" : "kathleen81@gmail.com" } }
{ "ts" : Timestamp(1524556103, 15), "t" : NumberLong(1), "h" : NumberLong("333343584211571593"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857d2"), "last_name" : "Owens", "quote" : "Sit quisquam id quidem voluptate consequuntur totam totam.", "job" : "Fisheries officer", "ssn" : "875-23-9138", "address" : { "city" : "Lake Meaganton", "state" : "Idaho", "street" : "81799 Nelson Forks Suite 297", "zip" : "10914-3394" }, "first_name" : "Robert", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2015-12-17T18:51:12Z"), "email" : "joshua24@harding-miller.biz" } }
{ "ts" : Timestamp(1524556103, 16), "t" : NumberLong(1), "h" : NumberLong("6372524148305143811"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857d3"), "last_name" : "Simon", "quote" : "Laboriosam incidunt minus vero voluptates officiis.", "job" : "Operational investment banker", "ssn" : "740-65-7137", "address" : { "city" : "Rogershire", "street" : "8041 Smith Gardens", "zip" : "60705" }, "first_name" : "Tanner", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2011-07-21T04:06:14Z"), "email" : "julie90@gmail.com" } }
{ "ts" : Timestamp(1524556103, 17), "t" : NumberLong(1), "h" : NumberLong("2361209461982062260"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857d4"), "last_name" : "Cole", "quote" : "At aut debitis alias itaque modi autem.", "job" : "Insurance broker", "ssn" : "821-30-8939", "address" : { "city" : "Lake Meaganton", "state" : "Idaho", "street" : "955 Kayla Manor", "zip" : "10914-3394" }, "first_name" : "Julia", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2015-12-30T09:26:58Z"), "email" : "owallace@yahoo.com" } }
{ "ts" : Timestamp(1524556103, 18), "t" : NumberLong(1), "h" : NumberLong("-867703067546619547"), "v" : 2, "op" : "i", "ns" : "m312.employees", "o" : { "_id" : ObjectId("5adee147db67512a034857d5"), "last_name" : "Fitzpatrick", "quote" : "Id amet id itaque.", "job" : "General practice doctor", "ssn" : "028-40-3851", "address" : { "city" : "Lake Meaganton", "state" : "Idaho", "street" : "69994 Booker Estate Apt. 230", "zip" : "10914-3394" }, "first_name" : "Lisa", "company_id" : ObjectId("58bdbe32500b1d42c7e10be7"), "employer" : "Terry and Sons", "birthday" : ISODate("2013-12-03T09:21:26Z"), "email" : "cynthia99@dalton.info" } }
Type "it" for more
It was observed that the time stamp for index creation was Timestamp(1524556103, 1)
The time stamps before and after it are: (1524556094, 2), (1524556103, 2)
It can be understood as:
more than 1 second before index build began
less than 1 second after index build ended
So the correct answer is:
- Less than one second after the index build ended
lab: Analyse Profiler Data
Download Handouts:
m312/lab_analyse_profiler/profile.json
In this lab, you are tasked to determine when a given event happened by analysing the system.profiler data.
This profiler information was captured during the execution of test script performing read operations. These read operations, consisted on 3 types of queries:
- query on _id field -> db.employees.find({_id: XXXX})
- query on address.zip field -> db.employees.find({"address.zip": XXX })
- range query on birthday field -> db.employees.find({"birthday": {"gt":X,"gt":X,"lt": X }})
To analyse the profiler data, we are going to use the best database in the world that, as you all know, is MongoDB.
Let's go ahead and setup the environment.
- First step, launch a single node mongod instance:
cd m312-vagrant-env
vagrant up
vagrant ssh
mlaunch --single
- The following step is to download the attached profile.json data and make it available in your m312 virtual machine:
cp Downloads/profiler*.json m312-vagrant-env/dataset
The command line example is set for Unix but a simple copy of this file will suffice
- Next, we will load the dataset into our single node mongod instance. Let's load the data into a collection named profiler_data
vagrant ssh
mongoimport -d m312 -c profiler_data /dataset/profile.json
The profiler data contains all read operations that surpassed the threshold of 40ms, the set slowms value:
db.setProfilingLevel(1, 40)
During the execution of our script, our DBAs decided to create an index that affected the behavior of one of the offending queries.
From the profiler data, we are asked to determined which index was created and when was this change reflected on the behavior of our query.
So in this lab we want to know:
When and which index was created ?
Choose the best answer:
db.companies.createIndex({'address.zip': 1})
After 2017-03-06T22:57:00.039Z
db.employees.createIndex({'address.zip': 1})
After 2017-03-06T22:55:55.065Z
db.employees.createIndex({'birthdate': 1})
After 2017-03-06T22:57:00.039Z
db.employees.createIndex({'birthdate': 1})
Before 2017-03-06T22:57:57.332Z
db.employees.createIndex({'address.zip': 1})
After 2017-03-06T22:56:30.407Z
Answer
Exit and re-enter the container:
E:\MongoDB\m312\chapter_3_slow_queries\m312\m312-vagrant-env>vagrant ssh
Welcome to Ubuntu 14.04.5 LTS (GNU/Linux 3.13.0-144-generic x86_64)
* Documentation: https://help.ubuntu.com/
System information as of Tue Apr 24 07:29:48 UTC 2018
System load: 0.0 Processes: 85
Usage of /: 3.7% of 39.34GB Users logged in: 0
Memory usage: 4% IP address for eth0: 10.0.2.15
Swap usage: 0% IP address for eth1: 192.168.14.100
Graph this data and manage this system at:
https://landscape.canonical.com/
Get cloud support with Ubuntu Advantage Cloud Guest:
http://www.ubuntu.com/business/services/cloud
New release '16.04.4 LTS' available.
Run 'do-release-upgrade' to upgrade to it.
*** System restart required ***
Last login: Tue Apr 24 07:29:49 2018 from 10.0.2.2
Start a single node instance:
vagrant@m312:~$ mlaunch --single
launching: mongod on port 27017
Download profile.json file and put it in path E: MongoDB m312 chapter_3_slow_queries m312 m312-vagrant-env dataset
Import scripts:
vagrant@m312:~$ mongoimport -d m312 -c profiler_data /dataset/profile.json
2018-04-24T08:51:19.449+0000 connected to: localhost
2018-04-24T08:51:19.501+0000 imported 195 documents
Enter the mongo shell and configure the analysis level:
vagrant@m312:~$ mongo
MongoDB shell version v3.4.2
connecting to: mongodb://127.0.0.1:27017
MongoDB server version: 3.4.2
Server has startup warnings:
2018-04-24T08:48:11.592+0000 I STORAGE [initandlisten]
2018-04-24T08:48:11.592+0000 I STORAGE [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2018-04-24T08:48:11.592+0000 I STORAGE [initandlisten] ** See http://dochub.mongodb.org/core/prodnotes-filesystem
2018-04-24T08:48:11.693+0000 I CONTROL [initandlisten]
2018-04-24T08:48:11.693+0000 I CONTROL [initandlisten] ** WARNING: Access control is not enabled for the database.
2018-04-24T08:48:11.693+0000 I CONTROL [initandlisten] ** Read and write access to data and configuration is unrestricted.
2018-04-24T08:48:11.693+0000 I CONTROL [initandlisten]
MongoDB Enterprise > db.setProfilingLevel(1, 40)
{ "was" : 0, "slowms" : 100, "ok" : 1 }
View the profiler_data collection:
MongoDB Enterprise > use m312
switched to db m312
MongoDB Enterprise > show collections
profiler_data
MongoDB Enterprise > db.profiler_data.find().count
function (applySkipLimit) {
var cmd = this._convertToCountCmd(applySkipLimit);
var res = this._db.runReadCommand(cmd);
if (res && res.n != null)
return res.n;
throw _getErrorWithCode(res, "count failed: " + tojson(res));
}
MongoDB Enterprise > db.profiler_data.find().count()
195
To analyze the topic, you should look for records that use an index (not a full table scan):
MongoDB Enterprise > db.profiler_data.find({"$nor":[{"planSummary" : "COLLSCAN"}]},{"_id":0,"planSummary":1,"ts":1})
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:56:30.407Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:56:31.579Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:57:00.039Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:57:42.188Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:57:57.332Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:58:06.581Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:58:10.604Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:58:12.412Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:58:47.868Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:58:49.977Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:58:52.015Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:58:55.367Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:58:56.807Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:59:08.078Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:59:10.228Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:59:23.411Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:59:26.937Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:59:41.204Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:59:43.138Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:59:48.636Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:59:54.835Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T22:59:57.930Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T23:00:17.057Z") }
{ "planSummary" : "IXSCAN { address.zip: 1 }", "ts" : ISODate("2017-03-06T23:00:21.825Z") }
The results show that the answer is
db.employees.createIndex({'address.zip': 1})
After 2017-03-06T22:55:55.065Z