[SERVER-28575] Profile entry for update/delete should contain entire raw update/delete Created: 31/Mar/17  Updated: 06/Dec/17  Resolved: 23/May/17

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

Type: Task Priority: Major - P3
Reporter: Tess Avitabile (Inactive) Assignee: Tess Avitabile (Inactive)
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Documented
is documented by DOCS-10300 Docs for SERVER-28575: Profile entry ... Closed
Related
Backwards Compatibility: Minor Change
Sprint: Query 2017-05-08, Query 2017-05-29
Participants:

 Description   

The profile entry for update/delete should contain the entire raw update/delete in the command field, i.e. for updates:

{ q: <query>, u: <update>, upsert: <boolean>, multi: <boolean>, ... }

and for deletes:

{ q : <query>, limit : <integer>, ... }

Remove the query, updateobj and collation fields, as they become redundant. Legacy updates/deletes should have the same format in the profile entry.

Extend profile_*.js tests to ensure that the arrayFilters are logged for update and findAndModify.

The log lines for individual updates/deletes and the currentOp should have the same command field. Their query, update, and collation fields should be removed.

The query/insert field should be renamed to command for all command's currentOp, log lines, and profile entries.



 Comments   
Comment by Githook User [ 23/May/17 ]

Author:

{u'username': u'tessavitabile', u'name': u'Tess Avitabile', u'email': u'tess.avitabile@mongodb.com'}

Message: SERVER-28575 Profile entry for update/delete should contain entire raw update/delete
Branch: master
https://github.com/mongodb/mongo/commit/f56ae945275aa9360d2d6eae192b64d558ede20b

Comment by Tess Avitabile (Inactive) [ 28/Apr/17 ]

I was not planning to include command options like writeConcern in the query field, since it seems odd to combine these. We could also consider including the entire command in the profile entry in a different field.

Comment by James Wahlin [ 28/Apr/17 ]

This approach sounds good to me. Would all command options be written with each individual update/delete?

Comment by Tess Avitabile (Inactive) [ 27/Apr/17 ]

For finds, we put the entire find command in the query field of the profile entry. For legacy finds, the query gets upconverted to a find command and included in the query field of the profile entry.

I would like to do something similar for updates and deletes, but there is a hiccup that we produce a profile entry for each individual update/delete in the command. This is important, since the stats in the entry, such as nMatched and nModified are per-update/delete. So instead of making the query field be the entire command, I would like to make it the individual update/delete, i.e. for updates:

{ q: <query>, u: <update>, upsert: <boolean>, multi: <boolean>, collation: <document> }

and for deletes:

{ q : <query>, limit : <integer>, collation: <document> }

Legacy updates/deletes would be upconverted to this format. I would get rid of the updateobj and collation fields in the profile entry, since they would become redundant. I would leave the upsert field, since it is set to true if a document is in fact inserted, but we could consider changed the name to upserted, perhaps.

james.wahlin and david.storch, how does this sound?

Comment by James Wahlin [ 26/Apr/17 ]

I agree with Dave that we should be writing the entire update command object. Looks like the profiler format is different than the log format? Running a test upsert where the document exists, I see the following in the log, which includes the 'upsert' flag even though there was no insert:

2017-04-26T11:31:07.044-0400 I COMMAND  [conn8] command test.$cmd appName: "MongoDB Shell" command: update { update: "test", updates: [ { q: { x: 1.0 }, u: { $set: { w: 1.0 } }, multi: false, upsert: true } ], ordered: true } numYields:0 reslen:202 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_command 0ms

My vote would be to unify the profiler output with that of the log, writing the entire command object. The current format was likely an attempt to not backwards break when we introduced write commands, but has led to this split.

Comment by Tess Avitabile (Inactive) [ 26/Apr/17 ]

I'm considering storing all of the update options in OpDebug and appending them generically in OpDebug::report() and OpDebug::append(), so that we don't need to do change OpDebug/CurOp the next time we add an option to update. Currently, we include collation in the profile object if it is non-empty. We do not include multi or writeConcern. We only include upsert=true if a document was inserted. Should we include multi and writeConcern in the profile object? And would it be a bad idea to make a backwards-breaking change to include upsert=true whenever specified in the command, even if no document was inserted? david.storch and james.wahlin, what do you think?

Comment by Tess Avitabile (Inactive) [ 21/Apr/17 ]

I found that for update, we do not record the entire command in the profiler. The profiler entry looks like this:

{
	"op" : "update",
	"ns" : "test.coll",
	"query" : {
		"a" : 5
	},
	"updateobj" : {
		"$set" : {
			"b" : 6
		}
	},
	"collation" : {
		"locale" : "en_US"
	},
	"keysExamined" : 0,
	"docsExamined" : 2,
	"nMatched" : 1,
	"nModified" : 0,
	"numYield" : 0,
	"locks" : {
		"Global" : {
			"acquireCount" : {
				"r" : NumberLong(1),
				"w" : NumberLong(1)
			}
		},
		"MMAPV1Journal" : {
			"acquireCount" : {
				"w" : NumberLong(1)
			}
		},
		"Database" : {
			"acquireCount" : {
				"w" : NumberLong(1)
			}
		},
		"Collection" : {
			"acquireCount" : {
				"W" : NumberLong(1)
			}
		}
	},
	"millis" : 0,
	"planSummary" : "COLLSCAN",
	"execStats" : {
		"stage" : "UPDATE",
		"nReturned" : 0,
		"executionTimeMillisEstimate" : 0,
		"works" : 4,
		"advanced" : 0,
		"needTime" : 3,
		"needYield" : 0,
		"saveState" : 0,
		"restoreState" : 0,
		"isEOF" : 1,
		"invalidates" : 0,
		"nMatched" : 1,
		"nWouldModify" : 0,
		"nInvalidateSkips" : 0,
		"wouldInsert" : false,
		"fastmodinsert" : false,
		"inputStage" : {
			"stage" : "COLLSCAN",
			"filter" : {
				"a" : {
					"$eq" : 5
				}
			},
			"nReturned" : 1,
			"executionTimeMillisEstimate" : 0,
			"works" : 3,
			"advanced" : 1,
			"needTime" : 2,
			"needYield" : 0,
			"saveState" : 1,
			"restoreState" : 1,
			"isEOF" : 0,
			"invalidates" : 0,
			"direction" : "forward",
			"docsExamined" : 2
		}
	},
	"ts" : ISODate("2017-04-21T20:57:29.521Z"),
	"client" : "127.0.0.1",
	"appName" : "MongoDB Shell",
	"allUsers" : [ ],
	"user" : ""
}

We set updateobj here. I think we should do something similar for arrayFilters.

Comment by David Storch [ 31/Mar/17 ]

I think we should be recording the entire update command in CurOp (presumably we're doing this already?), but I don't think we should have special CurOp logic for handling arrayFilters.

Comment by Tess Avitabile (Inactive) [ 31/Mar/17 ]

Do you think we need to record the arrayFilters in the CurOp in performSingleUpdateOp()? Perhaps not, since we don't record the update either. If not, then this is just testing.

Comment by David Storch [ 31/Mar/17 ]

tess.avitabile, there's not any special work here other than testing, correct?

Generated at Thu Feb 08 04:18:30 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.