[CDRIVER-4350] Unskip change stream and cursor tests Created: 11/Apr/22  Updated: 09/Oct/23

Status: Backlog
Project: C Driver
Component/s: None
Affects Version/s: None
Fix Version/s: None

Type: Task Priority: Major - P3
Reporter: Roberto Sanchez Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: failing-on-waterfall, flaky-tests
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
is duplicated by CDRIVER-3689 /BulkOperation/error/unordered failure Closed
Related
is related to CDRIVER-4111 Mock server tests sometimes fail afte... Closed
Epic Link: Stabilize Evergreen

 Description   

The following change stream and cursor tests are skipped due to previously observed test failures:

/change_streams/legacy/change-streams
/change_streams/legacy/change-streams-resume-allowlist
/change_streams/legacy/change-streams-resume-errorLabels
/unified/entity-find-cursor
/change_streams/legacy/change-streams-errors

It will first be necessary to remove them from .evergreen/skip-tests.txt and run a patch build to determine the current failure mode(s).



 Comments   
Comment by Githook User [ 09/Oct/23 ]

Author:

{'name': 'Kevin Albertson', 'email': 'kevin.albertson@mongodb.com', 'username': 'kevinAlbs'}

Message: CDRIVER-4350 unskip mock tests and remove unnecessary skips (#1437)

  • unskip `entity-client-storeEventsAsEntities`

As of https://github.com/mongodb/mongo-c-driver/pull/1220 the `storeEventsAsEntities` operation is supported in the test runner

  • remove `/unified/entity-client-cmap-events` from skip-tests.txt

Test is already skipped in runner.c

  • remove `/unified/entity-client-storeEventsAsEntities` from skip-tests.txt

Test is already skipped in runner.c

  • remove `/unified/assertNumberConnectionsCheckedOut` from skip-tests.txt

Test is already skipped in runner.c
Branch: master
https://github.com/mongodb/mongo-c-driver/commit/4998148f68d6b13748824f9e301cec3ccc2b7d60

Comment by Kevin Albertson [ 09/Oct/23 ]

https://github.com/mongodb/mongo-c-driver/pull/1437 unskips the mock tests.

The following referenced tests are live tests, not mock tests:

/change_streams/legacy/change-streams
/change_streams/legacy/change-streams-resume-allowlist
/change_streams/legacy/change-streams-resume-errorLabels
/unified/assertNumberConnectionsCheckedOut
/unified/entity-client-cmap-events
/unified/entity-client-storeEventsAsEntities
/unified/entity-find-cursor
/change_streams/legacy/change-streams-errors

Unskipping the live tests resulted in observed test failure in /change_streams/legacy/change-streams-resume-allowlist on this patch:

Begin /change_streams/legacy/change-streams-resume-allowlist, seed 4187180327
  - change stream resumes after a network error
{ "aggregate" : "test", "pipeline" : [ { "$changeStream" : {  } } ], "cursor" : {  }, "$db" : "change-stream-tests", "lsid" : { "id" : { "$binary" : { "base64" : "cgpjfZ1KTIq0dl9edQpQYA==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 5 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } } }
2023/10/09 13:38:33.0911: [ 3813]:    DEBUG:       mongoc: <-- COMMAND SUCCEEDED: { "cursor" : { "firstBatch" : [  ], "postBatchResumeToken" : { "_data" : "8265240259000000082B0429296E1404" }, "id" : { "$numberLong" : "4802931758226676921" }, "ns" : "change-stream-tests.test" }, "ok" : { "$numberDouble" : "1.0" }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 7 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } }, "operationTime" : { "$timestamp" : { "t" : 1696858713, "i" : 7 } } }
{ "configureFailPoint" : "failCommand", "mode" : { "times" : { "$numberInt" : "1" } }, "data" : { "failCommands" : [ "getMore" ], "closeConnection" : true }, "$db" : "admin", "lsid" : { "id" : { "$binary" : { "base64" : "rXHkFf13QsOJDGpX78xGWg==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 7 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } } }
2023/10/09 13:38:33.0912: [ 3813]:    DEBUG:       mongoc: <-- COMMAND SUCCEEDED: { "count" : { "$numberInt" : "1" }, "ok" : { "$numberDouble" : "1.0" }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 7 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } }, "operationTime" : { "$timestamp" : { "t" : 1696858713, "i" : 7 } } }
2023/10/09 13:38:33.0912: [ 3813]:    DEBUG:       mongoc:      running operation insertOne : { "database" : "change-stream-tests", "collection" : "test", "name" : "insertOne", "arguments" : { "document" : { "x" : 1 } } }
{ "insert" : "test", "ordered" : true, "$db" : "change-stream-tests", "lsid" : { "id" : { "$binary" : { "base64" : "rXHkFf13QsOJDGpX78xGWg==", "subType" : "04" } } }, "txnNumber" : { "$numberLong" : "1" }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 7 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } }, "documents" : [ { "_id" : { "$oid" : "652402592c1ff5ff4a076e16" }, "x" : { "$numberInt" : "1" } } ] }
2023/10/09 13:38:33.0913: [ 3813]:    DEBUG:       mongoc: <-- COMMAND SUCCEEDED: { "n" : { "$numberInt" : "1" }, "electionId" : { "$oid" : "7fffffff0000000000000002" }, "opTime" : { "ts" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "t" : { "$numberLong" : "2" } }, "ok" : { "$numberDouble" : "1.0" }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } }, "operationTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } } }
{ "getMore" : { "$numberLong" : "4802931758226676921" }, "collection" : "test", "maxTimeMS" : { "$numberLong" : "1000" }, "$db" : "change-stream-tests", "lsid" : { "id" : { "$binary" : { "base64" : "cgpjfZ1KTIq0dl9edQpQYA==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } } }
2023/10/09 13:38:33.0913: [ 3813]:    DEBUG:      cluster: could not read message length, stream probably closed or timed out
2023/10/09 13:38:33.0913: [ 3813]:    DEBUG:       mongoc: <-- getMore COMMAND FAILED: Failed to send "getMore" command with database "change-stream-tests": Failed to read 4 bytes: socket error or timeout
REPLY: { }
{ "aggregate" : "test", "pipeline" : [ { "$changeStream" : { "resumeAfter" : { "_data" : "8265240259000000082B0429296E1404" } } } ], "cursor" : {  }, "$db" : "change-stream-tests", "lsid" : { "id" : { "$binary" : { "base64" : "cgpjfZ1KTIq0dl9edQpQYA==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } } }
2023/10/09 13:38:33.0944: [ 3813]:    DEBUG:       mongoc: <-- COMMAND SUCCEEDED: { "cursor" : { "firstBatch" : [  ], "postBatchResumeToken" : { "_data" : "8265240259000000082B0429296E1404" }, "id" : { "$numberLong" : "7573447869255482329" }, "ns" : "change-stream-tests.test" }, "ok" : { "$numberDouble" : "1.0" }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } }, "operationTime" : { "$timestamp" : { "t" : 1696858713, "i" : 7 } } }
{ "getMore" : { "$numberLong" : "7573447869255482329" }, "collection" : "test", "maxTimeMS" : { "$numberLong" : "1000" }, "$db" : "change-stream-tests", "lsid" : { "id" : { "$binary" : { "base64" : "cgpjfZ1KTIq0dl9edQpQYA==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } } }
2023/10/09 13:38:34.0005: [ 3813]:    DEBUG:       mongoc: <-- COMMAND SUCCEEDED: { "cursor" : { "nextBatch" : [ { "_id" : { "_data" : "8265240259000000082B042C0100296E5A10043A3C2877294849419B53B7CC89C0BF91463C6F7065726174696F6E54797065003C696E736572740046646F63756D656E744B65790046645F69640064652402592C1FF5FF4A076E16000004" }, "operationType" : "insert", "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "wallTime" : { "$date" : { "$numberLong" : "1696858713913" } }, "fullDocument" : { "_id" : { "$oid" : "652402592c1ff5ff4a076e16" }, "x" : { "$numberInt" : "1" } }, "ns" : { "db" : "change-stream-tests", "coll" : "test" }, "documentKey" : { "_id" : { "$oid" : "652402592c1ff5ff4a076e16" } } } ], "postBatchResumeToken" : { "_data" : "8265240259000000082B042C0100296E5A10043A3C2877294849419B53B7CC89C0BF91463C6F7065726174696F6E54797065003C696E736572740046646F63756D656E744B65790046645F69640064652402592C1FF5FF4A076E16000004" }, "id" : { "$numberLong" : "7573447869255482329" }, "ns" : "change-stream-tests.test" }, "ok" : { "$numberDouble" : "1.0" }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } }, "operationTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } } }
{ "killCursors" : "test", "cursors" : [ { "$numberLong" : "7573447869255482329" } ], "$db" : "change-stream-tests", "lsid" : { "id" : { "$binary" : { "base64" : "cgpjfZ1KTIq0dl9edQpQYA==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } } }
2023/10/09 13:38:34.0005: [ 3813]:    DEBUG:       mongoc: <-- COMMAND SUCCEEDED: { "cursorsKilled" : [ { "$numberLong" : "7573447869255482329" } ], "cursorsNotFound" : [  ], "cursorsAlive" : [  ], "cursorsUnknown" : [  ], "ok" : { "$numberDouble" : "1.0" }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } }, "operationTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } } }
Error in APM matching
Full list of captured events: { "0" : { "command_started_event" : { "command" : { "aggregate" : "test", "pipeline" : [ { "$changeStream" : {  } } ], "cursor" : {  }, "$db" : "change-stream-tests", "lsid" : { "id" : { "$binary" : { "base64" : "cgpjfZ1KTIq0dl9edQpQYA==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 5 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } } }, "command_name" : "aggregate", "database_name" : "change-stream-tests", "operation_id" : { "$numberLong" : "1948558153" } } }, "1" : { "command_started_event" : { "command" : { "configureFailPoint" : "failCommand", "mode" : { "times" : { "$numberInt" : "1" } }, "data" : { "failCommands" : [ "getMore" ], "closeConnection" : true }, "$db" : "admin", "lsid" : { "id" : { "$binary" : { "base64" : "rXHkFf13QsOJDGpX78xGWg==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 7 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } } }, "command_name" : "configureFailPoint", "database_name" : "admin", "operation_id" : { "$numberLong" : "1948558154" } } }, "2" : { "command_started_event" : { "command" : { "insert" : "test", "ordered" : true, "$db" : "change-stream-tests", "lsid" : { "id" : { "$binary" : { "base64" : "rXHkFf13QsOJDGpX78xGWg==", "subType" : "04" } } }, "txnNumber" : { "$numberLong" : "1" }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 7 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } }, "documents" : [ { "_id" : { "$oid" : "652402592c1ff5ff4a076e16" }, "x" : { "$numberInt" : "1" } } ] }, "command_name" : "insert", "database_name" : "change-stream-tests", "operation_id" : { "$numberLong" : "1948558155" } } }, "3" : { "command_started_event" : { "command" : { "getMore" : { "$numberLong" : "4802931758226676921" }, "collection" : "test", "maxTimeMS" : { "$numberLong" : "1000" }, "$db" : "change-stream-tests", "lsid" : { "id" : { "$binary" : { "base64" : "cgpjfZ1KTIq0dl9edQpQYA==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } } }, "command_name" : "getMore", "database_name" : "change-stream-tests", "operation_id" : { "$numberLong" : "0" } } }, "4" : { "command_started_event" : { "command" : { "aggregate" : "test", "pipeline" : [ { "$changeStream" : { "resumeAfter" : { "_data" : "8265240259000000082B0429296E1404" } } } ], "cursor" : {  }, "$db" : "change-stream-tests", "lsid" : { "id" : { "$binary" : { "base64" : "cgpjfZ1KTIq0dl9edQpQYA==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } } }, "command_name" : "aggregate", "database_name" : "change-stream-tests", "operation_id" : { "$numberLong" : "1948558156" } } }, "5" : { "command_started_event" : { "command" : { "getMore" : { "$numberLong" : "7573447869255482329" }, "collection" : "test", "maxTimeMS" : { "$numberLong" : "1000" }, "$db" : "change-stream-tests", "lsid" : { "id" : { "$binary" : { "base64" : "cgpjfZ1KTIq0dl9edQpQYA==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } } }, "command_name" : "getMore", "database_name" : "change-stream-tests", "operation_id" : { "$numberLong" : "0" } } }, "6" : { "command_started_event" : { "command" : { "killCursors" : "test", "cursors" : [ { "$numberLong" : "7573447869255482329" } ], "$db" : "change-stream-tests", "lsid" : { "id" : { "$binary" : { "base64" : "cgpjfZ1KTIq0dl9edQpQYA==", "subType" : "04" } } }, "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1696858713, "i" : 8 } }, "signature" : { "hash" : { "$binary" : { "base64" : "vxzANUaF4hNIsgdk5bQeDqQe0d8=", "subType" : "00" } }, "keyId" : { "$numberLong" : "7287952437749481477" } } } }, "command_name" : "killCursors", "database_name" : "change-stream-tests", "operation_id" : { "$numberLong" : "1948558157" } } } }
Full list of expectations: { "0" : { "command_started_event" : { "command" : { "aggregate" : "test", "cursor" : {  }, "pipeline" : [ { "$changeStream" : {  } } ] }, "command_name" : "aggregate", "database_name" : "change-stream-tests" } }, "1" : { "command_started_event" : { "command" : { "getMore" : { "$numberInt" : "42" }, "collection" : "test" }, "command_name" : "getMore", "database_name" : "change-stream-tests" } }, "2" : { "command_started_event" : { "command" : { "aggregate" : "test", "cursor" : {  }, "pipeline" : [ { "$changeStream" : {  } } ] }, "command_name" : "aggregate", "database_name" : "change-stream-tests" } } }test error in: /data/mci/b937c30ba90cd52a355dc3fa34a5fb78/mongoc/src/libmongoc/tests/json-test-monitoring.c 606:check_json_apm_events()
expectation unmatched
	expected: { "command_started_event" : { "command" : { "aggregate" : "test", "cursor" : {  }, "pipeline" : [ { "$changeStream" : {  } } ] }, "command_name" : "aggregate", "database_name" : "change-stream-tests" } }

Updating ticket title to "Unskip change stream and cursor tests". Updating description to reference remaining skipped tests. Leaving in "Backlog".

Generated at Wed Feb 07 21:20:40 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.