-
Type:
Bug
-
Resolution: Fixed
-
Priority:
Major - P3
-
Affects Version/s: None
-
Component/s: None
-
None
-
RSS Sydney
-
Fully Compatible
-
ALL
-
GregsList - 2024-09-03, PopcornChicken - 2024-09-17, MorningKaraoke 2024-10-01
Upon investigating the linked HELP ticket, we found a bug in our capped collection diagnostics where key deletions aren't being reported in the slow query logs.
Here is a current example log for a capped insert:
{"t":\{"$date":"2024-07-04T02:15:12.105+00:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn1","msg":"Slow query","attr":\{"type":"command","isFromUserConnection":true,"ns":"test.testy","collectionType":"normal","appName":"MongoDB Shell","command":{"insert":"testy","ordered":true,"lsid":{"id":{"$uuid":"e60ddcef-f159-478d-9fe0-44840266de90"}},"$db":"test"},"ninserted":1,"keysInserted":1,"numYields":0,"reslen":45,"locks":\{"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":\{"acquireCount":{"w":1}},"Database":\{"acquireCount":{"w":1}},"Collection":\{"acquireCount":{"w":1}},"Metadata":\{"acquireCount":{"W":1}}},"flowControl":\{"acquireCount":1},"storage":\{"data":{"txnBytesDirty":351}},"cpuNanos":1812928,"remote":"127.0.0.1:45234","protocol":"op_msg","queues":\{"execution":{"admissions":2,"totalTimeQueuedMicros":0},"ingress":\{"admissions":1,"totalTimeQueuedMicros":0}},"workingMillis":1,"durationMillis":1}}
Attached is a diff (`cappedCollectionsLogging.diff`) that contains a fix that will accurately increment the number of deleted keys in capped collections to look something like below (note nDeleted and keysDeleted):
{"t":{"$date":"2024-07-04T02:35:36.140+00:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn1","msg":"Slow query","attr":{"type":"command","isFromUserConnection":true,"ns":"test.testy","collectionType":"normal","appName":"MongoDB Shell","command":{"insert":"testy","ordered":true,"lsid":{"id":{"$uuid":"57f62d14-0379-4a20-a191-1c0538a36841"}},"$db":"test"},"ninserted":1,"ndeleted":1,"keysInserted":1,"keysDeleted":1,"numYields":0,"reslen":45,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Metadata":{"acquireCount":{"W":1}}},"flowControl":{"acquireCount":1},"storage":{"data":{"txnBytesDirty":359}},"cpuNanos":1870209,"remote":"127.0.0.1:55092","protocol":"op_msg","queues":{"ingress":{"admissions":1,"totalTimeQueuedMicros":0},"execution":{"admissions":2,"totalTimeQueuedMicros":0}},"workingMillis":1,"durationMillis":1}}