slow_query_and_profiler_output.txt

Profiler:

[jsTest] ----
[jsTest] ~~~: [
[jsTest] 	{
[jsTest] 		"op" : "update",
[jsTest] 		"ns" : "testDB.slow_query_oplog_slot_duration",
[jsTest] 		"command" : {
[jsTest] 			"q" : {
[jsTest]
[jsTest] 			},
[jsTest] 			"u" : {
[jsTest] 				"updateField" : 1
[jsTest] 			},
[jsTest] 			"multi" : false,
[jsTest] 			"upsert" : false,
[jsTest] 			"comment" : "updateSomething"
[jsTest] 		},
[jsTest] 		"keysExamined" : 0,
[jsTest] 		"docsExamined" : 1,
[jsTest] 		"nMatched" : 1,
[jsTest] 		"nModified" : 1,
[jsTest] 		"nUpserted" : 0,
[jsTest] 		"keysInserted" : 0,
[jsTest] 		"keysDeleted" : 0,
[jsTest] 		"numYield" : 0,
[jsTest] 		"locks" : {
[jsTest] 			"ParallelBatchWriterMode" : {
[jsTest] 				"acquireCount" : {
[jsTest] 					"r" : NumberLong(1)
[jsTest] 				}
[jsTest] 			},
[jsTest] 			"FeatureCompatibilityVersion" : {
[jsTest] 				"acquireCount" : {
[jsTest] 					"r" : NumberLong(1),
[jsTest] 					"w" : NumberLong(1)
[jsTest] 				}
[jsTest] 			},
[jsTest] 			"ReplicationStateTransition" : {
[jsTest] 				"acquireCount" : {
[jsTest] 					"w" : NumberLong(2)
[jsTest] 				}
[jsTest] 			},
[jsTest] 			"Global" : {
[jsTest] 				"acquireCount" : {
[jsTest] 					"r" : NumberLong(1),
[jsTest] 					"w" : NumberLong(1)
[jsTest] 				}
[jsTest] 			},
[jsTest] 			"Database" : {
[jsTest] 				"acquireCount" : {
[jsTest] 					"w" : NumberLong(1)
[jsTest] 				}
[jsTest] 			},
[jsTest] 			"Collection" : {
[jsTest] 				"acquireCount" : {
[jsTest] 					"w" : NumberLong(1)
[jsTest] 				}
[jsTest] 			},
[jsTest] 			"Mutex" : {
[jsTest] 				"acquireCount" : {
[jsTest] 					"r" : NumberLong(3)
[jsTest] 				}
[jsTest] 			}
[jsTest] 		},
[jsTest] 		"flowControl" : {
[jsTest] 			"acquireCount" : NumberLong(1)
[jsTest] 		},
[jsTest] 		"readConcern" : {
[jsTest] 			"level" : "local",
[jsTest] 			"provenance" : "implicitDefault"
[jsTest] 		},
[jsTest] 		"storage" : {
[jsTest]
[jsTest] 		},
[jsTest] 		"cpuNanos" : 3021639,
[jsTest] 		"millis" : 3,
[jsTest] 		"planSummary" : "COLLSCAN",
[jsTest] 		"totalOplogSlotDurationMicros" : 155,
[jsTest] 		"execStats" : {
[jsTest] 			"stage" : "UPDATE",
[jsTest] 			"nReturned" : 0,
[jsTest] 			"executionTimeMillisEstimate" : 1,
[jsTest] 			"works" : 2,
[jsTest] 			"advanced" : 0,
[jsTest] 			"needTime" : 1,
[jsTest] 			"needYield" : 0,
[jsTest] 			"saveState" : 0,
[jsTest] 			"restoreState" : 0,
[jsTest] 			"isEOF" : 1,
[jsTest] 			"nMatched" : 1,
[jsTest] 			"nWouldModify" : 1,
[jsTest] 			"nWouldUpsert" : 0,
[jsTest] 			"inputStage" : {
[jsTest] 				"stage" : "COLLSCAN",
[jsTest] 				"nReturned" : 1,
[jsTest] 				"executionTimeMillisEstimate" : 0,
[jsTest] 				"works" : 1,
[jsTest] 				"advanced" : 1,
[jsTest] 				"needTime" : 0,
[jsTest] 				"needYield" : 0,
[jsTest] 				"saveState" : 1,
[jsTest] 				"restoreState" : 1,
[jsTest] 				"isEOF" : 0,
[jsTest] 				"direction" : "forward",
[jsTest] 				"docsExamined" : 1
[jsTest] 			}
[jsTest] 		},
[jsTest] 		"ts" : ISODate("2023-03-03T21:02:28.849Z"),
[jsTest] 		"client" : "127.0.0.1",
[jsTest] 		"appName" : "MongoDB Shell",
[jsTest] 		"allUsers" : [ ],
[jsTest] 		"user" : ""
[jsTest] 	}
[jsTest] ]
[jsTest] ----

--------------------------------------------------------------

Slow query log output (partially reformatted):

{"t":{"$date":"2023-03-02T20:46:28.011+00:00"},
 "s":"I",
 "c":"WRITE",    
 "id":51803,   
 "ctx":"conn1",
 "msg":"Slow query",
 "attr":{
 	"type":"update",
 	"ns":"test.slow_query_oplog_slot_millis",
 	"appName":"MongoDB Shell",
 	"command":{"q":{"$where":"sleep(1000); return true;"},"u":{"updateField":1},"multi":false,"upsert":false,"comment":"updateSomething"},
 	"planSummary":"COLLSCAN",
 	"totalOplogSlotDurationMicrosMicros":356,
 	"keysExamined":0,
 	"docsExamined":1,
 	"nMatched":1,
 	"nModified":1,
 	"nUpserted":0,
 	"keysInserted":0,"keysDeleted":0,"numYields":1,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":2}},"FeatureCompatibilityVersion":{"acquireCount":{"r":4,"w":2}},"ReplicationStateTransition":{"acquireCount":{"w":6}},"Global":{"acquireCount":{"r":4,"w":2}},"Database":{"acquireCount":{"r":2,"w":2}},"Collection":{"acquireCount":{"r":2,"w":2}},"Mutex":{"acquireCount":{"r":5}}},"flowControl":{"acquireCount":2},"readConcern":{"provenance":"implicitDefault"},"storage":{},"cpuNanos":15876131,"remote":"127.0.0.1:54288","durationMillis":1552}
}