[SERVER-35907] Database Profiler should provide information about the write concern Created: 29/Jun/18  Updated: 27/Oct/23  Resolved: 06/Aug/18

Status: Closed
Project: Core Server
Component/s: Diagnostics
Affects Version/s: 3.6.5
Fix Version/s: None

Type: New Feature Priority: Major - P3
Reporter: Niklas Wenzel Assignee: Asya Kamsky
Resolution: Works as Designed Votes: 0
Labels: profiling
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Participants:

 Description   

I would like to confirm that a third-party library uses the correct write concern when sending commands to the MongoDB instance. There currently does not seem to be a way to do that.

Proposed solution: Make the database profiler store the write concern of each operation in the database's system.profile collection when the profiling level is set to 2.



 Comments   
Comment by Asya Kamsky [ 23/Sep/18 ]

We have reconsidered the ticket and decided against it - we have already seen some confusion when writes and overall batches are logged separately as well as worried that the totals won’t “add up” or at least will be more difficult to interpret if we wrote them to profile separately.

Comment by Niklas Wenzel [ 13/Sep/18 ]

Thank you, Asya!

Can we then reopen this issue to have the write concern logged in the system.profile collection for update operations as well?

Comment by Asya Kamsky [ 26/Aug/18 ]

You can check write concern for update command in the logs.

The update has two operations, the update command which specifies (and waits for) write concern and the update/write which is what happens to get recorded in the system.profile collection.

The mongod logs will contain both however.  Here's an example:

2018-08-26T01:43:18.761-0400 I WRITE    [conn25190] update test.people2 appName: "MongoDB Shell" command: { q: {}, u: { $set: { name: "Asya" } }, multi: false, upsert: false } planSummary: COLLSCAN keysExamined:0 docsExamined:1 nMatched:1 nModified:1 numYields:0 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 0ms
2018-08-26T01:43:18.764-0400 I COMMAND  [conn25190] command test.$cmd appName: "MongoDB Shell" command: update { update: "people2", updates: [ { q: {}, u: { $set: { name: "Asya" } }, multi: false, upsert: false } ], ordered: true, writeConcern: { w: "majority" }, $db: "test" } numYields:0 reslen:245 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { W: 1 } }, oplog: { acquireCount: { w: 1 } } } 

As you can see, the second line corresponding to the command has the writeConcern logged.

Comment by Niklas Wenzel [ 15/Aug/18 ]

Running commands in mongo shell, I noticed the following:

  • The write concern is being logged when running an "insert" operation.
  • The write concern is not being logged when running an "update" operation.

I haven't tested what happens when running other types of operations.

Comment by Niklas Wenzel [ 15/Aug/18 ]

Thank you for your reply, Asya.

I had a look at it again and I don't see the information in my system.profiles collection that you see.

More details about my setup:

  • I'm running Mongo DB 4.0.1.
  • I'm running a standalone mongo instance, not a replica set.
  • I'm connecting using the Node.js driver.
  • I'm running an update operation.
  • The "command" portion in the document in the system.profiles collection contains the following keys:
    • q: The query document
    • u: The update document
    • multi: boolean
    • upsert: boolean
  • There is no "writeConcern" key as in your case.
  • The acquired locks do not provide any indication of whether the write concern was properly applied when using a standalone.
Comment by Asya Kamsky [ 06/Aug/18 ]

This is already the case. After setting profiling level here is what I see in system.profile collection:

{
	"op" : "insert",
	"ns" : "test.warehouse",
	"command" : {
		"insert" : "warehouse",
		"ordered" : true,
		"writeConcern" : {
			"j" : true
		},
		"$db" : "test"
	},
	"ninserted" : 1,
	"keysInserted" : 2,
	"numYield" : 0,
	"locks" : {
		"Global" : {
			"acquireCount" : {
				"r" : NumberLong(1),
				"w" : NumberLong(1)
			}
		},
		"Database" : {
			"acquireCount" : {
				"w" : NumberLong(1)
			}
		},
		"Collection" : {
			"acquireCount" : {
				"w" : NumberLong(1)
			}
		}
	},
	"responseLength" : 45,
	"protocol" : "op_msg",
	"millis" : 15,
	"ts" : ISODate("2018-08-06T14:56:53.152Z"),
	"client" : "127.0.0.1",
	"appName" : "MongoDB Shell",
	"allUsers" : [ ],
	"user" : ""
}
{
	"op" : "insert",
	"ns" : "test.warehouse",
	"command" : {
		"insert" : "warehouse",
		"ordered" : true,
		"writeConcern" : {
			"w" : "majority"
		},
		"$db" : "test"
	},
	"ninserted" : 0,
	"numYield" : 0,
	"locks" : {
		"Global" : {
			"acquireCount" : {
				"r" : NumberLong(1),
				"w" : NumberLong(1)
			}
		},
		"Database" : {
			"acquireCount" : {
				"w" : NumberLong(1)
			}
		},
		"Collection" : {
			"acquireCount" : {
				"w" : NumberLong(1)
			}
		}
	},
	"responseLength" : 192,
	"protocol" : "op_msg",
	"millis" : 1,
	"ts" : ISODate("2018-08-06T14:57:00.112Z"),
	"client" : "127.0.0.1",
	"appName" : "MongoDB Shell",
	"allUsers" : [ ],
	"user" : ""
}
{
	"op" : "insert",
	"ns" : "test.warehouse",
	"command" : {
		"insert" : "warehouse",
		"ordered" : true,
		"writeConcern" : {
			"w" : "majority"
		},
		"$db" : "test"
	},
	"ninserted" : 1,
	"keysInserted" : 2,
	"numYield" : 0,
	"locks" : {
		"Global" : {
			"acquireCount" : {
				"r" : NumberLong(1),
				"w" : NumberLong(1)
			}
		},
		"Database" : {
			"acquireCount" : {
				"w" : NumberLong(1)
			}
		},
		"Collection" : {
			"acquireCount" : {
				"w" : NumberLong(1)
			}
		}
	},
	"responseLength" : 45,
	"protocol" : "op_msg",
	"millis" : 2,
	"ts" : ISODate("2018-08-06T14:57:06.512Z"),
	"client" : "127.0.0.1",
	"appName" : "MongoDB Shell",
	"allUsers" : [ ],
	"user" : ""
}

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