"errCode":279, errName":"ClientDisconnect",

MongoDB Atlas
1

Why it is happened in Atlas Cloud

when we received alert CPU usage gone above 80% in Mongod.logs we are found the below error

"ok":0,"errMsg":"Error in $cursor stage :: caused by :: operation was interrupted because a client disconnected","errName":"ClientDisconnect",

"errCode":279, ?


{"t":{"$date":"2023-09-20T11:48:21.945+00:00"},"s":"I", "c":"COMMAND", "id":518,

"ctx":"conn1990250","msg":"Slow query","attr":{"type":"command","ns":"BPO.customer",
"command":{"aggregate":"test","pipeline":[{"$match":{"$and":[{"status":"Open"},{"appDateTime":{"$gte":{"$date":"2023-09-20T11:48:13.031Z"}}},
{"appDateTime":{"$lt":{"$date":"2023-10-20T11:48:13.031Z"}}}]}},{"$group":{"_id":"$storeNumber","totalSlotCount":{"$sum":1},"minSlotDate":
{"$min":"$appDateTime"}}}],"cursor":{},"allowDiskUse":false,"$db":"RAVaccineSchedulerPRODDB","lsid":{"id"{"$uuid":"807d5eb6-4067-4051-a89b-38f06aa1bd86"}}},
"planSummary":"IXSCAN { status: 1, appTime: 1, reservedTime: 1 }",
"numYields":1725,"queryHash":"E2C2E097","planCacheKey":"6DD10207",
"ok":0,"errMsg":"Error in $cursor stage :: caused by :: operation was interrupted because a client disconnected","errName":"ClientDisconnect",
"errCode":279,"reslen":311,"locks":{"FeatureCompatibilityVersion":{"acquireCount":{"r":1782}},"ReplicationStateTransition":{"acquireCount":{"w":1782}},
"Global":{"acquireCount":{"r":1782}},"Database":{"acquireCount":{"r":1781}},"Collection":{"acquireCount":{"r":1781}},"Mutex":{"acquireCount":{"r":57}}},
"protocol":"op_msg","durationMillis":8050}}
2

Hey @hari_dba,

Welcome to the MongoDB Community!

I suspect this is happening due to the client getting disconnected, so if the issuing client disconnects before the operation completes, MongoDB marks the following operations for termination. To read more please refer to the documentation.

Also, refer to the FAQ - What Happens to Running Operations If the Client Disconnects?.

Could you please see the logs that show what happened on the client or application side? It will give you insights into the specific events around this issue.

Regards,
Kushagra

3

same error we are got again

Can you fix the issue ?

Why the lock was accquired time out what is reason ?

how do we fing which query was lock happened ?
,“msg”:“Failed to gather storage statistics for slow operation”,
“attr”:{“opId”:529542,“error”:“lock acquire timeout”}}

{“t”:{“$date”:“2023-09-27T16:41:43.626+00:00”},“s”:“I”, “c”:“NETWORK”, “id”:5180,
“ctx”:“conn25883”,“msg”:“client metadata”,“attr”:{“remote”:“193.168.249.52:52970”,
“client”:“conn25883”,“doc”:{“driver”:{“name”:“mongo-java-driver|sync|spring-boot”,“version”:“4.6.1”},
“os”:{“type”:“Linux”,“name”:“Linux”,“architecture”:“amd64”,“version”:“5.10.184-175.731.amzn2.x86_64”},
“platform”:“Java/Oracle Corporation/1.8.0_342-b07”}}}

{“t”:{“$date”:“2023-09-27T16:41:43.626+00:00”},“s”:“I”, “c”:“ACCESS”, “id”:2024,
“ctx”:“conn25883”,“msg”:“Authentication failed”,“attr”:{“mechanism”:“SCRAM-SHA-256”,“speculative”:true,“principalName”:“user”,
“authenticationDatabase”:“admin”,“remote”:“193.168.249.52:52970”,“extraInfo”:{},“error”:“BadValue: SCRAM-SHA-256 authentication is disabled”}}

{“t”:{“$date”:“2023-09-27T16:41:43.693+00:00”},“s”:“I”, “c”:“ACCESS”, “id”:202,
“ctx”:“conn25883”,“msg”:“Authentication succeeded”,“attr”:{“mechanism”:“SCRAM-SHA-1”,“speculative”:false,“principalName”:“user”,
“authenticationDatabase”:“admin”,“remote”:“193.168.249.52:52970”,“extraInfo”:{}}}

{“t”:{“$date”:“2023-09-27T16:41:49.800+00:00”},“s”:“I”, “c”:“-”,
“id”:20883, “ctx”:“conn2588325”,“msg”:“Interrupted operation as its client disconnected”,“attr”:{“opId”:529542}}

{“t”:{“$date”:“2023-09-27T16:41:49.808+00:00”},“s”:“W”,
“c”:“COMMAND”, “id”:20525, “ctx”:“conn25883”,“msg”:“Failed to gather storage statistics for slow operation”,
“attr”:{“opId”:529542,“error”:“lock acquire timeout”}}

{“t”:{“$date”:“2023-09-27T16:41:49.808+00:00”},“s”:“I”, “c”:“COMMAND”, “id”:518,
“ctx”:“conn25883”,“msg”:“Slow query”,“attr”:{“type”:“command”,“ns”:“test:sample”,
“command”:{“aggregate”:“Appointment”,“pipeline”:[{“$match”:{“$and”:[{“status”:“Open”},{“DateTime”:{“$gte”:{“$date”:“2023-09-27T16:41:42.853Z”}}},
{“DateTime”:{“$lt”:{“$date”:“2023-10-27T16:41:42.854Z”}}}]}},{“$group”:{“_id”:“$storeNumber”,“totalSlotCount”:{“$sum”:1},
“minSlotDate”:{“$min”:“$appDateTime”}}}],“cursor”:{},
“allowDiskUse”:false,“$db”:“test”,“lsid”:{“id”:
{“$uuid”:“057da301-5b71-43a4-a102-db2a8a354050”}}},“planSummary”:“IXSCAN { status: 1, DateTime: 1, Time: 1 }”,"
numYields":1261,“queryHash”:“E2C2E097”,“planCacheKey”:“6DD10207”,"
ok":0,“errMsg”:“Error in $cursor stage :: caused by :: operation was interrupted because a client disconnected”,
“errName”:“ClientDisconnect”,“errCode”:279,“reslen”:311,“locks”:{“FeatureCompatibilityVersion”:{“acquireCount”:{“r”:1303}},
“ReplicationStateTransition”:{“acquireCount”:{“w”:1303}},“Global”:{“acquireCount”:{“r”:1303}},“Database”:{“acquireCount”:{“r”:1303}},
“Collection”:{“acquireCount”:{“r”:1303}},
“Mutex”:{“acquireCount”:{“r”:42}}},“protocol”:“op_msg”,“durationMillis”:6035}}

{“t”:{“$date”:“2023-09-27T16:41:49.809+00:00”},“s”:“I”,
“c”:“NETWORK”, “id”:22944, “ctx”:“conn25883”,“msg”:“Connection ended”,"
attr":{“remote”:“193.168.249.52:52970”,“connectionId”:25883,“connectionCount”:279}}