Uploaded image for project: 'C Driver'
  1. C Driver
  2. CDRIVER-3770

Extra getMore is sent when a tailable cursor receives an empty initial batch

    • Type: Icon: Bug Bug
    • Resolution: Unresolved
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: None
    • Component/s: None
    • Labels:
      None

      Discovered in PHPC-1409. I was able to reproduce this behavior with a test program.

      1. Create a capped collection in the shell and insert a document. (Note, creating a tailable/awaitData to an empty capped collection appears to always return a closed id=0 cursor)

      db.createCollection("capped", {capped: true, size: 10000})
      db.capped.insert({x:1})
      

      2. Create a tailable/awaitData cursor in libmongoc with a filter matching nothing in the capped collection.
      3. Iterate once with mongoc_cursor_next.

      APM events show the extra getMore.

      2020/08/05 13:24:12.0356: [64909]:    DEBUG:       mongoc: begin: first call to mongoc_cursor_next
      2020/08/05 13:24:12.0359: [64909]:    DEBUG:       mongoc: command_started: { "find" : "capped", "filter" : { "match_nothing" : { "$numberInt" : "1" } }, "tailable" : true, "awaitData" : true, "$db" : "test", "$readPreference" : { "mode" : "primaryPreferred" }, "lsid" : { "id" : { "$binary" : { "base64": "ha69vxrBQfqNXR6p70xcYA==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1596648251, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64": "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : { "$numberLong" : "0"} } } }
      2020/08/05 13:24:12.0360: [64909]:    DEBUG:       mongoc: command_succeeded: { "cursor" : { "firstBatch" : [  ], "id" : { "$numberLong" : "171857474237404106"}, "ns" : "test.capped" }, "ok" : { "$numberDouble" : "1.0" }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1596648251, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64": "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : { "$numberLong" : "0"} } }, "operationTime" : { "$timestamp" : { "t" : 1596648251, "i" : 1 } } }
      2020/08/05 13:24:12.0449: [64909]:    DEBUG:       mongoc: command_started: { "getMore" : { "$numberLong" : "171857474237404106"}, "collection" : "capped", "$db" : "test", "$readPreference" : { "mode" : "primaryPreferred" }, "lsid" : { "id" : { "$binary" : { "base64": "ha69vxrBQfqNXR6p70xcYA==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1596648251, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64": "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : { "$numberLong" : "0"} } } }
      2020/08/05 13:24:13.0454: [64909]:    DEBUG:       mongoc: command_succeeded: { "cursor" : { "nextBatch" : [  ], "id" : { "$numberLong" : "171857474237404106"}, "ns" : "test.capped" }, "ok" : { "$numberDouble" : "1.0" }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1596648251, "i" : 1 } }, "signature" : { "hash" : { "$binary" : { "base64": "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType" : "00" } }, "keyId" : { "$numberLong" : "0"} } }, "operationTime" : { "$timestamp" : { "t" : 1596648251, "i" : 1 } } }
      2020/08/05 13:24:13.0454: [64909]:    DEBUG:       mongoc: end: first call to mongoc_cursor_next
      

            Assignee:
            Unassigned Unassigned
            Reporter:
            kevin.albertson@mongodb.com Kevin Albertson
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated: