[GODRIVER-1037] Driver appears to send killCursors with a cursorId of 0 Created: 10/May/19  Updated: 27/Oct/23  Resolved: 28/Aug/19

Status: Closed
Project: Go Driver
Component/s: CRUD
Affects Version/s: None
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Jeffrey Yemin Assignee: Unassigned
Resolution: Gone away Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related

 Description   

Atlas team found the following in application logs, from traffic generated by the automation agent:

2019-05-10T20:39:24.964+0000 I COMMAND  [conn11] command local.clustermanager appName: "MongoDB Automation Agent v10.1.0.5757 (git: 5725b463e240f3602000dd47e3fe652260e8de71)" command: find { find: "clustermanager", filter: {}, sort: {}, $clusterTime: { clusterTime: Timestamp(1557520763, 1), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "local", $readPreference: { mode: "primaryPreferred" } } planSummary: COLLSCAN keysExamined:0 docsExamined:1 cursorExhausted:1 numYields:0 nreturned:1 reslen:301 locks:{ Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_msg 0ms
 
2019-05-10T20:39:24.965+0000 D COMMAND  [conn11] run command local.$cmd { killCursors: "clustermanager", cursors: [ 0 ], $clusterTime: { clusterTime: Timestamp(1557520763, 1), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "local", $readPreference: { mode: "primaryPreferred" } }
 
2019-05-10T20:39:24.966+0000 I COMMAND  [conn11] command local.clustermanager appName: "MongoDB Automation Agent v10.1.0.5757 (git: 5725b463e240f3602000dd47e3fe652260e8de71)" command: killCursors { killCursors: "clustermanager", cursors: [ 0 ], $clusterTime: { clusterTime: Timestamp(1557520763, 1), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "local", $readPreference: { mode: "primaryPreferred" } } numYields:0 reslen:256 locks:{ Global: { acquireCount: { r: 1 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_msg 0ms

This may indicate a driver bug. Consider that:

  • the find log line indicates cursorExhausted:1, which means the cursorId should come back as 0
  • the killCursors log line indicates cursors: [ 0 ], which if accurate is incorrect. A driver should never send a cursorId of 0 to killCursors, as 0 is the sentinel value indicating that there is no cursor. This is in line with cursorExhausted for the find command just above.


 Comments   
Comment by Alice Thum [ 28/Aug/19 ]

It appears this issue has been fixed at https://github.com/mongodb/mongo-go-driver/blob/master/x/mongo/driver/batch_cursor.go#L217 where KillCursors checks the bc.id for 0.

Comment by Jeffrey Yemin [ 10/May/19 ]

Looking at https://github.com/mongodb/mongo-go-driver/blob/v1.0.1/x/mongo/driver/batch_cursor.go#L203-L207, there doesn't seem to be a check for bc.id == 0 protecting the call to killCursors.

Generated at Thu Feb 08 08:35:32 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.