[SERVER-3443] alter profiler to capture plan used when query ran Created: 18/Jul/11  Updated: 12/Jul/16  Resolved: 14/Jan/14

Status: Closed
Project: Core Server
Component/s: Querying
Affects Version/s: None
Fix Version/s: 2.5.5

Type: Improvement Priority: Minor - P4
Reporter: Kenny Gorman Assignee: hari.khalsa@10gen.com
Resolution: Done Votes: 5
Labels: query_triage
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

1.8.1


Issue Links:
Depends
Duplicate
is duplicated by SERVER-5578 Have profiler capture which index was... Closed
Related
is related to SERVER-7754 add index/query plan to currentOp and... Closed
Participants:

 Description   

I know this may be difficult or require a query to be double run, but it would be great to have the plan in the profiler. Especially the nYields field.

> db.contact.find(

{userid:"000020862072"}

).explain()
{
"cursor" : "BasicCursor",
"nscanned" : 299073,
"nscannedObjects" : 299073,
"n" : 6,
"millis" : 606,
"nYields" : 1,
"nChunkSkips" : 0,
"isMultiKey" : false,
"indexOnly" : false,
"indexBounds" : {

}
}



 Comments   
Comment by hari.khalsa@10gen.com [ 14/Jan/14 ]

In the case above, there was no index used. Here is an example with an index:

	"execStats" : {
		"type" : "LIMIT",
		"works" : 2,
		"yields" : 0,
		"unyields" : 0,
		"invalidates" : 0,
		"advanced" : 1,
		"needTime" : 0,
		"needFetch" : 0,
		"isEOF" : 1,
		"children" : [
			{
				"type" : "FETCH",
				"works" : 1,
				"yields" : 0,
				"unyields" : 0,
				"invalidates" : 0,
				"advanced" : 1,
				"needTime" : 0,
				"needFetch" : 0,
				"isEOF" : 1,
				"alreadyHasObj" : 0,
				"forcedFetches" : 0,
				"matchTested" : 0,
				"children" : [
					{
						"type" : "IXSCAN",
						"works" : 1,
						"yields" : 0,
						"unyields" : 0,
						"invalidates" : 0,
						"advanced" : 1,
						"needTime" : 0,
						"needFetch" : 0,
						"isEOF" : 1,
						"keyPattern" : "{ x: 1.0 }",
						"bounds" : {
							"x" : [
								[
									1,
									1
								]
							]
						},
						"isMultiKey" : 0,
						"yieldMovedCursor" : 0,
						"dupsTested" : 0,
						"dupsDropped" : 0,
						"seenInvalidated" : 0,
						"matchTested" : 0,
						"keysExamined" : 1,
						"children" : [ ]
					}
				]
			}
		]
	},

Comment by Christopher Price [ 14/Jan/14 ]

Where is the name of the index that was used?

Comment by Githook User [ 14/Jan/14 ]

Author:

{u'username': u'hkhalsa', u'name': u'Hari Khalsa', u'email': u'hkhalsa@10gen.com'}

Message: SERVER-3443 SERVER-7754 add plan exec stats to system profile
Branch: master
https://github.com/mongodb/mongo/commit/59b0371902b5b278ef1e88a9c15424c6efeea666

Comment by Daniel Pasette (Inactive) [ 14/Jan/14 ]

Would look like this. Note the new field "execStats":

{
        "op" : "update",
        "ns" : "profile3.profile3",
        "query" : {
                "x" : 0
        },
        "updateobj" : {
                "$inc" : {
                        "a" : 1
                }
        },
        "nscanned" : 0,
        "nupdated" : 0,
        "nModified" : 0,
        "keyUpdates" : 0,
        "numYield" : 0,
        "lockStats" : {
                "timeLockedMicros" : {
                        "r" : NumberLong(0),
                        "w" : NumberLong(26)
                },
                "timeAcquiringMicros" : {
                        "r" : NumberLong(0),
                        "w" : NumberLong(2)
                }
        },
        "millis" : 0,
        "execStats" : {
                "type" : "LIMIT",
                "works" : 2,
                "yields" : 0,
                "unyields" : 0,
                "invalidates" : 0,
                "advanced" : 1,
                "needTime" : 1,
                "needFetch" : 0,
                "isEOF" : 1,
                "children" : [
                        {
                                "type" : "COLLSCAN",
                                "works" : 2,
                                "yields" : 0,
                                "unyields" : 0,
                                "invalidates" : 0,
                                "advanced" : 1,
                                "needTime" : 1,
                                "needFetch" : 0,
                                "isEOF" : 1,
                                "docsTested" : 1,
                                "children" : [ ]
                        }
                ]
        },
        "ts" : ISODate("2014-01-13T21:53:38.703Z"),
        "client" : "127.0.0.1",
        "allUsers" : [
                {
                        "user" : "jstests_profile3_user",
                        "db" : "profile3"
                }
        ],
        "user" : "jstests_profile3_user@profile3"
}

Comment by Christopher Price [ 13/Jan/14 ]

Could we see sample output before this is implemented?

Comment by Daniel Crosta [ 20/Sep/11 ]

Would be great to see nScannedObjects, cursor, and (for BTree Cursors) the index(es) used

Comment by Dwight Merriman [ 19/Jul/11 ]

yes a subset would be good. assigning to dan until assigned elsewhere.

Comment by Eliot Horowitz (Inactive) [ 19/Jul/11 ]

We probably don't want the whole thing as that is a bit expensive.
Maybe some more of the fields though

Comment by Kenny Gorman [ 18/Jul/11 ]

Sorry, I will try to be more explicit. It would be great to see the explain() output in the db.system.profile collection.

Comment by Dwight Merriman [ 18/Jul/11 ]

i didn't quite understand what the request is, what is new there vs. already there.

Comment by Kenny Gorman [ 18/Jul/11 ]

OK, will create SERVER in the future...

Generated at Thu Feb 08 03:03:05 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.