From e4aa2b32a8301e28bf0ba6ae0743e595113bb3d0 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Tue, 14 Jan 2025 10:04:59 -0700 Subject: [PATCH 01/20] DRIVERS-2868 Guard server round trips from timeout --- internal/driverutil/operation.go | 39 ++ .../unified/collection_operation_execution.go | 17 + .../unified/cursor_operation_execution.go | 7 + .../unified/unified_spec_runner.go | 20 +- .../tailable-awaitData.json | 463 ++++++++++++++++++ .../tailable-awaitData.yml | 280 +++++++++++ x/mongo/driver/batch_cursor.go | 29 +- x/mongo/driver/operation.go | 30 +- x/mongo/driver/topology/connection.go | 2 + 9 files changed, 849 insertions(+), 38 deletions(-) create mode 100644 testdata/client-side-operations-timeout/tailable-awaitData.json create mode 100644 testdata/client-side-operations-timeout/tailable-awaitData.yml diff --git a/internal/driverutil/operation.go b/internal/driverutil/operation.go index 32704312ff..587c361d6e 100644 --- a/internal/driverutil/operation.go +++ b/internal/driverutil/operation.go @@ -6,6 +6,13 @@ package driverutil +import ( + "context" + "fmt" + "math" + "time" +) + // Operation Names should be sourced from the command reference documentation: // https://www.mongodb.com/docs/manual/reference/command/ const ( @@ -29,3 +36,35 @@ const ( ListDatabasesOp = "listDatabases" // ListDatabasesOp is the name for listing databases UpdateOp = "update" // UpdateOp is the name for updating ) + +func CalculateMaxTimeMS(ctx context.Context, rttMin time.Duration, rttStats string, err error) (int64, error) { + deadline, ok := ctx.Deadline() + if !ok { + return 0, nil + } + + remainingTimeout := time.Until(deadline) + + // Always round up to the next millisecond value so we never truncate the calculated + // maxTimeMS value (e.g. 400 microseconds evaluates to 1ms, not 0ms). + maxTimeMS := int64((remainingTimeout - rttMin + time.Millisecond - 1) / time.Millisecond) + if maxTimeMS <= 0 { + return 0, fmt.Errorf( + "remaining time %v until context deadline is less than or equal to min network round-trip time %v (%v): %w", + remainingTimeout, + rttMin, + rttStats, + err) + } + + // The server will return a "BadValue" error if maxTimeMS is greater + // than the maximum positive int32 value (about 24.9 days). If the + // user specified a timeout value greater than that, omit maxTimeMS + // and let the client-side timeout handle cancelling the op if the + // timeout is ever reached. + if maxTimeMS > math.MaxInt32 { + return 0, nil + } + + return maxTimeMS, nil +} diff --git a/internal/integration/unified/collection_operation_execution.go b/internal/integration/unified/collection_operation_execution.go index 6c8b38145a..8f2866f527 100644 --- a/internal/integration/unified/collection_operation_execution.go +++ b/internal/integration/unified/collection_operation_execution.go @@ -10,6 +10,7 @@ import ( "context" "errors" "fmt" + "strings" "time" "go.mongodb.org/mongo-driver/v2/bson" @@ -1485,6 +1486,22 @@ func createFindCursor(ctx context.Context, operation *operation) (*cursorResult, opts.SetSkip(int64(val.Int32())) case "sort": opts.SetSort(val.Document()) + case "timeoutMode": + return nil, newSkipTestError(fmt.Sprintf("timeoutMode is not supported")) + case "cursorType": + fmt.Println("cursorType check", val.String(), strings.ToLower(val.String()), val.String() == "tailableAwait") + switch strings.ToLower(val.StringValue()) { + case "tailable": + opts.SetCursorType(options.Tailable) + case "tailableawait": + fmt.Println("gottem") + opts.SetCursorType(options.TailableAwait) + case "nontailable": + opts.SetCursorType(options.NonTailable) + } + case "maxAwaitTimeMS": + maxAwaitTimeMS := time.Duration(val.Int32()) * time.Millisecond + opts.SetMaxAwaitTime(maxAwaitTimeMS) default: return nil, fmt.Errorf("unrecognized find option %q", key) } diff --git a/internal/integration/unified/cursor_operation_execution.go b/internal/integration/unified/cursor_operation_execution.go index 894bb87ce3..d35503b5be 100644 --- a/internal/integration/unified/cursor_operation_execution.go +++ b/internal/integration/unified/cursor_operation_execution.go @@ -19,17 +19,24 @@ func executeIterateOnce(ctx context.Context, operation *operation) (*operationRe return nil, err } + fmt.Println("iterate once") + // TryNext will attempt to get the next document, potentially issuing a single 'getMore'. if cursor.TryNext(ctx) { // We don't expect the server to return malformed documents, so any errors from Decode here are treated // as fatal. var res bson.Raw if err := cursor.Decode(&res); err != nil { + fmt.Println("err:", err) return nil, fmt.Errorf("error decoding cursor result: %w", err) } + fmt.Println("err:", cursor.Err()) + return newDocumentResult(res, nil), nil } + + fmt.Println("err:", cursor.Err()) return newErrorResult(cursor.Err()), nil } diff --git a/internal/integration/unified/unified_spec_runner.go b/internal/integration/unified/unified_spec_runner.go index 2ca3f27fbd..59e4bf2fff 100644 --- a/internal/integration/unified/unified_spec_runner.go +++ b/internal/integration/unified/unified_spec_runner.go @@ -78,6 +78,10 @@ var ( "operation is retried multiple times for non-zero timeoutMS - aggregate on collection": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", "operation is retried multiple times for non-zero timeoutMS - aggregate on database": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", "timeoutMS applied to find command": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", + "timeoutMS applied to find": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", + "timeoutMS is refreshed for getMore if maxAwaitTimeMS is not set": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", + "timeoutMS is refreshed for getMore if maxAwaitTimeMS is set": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", + "timeoutMS is refreshed for getMore - failure": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", // DRIVERS-2953: This test requires that the driver sends a "getMore" // with "maxTimeMS" set. However, "getMore" can only include "maxTimeMS" @@ -178,14 +182,14 @@ func runTestFile(t *testing.T, filepath string, expectValidFail bool, opts ...*O mt.Skip("Skipping CSOT spec test because SKIP_CSOT_TESTS=true") } - defer func() { - // catch panics from looking up elements and fail if it's unexpected - if r := recover(); r != nil { - if !expectValidFail { - mt.Fatal(r) - } - } - }() + //defer func() { + // // catch panics from looking up elements and fail if it's unexpected + // if r := recover(); r != nil { + // if !expectValidFail { + // mt.Fatal(r) + // } + // } + //}() err := testCase.Run(mt) if expectValidFail { if err != nil { diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.json b/testdata/client-side-operations-timeout/tailable-awaitData.json new file mode 100644 index 0000000000..e56f8f5ea4 --- /dev/null +++ b/testdata/client-side-operations-timeout/tailable-awaitData.json @@ -0,0 +1,463 @@ +{ + "description": "timeoutMS behaves correctly for tailable awaitData cursors", + "schemaVersion": "1.9", + "runOnRequirements": [ + { + "minServerVersion": "4.4" + } + ], + "createEntities": [ + { + "client": { + "id": "failPointClient", + "useMultipleMongoses": false + } + }, + { + "client": { + "id": "client", + "uriOptions": { + "heartbeatFrequencyMS": 500, + "timeoutMS": 200 + }, + "useMultipleMongoses": false, + "observeEvents": [ + "commandStartedEvent" + ] + } + }, + { + "database": { + "id": "database", + "client": "client", + "databaseName": "test" + } + }, + { + "collection": { + "id": "collection", + "database": "database", + "collectionName": "coll" + } + } + ], + "initialData": [ + { + "collectionName": "coll", + "databaseName": "test", + "createOptions": { + "capped": true, + "size": 500 + }, + "documents": [ + { + "_id": 0 + }, + { + "_id": 1 + } + ] + } + ], + "tests": [ + { + "description": "error if timeoutMode is cursor_lifetime", + "operations": [ + { + "name": "find", + "object": "collection", + "arguments": { + "filter": {}, + "timeoutMode": "cursorLifetime", + "cursorType": "tailableAwait" + }, + "expectError": { + "isClientError": true + } + } + ] + }, + { + "description": "error if maxAwaitTimeMS is greater than timeoutMS", + "operations": [ + { + "name": "find", + "object": "collection", + "arguments": { + "filter": {}, + "cursorType": "tailableAwait", + "timeoutMS": 5, + "maxAwaitTimeMS": 10 + }, + "expectError": { + "isClientError": true + } + } + ] + }, + { + "description": "error if maxAwaitTimeMS is equal to timeoutMS", + "operations": [ + { + "name": "find", + "object": "collection", + "arguments": { + "filter": {}, + "cursorType": "tailableAwait", + "timeoutMS": 5, + "maxAwaitTimeMS": 5 + }, + "expectError": { + "isClientError": true + } + } + ] + }, + { + "description": "some test for us", + "operations": [ + { + "name": "wait", + "object": "testRunner", + "arguments": { + "ms": 750 + } + }, + { + "name": "createFindCursor", + "object": "collection", + "arguments": { + "filter": {}, + "cursorType": "tailableAwait", + "batchSize": 1, + "maxAwaitTimeMS": 10 + }, + "saveResultAsEntity": "tailableCursor" + }, + { + "name": "iterateOnce", + "object": "tailableCursor", + "arguments": { + "timeoutMS": 11 + } + }, + { + "name": "iterateOnce", + "object": "tailableCursor", + "arguments": { + "timeoutMS": 11 + }, + "expectError": { + "isTimeoutError": false + } + } + ] + }, + { + "description": "timeoutMS applied to find", + "operations": [ + { + "name": "failPoint", + "object": "testRunner", + "arguments": { + "client": "failPointClient", + "failPoint": { + "configureFailPoint": "failCommand", + "mode": { + "times": 1 + }, + "data": { + "failCommands": [ + "find" + ], + "blockConnection": true, + "blockTimeMS": 300 + } + } + } + }, + { + "name": "find", + "object": "collection", + "arguments": { + "filter": {}, + "cursorType": "tailableAwait" + }, + "expectError": { + "isTimeoutError": true + } + } + ], + "expectEvents": [ + { + "client": "client", + "events": [ + { + "commandStartedEvent": { + "commandName": "find", + "databaseName": "test", + "command": { + "find": "coll", + "tailable": true, + "awaitData": true, + "maxTimeMS": { + "$$exists": true + } + } + } + } + ] + } + ] + }, + { + "description": "timeoutMS is refreshed for getMore if maxAwaitTimeMS is not set", + "operations": [ + { + "name": "failPoint", + "object": "testRunner", + "arguments": { + "client": "failPointClient", + "failPoint": { + "configureFailPoint": "failCommand", + "mode": { + "times": 2 + }, + "data": { + "failCommands": [ + "find", + "getMore" + ], + "blockConnection": true, + "blockTimeMS": 150 + } + } + } + }, + { + "name": "createFindCursor", + "object": "collection", + "arguments": { + "filter": {}, + "cursorType": "tailableAwait", + "timeoutMS": 250, + "batchSize": 1 + }, + "saveResultAsEntity": "tailableCursor" + }, + { + "name": "iterateUntilDocumentOrError", + "object": "tailableCursor" + }, + { + "name": "iterateUntilDocumentOrError", + "object": "tailableCursor" + } + ], + "expectEvents": [ + { + "client": "client", + "events": [ + { + "commandStartedEvent": { + "commandName": "find", + "databaseName": "test", + "command": { + "find": "coll", + "tailable": true, + "awaitData": true, + "maxTimeMS": { + "$$exists": true + } + } + } + }, + { + "commandStartedEvent": { + "commandName": "getMore", + "databaseName": "test", + "command": { + "getMore": { + "$$type": [ + "int", + "long" + ] + }, + "collection": "coll", + "maxTimeMS": { + "$$exists": false + } + } + } + } + ] + } + ] + }, + { + "description": "timeoutMS is refreshed for getMore if maxAwaitTimeMS is set", + "operations": [ + { + "name": "failPoint", + "object": "testRunner", + "arguments": { + "client": "failPointClient", + "failPoint": { + "configureFailPoint": "failCommand", + "mode": { + "times": 2 + }, + "data": { + "failCommands": [ + "find", + "getMore" + ], + "blockConnection": true, + "blockTimeMS": 150 + } + } + } + }, + { + "name": "createFindCursor", + "object": "collection", + "arguments": { + "filter": {}, + "cursorType": "tailableAwait", + "timeoutMS": 250, + "batchSize": 1, + "maxAwaitTimeMS": 1 + }, + "saveResultAsEntity": "tailableCursor" + }, + { + "name": "iterateUntilDocumentOrError", + "object": "tailableCursor" + }, + { + "name": "iterateUntilDocumentOrError", + "object": "tailableCursor" + } + ], + "expectEvents": [ + { + "client": "client", + "events": [ + { + "commandStartedEvent": { + "commandName": "find", + "databaseName": "test", + "command": { + "find": "coll", + "tailable": true, + "awaitData": true, + "maxTimeMS": { + "$$exists": true + } + } + } + }, + { + "commandStartedEvent": { + "commandName": "getMore", + "databaseName": "test", + "command": { + "getMore": { + "$$type": [ + "int", + "long" + ] + }, + "collection": "coll", + "maxTimeMS": 1 + } + } + } + ] + } + ] + }, + { + "description": "timeoutMS is refreshed for getMore - failure", + "operations": [ + { + "name": "failPoint", + "object": "testRunner", + "arguments": { + "client": "failPointClient", + "failPoint": { + "configureFailPoint": "failCommand", + "mode": { + "times": 1 + }, + "data": { + "failCommands": [ + "getMore" + ], + "blockConnection": true, + "blockTimeMS": 250 + } + } + } + }, + { + "name": "createFindCursor", + "object": "collection", + "arguments": { + "filter": {}, + "cursorType": "tailableAwait", + "batchSize": 1 + }, + "saveResultAsEntity": "tailableCursor" + }, + { + "name": "iterateUntilDocumentOrError", + "object": "tailableCursor" + }, + { + "name": "iterateUntilDocumentOrError", + "object": "tailableCursor", + "expectError": { + "isTimeoutError": true + } + } + ], + "expectEvents": [ + { + "client": "client", + "events": [ + { + "commandStartedEvent": { + "commandName": "find", + "databaseName": "test", + "command": { + "find": "coll", + "tailable": true, + "awaitData": true, + "maxTimeMS": { + "$$exists": true + } + } + } + }, + { + "commandStartedEvent": { + "commandName": "getMore", + "databaseName": "test", + "command": { + "getMore": { + "$$type": [ + "int", + "long" + ] + }, + "collection": "coll" + } + } + } + ] + } + ] + } + ] +} diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.yml b/testdata/client-side-operations-timeout/tailable-awaitData.yml new file mode 100644 index 0000000000..544f9db29d --- /dev/null +++ b/testdata/client-side-operations-timeout/tailable-awaitData.yml @@ -0,0 +1,280 @@ +description: "timeoutMS behaves correctly for tailable awaitData cursors" + +schemaVersion: "1.9" + +runOnRequirements: + - minServerVersion: "4.4" + +createEntities: + - client: + id: &failPointClient failPointClient + useMultipleMongoses: false + - client: + id: &client client + uriOptions: + # Use a high heartbeatFrequencyMS to ensure, when needed, the RTT + # monitor has enough samples to produce a minRTT. + heartbeatFrequencyMS: 500 + timeoutMS: 200 + useMultipleMongoses: false + observeEvents: + - commandStartedEvent + - database: + id: &database database + client: *client + databaseName: &databaseName test + - collection: + id: &collection collection + database: *database + collectionName: &collectionName coll + +initialData: + - collectionName: *collectionName + databaseName: *databaseName + createOptions: + capped: true + size: 500 + documents: + - { _id: 0 } + - { _id: 1 } + +tests: + - description: "error if timeoutMode is cursor_lifetime" + operations: + - name: find + object: *collection + arguments: + filter: {} + timeoutMode: cursorLifetime + cursorType: tailableAwait + expectError: + isClientError: true + + - description: "error if maxAwaitTimeMS is greater than timeoutMS" + operations: + - name: find + object: *collection + arguments: + filter: {} + cursorType: tailableAwait + timeoutMS: 5 + maxAwaitTimeMS: 10 + expectError: + isClientError: true + + - description: "error if maxAwaitTimeMS is equal to timeoutMS" + operations: + - name: find + object: *collection + arguments: + filter: {} + cursorType: tailableAwait + timeoutMS: 5 + maxAwaitTimeMS: 5 + expectError: + isClientError: true + + - description: "some test for us" + operations: + # Wait for enough samples to be added to the RTT Monitor to ensure a + # minimum RTT is available. + - name: wait + object: testRunner + arguments: + ms: 750 + - name: createFindCursor + object: *collection + arguments: + filter: {} + cursorType: tailableAwait + batchSize: 1 + maxAwaitTimeMS: 10 + saveResultAsEntity: &tailableCursor tailableCursor + # Iterate twice to force a getMore. + - name: iterateOnce + object: *tailableCursor + arguments: + timeoutMS: 11 + # ms: 1 + # timeoutMS: 11 + - name: iterateOnce + object: *tailableCursor + arguments: + timeoutMS: 11 + expectError: + isTimeoutError: false + + - description: "timeoutMS applied to find" + operations: + - name: failPoint + object: testRunner + arguments: + client: *failPointClient + failPoint: + configureFailPoint: failCommand + mode: { times: 1 } + data: + failCommands: ["find"] + blockConnection: true + blockTimeMS: 300 + - name: find + object: *collection + arguments: + filter: {} + cursorType: tailableAwait + expectError: + isTimeoutError: true + expectEvents: + - client: *client + events: + - commandStartedEvent: + commandName: find + databaseName: *databaseName + command: + find: *collectionName + tailable: true + awaitData: true + maxTimeMS: { $$exists: true } + + # If maxAwaitTimeMS is not set, timeoutMS should be refreshed for the getMore and the getMore should not have a + # maxTimeMS field. + - description: "timeoutMS is refreshed for getMore if maxAwaitTimeMS is not set" + operations: + - name: failPoint + object: testRunner + arguments: + client: *failPointClient + failPoint: + configureFailPoint: failCommand + mode: { times: 2 } + data: + failCommands: ["find", "getMore"] + blockConnection: true + blockTimeMS: 150 + - name: createFindCursor + object: *collection + arguments: + filter: {} + cursorType: tailableAwait + timeoutMS: 250 + batchSize: 1 + saveResultAsEntity: &tailableCursor tailableCursor + # Iterate twice to force a getMore. The first iteration will return the document from the first batch and the + # second will do a getMore. + - name: iterateUntilDocumentOrError + object: *tailableCursor + - name: iterateUntilDocumentOrError + object: *tailableCursor + expectEvents: + - client: *client + events: + - commandStartedEvent: + commandName: find + databaseName: *databaseName + command: + find: *collectionName + tailable: true + awaitData: true + maxTimeMS: { $$exists: true } + - commandStartedEvent: + commandName: getMore + databaseName: *databaseName + command: + getMore: { $$type: ["int", "long"] } + collection: *collectionName + maxTimeMS: { $$exists: false } + + # If maxAwaitTimeMS is set for the initial command, timeoutMS should still be refreshed for the getMore and the + # getMore command should have a maxTimeMS field. + - description: "timeoutMS is refreshed for getMore if maxAwaitTimeMS is set" + operations: + - name: failPoint + object: testRunner + arguments: + client: *failPointClient + failPoint: + configureFailPoint: failCommand + mode: { times: 2 } + data: + failCommands: ["find", "getMore"] + blockConnection: true + blockTimeMS: 150 + - name: createFindCursor + object: *collection + arguments: + filter: {} + cursorType: tailableAwait + timeoutMS: 250 + batchSize: 1 + maxAwaitTimeMS: 1 + saveResultAsEntity: &tailableCursor tailableCursor + # Iterate twice to force a getMore. + - name: iterateUntilDocumentOrError + object: *tailableCursor + - name: iterateUntilDocumentOrError + object: *tailableCursor + expectEvents: + - client: *client + events: + - commandStartedEvent: + commandName: find + databaseName: *databaseName + command: + find: *collectionName + tailable: true + awaitData: true + maxTimeMS: { $$exists: true } + - commandStartedEvent: + commandName: getMore + databaseName: *databaseName + command: + getMore: { $$type: ["int", "long"] } + collection: *collectionName + maxTimeMS: 1 + + # The timeoutMS value should be refreshed for getMore's. This is a failure test. The find inherits timeoutMS=200 from + # the collection and the getMore blocks for 250ms, causing iteration to fail with a timeout error. + - description: "timeoutMS is refreshed for getMore - failure" + operations: + - name: failPoint + object: testRunner + arguments: + client: *failPointClient + failPoint: + configureFailPoint: failCommand + mode: { times: 1 } + data: + failCommands: ["getMore"] + blockConnection: true + blockTimeMS: 250 + - name: createFindCursor + object: *collection + arguments: + filter: {} + cursorType: tailableAwait + batchSize: 1 + saveResultAsEntity: &tailableCursor tailableCursor + # Iterate twice to force a getMore. + - name: iterateUntilDocumentOrError + object: *tailableCursor + - name: iterateUntilDocumentOrError + object: *tailableCursor + expectError: + isTimeoutError: true + expectEvents: + - client: *client + events: + - commandStartedEvent: + commandName: find + databaseName: *databaseName + command: + find: *collectionName + tailable: true + awaitData: true + maxTimeMS: { $$exists: true } + - commandStartedEvent: + commandName: getMore + databaseName: *databaseName + command: + getMore: { $$type: ["int", "long"] } + collection: *collectionName diff --git a/x/mongo/driver/batch_cursor.go b/x/mongo/driver/batch_cursor.go index 47abe3e5f2..03a9fc03e0 100644 --- a/x/mongo/driver/batch_cursor.go +++ b/x/mongo/driver/batch_cursor.go @@ -373,8 +373,33 @@ func (bc *BatchCursor) getMore(ctx context.Context) { return } + dl, ok := ctx.Deadline() + fmt.Println("bc deadline: ", time.Until(dl), ok) + fmt.Println("bc maxAwaitTime: ", *bc.maxAwaitTime) + if bc.maxAwaitTime != nil { + } + bc.err = Operation{ CommandFn: func(dst []byte, _ description.SelectedServer) ([]byte, error) { + conn, err := bc.Server().Connection(context.Background()) + if err != nil { + panic(err) + } + + rttMonitor := bc.Server().RTTMonitor() + maxTimeMS, err := driverutil.CalculateMaxTimeMS(ctx, rttMonitor.Min(), rttMonitor.Stats(), ErrDeadlineWouldBeExceeded) + if bc.maxAwaitTime != nil && int64(*bc.maxAwaitTime/time.Millisecond) >= maxTimeMS { + fmt.Println(int64(*bc.maxAwaitTime/time.Millisecond), maxTimeMS) + return nil, ErrDeadlineWouldBeExceeded + } + + dl, ok := ctx.Deadline() + fmt.Println("bc deadline: ", time.Until(dl), ok) + fmt.Println("min (bc): ", bc.Server().RTTMonitor().Min(), conn.Describer.ID(), conn.Describer.Address(), maxTimeMS, time.Until(dl), ok, bc.maxAwaitTime) + if err != nil { + return nil, err + } + dst = bsoncore.AppendInt64Element(dst, "getMore", bc.id) dst = bsoncore.AppendStringElement(dst, "collection", bc.collection) if numToReturn > 0 { @@ -382,7 +407,9 @@ func (bc *BatchCursor) getMore(ctx context.Context) { } if bc.maxAwaitTime != nil && *bc.maxAwaitTime > 0 { - dst = bsoncore.AppendInt64Element(dst, "maxTimeMS", int64(*bc.maxAwaitTime)/int64(time.Millisecond)) + dst = bsoncore.AppendInt64Element(dst, "maxTimeMS", maxTimeMS) + + //dst = bsoncore.AppendInt64Element(dst, "maxTimeMS", int64(*bc.maxAwaitTime)/int64(time.Millisecond)) } comment, err := codecutil.MarshalValue(bc.comment, bc.encoderFn) diff --git a/x/mongo/driver/operation.go b/x/mongo/driver/operation.go index 968b2f258c..6a5d22403d 100644 --- a/x/mongo/driver/operation.go +++ b/x/mongo/driver/operation.go @@ -1665,35 +1665,7 @@ func (op Operation) calculateMaxTimeMS(ctx context.Context, rttMin time.Duration return 0, nil } - deadline, ok := ctx.Deadline() - if !ok { - return 0, nil - } - - remainingTimeout := time.Until(deadline) - - // Always round up to the next millisecond value so we never truncate the calculated - // maxTimeMS value (e.g. 400 microseconds evaluates to 1ms, not 0ms). - maxTimeMS := int64((remainingTimeout - rttMin + time.Millisecond - 1) / time.Millisecond) - if maxTimeMS <= 0 { - return 0, fmt.Errorf( - "remaining time %v until context deadline is less than or equal to min network round-trip time %v (%v): %w", - remainingTimeout, - rttMin, - rttStats, - ErrDeadlineWouldBeExceeded) - } - - // The server will return a "BadValue" error if maxTimeMS is greater - // than the maximum positive int32 value (about 24.9 days). If the - // user specified a timeout value greater than that, omit maxTimeMS - // and let the client-side timeout handle cancelling the op if the - // timeout is ever reached. - if maxTimeMS > math.MaxInt32 { - return 0, nil - } - - return maxTimeMS, nil + return driverutil.CalculateMaxTimeMS(ctx, rttMin, rttStats, ErrDeadlineWouldBeExceeded) } // updateClusterTimes updates the cluster times for the session and cluster clock attached to this diff --git a/x/mongo/driver/topology/connection.go b/x/mongo/driver/topology/connection.go index 24ad6a3a51..6b51ed5e59 100644 --- a/x/mongo/driver/topology/connection.go +++ b/x/mongo/driver/topology/connection.go @@ -405,6 +405,8 @@ func (c *connection) readWireMessage(ctx context.Context) ([]byte, error) { return nil, ConnectionError{ConnectionID: c.id, Wrapped: err, message: "failed to set read deadline"} } + fmt.Println("contextDeadlineUsed", contextDeadlineUsed, time.Until(deadline)) + dst, errMsg, err := c.read(ctx) if err != nil { if c.awaitRemainingBytes == nil { From b2e5cbb6b5b8e5eedd83316bb5f2f71b2ac798b7 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Wed, 29 Jan 2025 15:45:50 -0700 Subject: [PATCH 02/20] GODRIVER-3444 Implement validation --- internal/driverutil/operation.go | 2 +- .../unified/collection_operation_execution.go | 4 +- .../unified/cursor_operation_execution.go | 6 -- .../unified/unified_spec_runner.go | 28 ++++-- .../tailable-awaitData.json | 95 +++++++++++-------- .../tailable-awaitData.yml | 64 ++++++------- x/mongo/driver/batch_cursor.go | 47 ++++----- x/mongo/driver/topology/connection.go | 2 - 8 files changed, 128 insertions(+), 120 deletions(-) diff --git a/internal/driverutil/operation.go b/internal/driverutil/operation.go index 587c361d6e..70d5c79760 100644 --- a/internal/driverutil/operation.go +++ b/internal/driverutil/operation.go @@ -47,7 +47,7 @@ func CalculateMaxTimeMS(ctx context.Context, rttMin time.Duration, rttStats stri // Always round up to the next millisecond value so we never truncate the calculated // maxTimeMS value (e.g. 400 microseconds evaluates to 1ms, not 0ms). - maxTimeMS := int64((remainingTimeout - rttMin + time.Millisecond - 1) / time.Millisecond) + maxTimeMS := int64((remainingTimeout - rttMin) / time.Millisecond) if maxTimeMS <= 0 { return 0, fmt.Errorf( "remaining time %v until context deadline is less than or equal to min network round-trip time %v (%v): %w", diff --git a/internal/integration/unified/collection_operation_execution.go b/internal/integration/unified/collection_operation_execution.go index 8f2866f527..c3e7040256 100644 --- a/internal/integration/unified/collection_operation_execution.go +++ b/internal/integration/unified/collection_operation_execution.go @@ -1487,14 +1487,12 @@ func createFindCursor(ctx context.Context, operation *operation) (*cursorResult, case "sort": opts.SetSort(val.Document()) case "timeoutMode": - return nil, newSkipTestError(fmt.Sprintf("timeoutMode is not supported")) + return nil, newSkipTestError("timeoutMode is not supported") case "cursorType": - fmt.Println("cursorType check", val.String(), strings.ToLower(val.String()), val.String() == "tailableAwait") switch strings.ToLower(val.StringValue()) { case "tailable": opts.SetCursorType(options.Tailable) case "tailableawait": - fmt.Println("gottem") opts.SetCursorType(options.TailableAwait) case "nontailable": opts.SetCursorType(options.NonTailable) diff --git a/internal/integration/unified/cursor_operation_execution.go b/internal/integration/unified/cursor_operation_execution.go index d35503b5be..03fa0d81a5 100644 --- a/internal/integration/unified/cursor_operation_execution.go +++ b/internal/integration/unified/cursor_operation_execution.go @@ -19,24 +19,18 @@ func executeIterateOnce(ctx context.Context, operation *operation) (*operationRe return nil, err } - fmt.Println("iterate once") - // TryNext will attempt to get the next document, potentially issuing a single 'getMore'. if cursor.TryNext(ctx) { // We don't expect the server to return malformed documents, so any errors from Decode here are treated // as fatal. var res bson.Raw if err := cursor.Decode(&res); err != nil { - fmt.Println("err:", err) return nil, fmt.Errorf("error decoding cursor result: %w", err) } - fmt.Println("err:", cursor.Err()) - return newDocumentResult(res, nil), nil } - fmt.Println("err:", cursor.Err()) return newErrorResult(cursor.Err()), nil } diff --git a/internal/integration/unified/unified_spec_runner.go b/internal/integration/unified/unified_spec_runner.go index 59e4bf2fff..516768a745 100644 --- a/internal/integration/unified/unified_spec_runner.go +++ b/internal/integration/unified/unified_spec_runner.go @@ -83,6 +83,18 @@ var ( "timeoutMS is refreshed for getMore if maxAwaitTimeMS is set": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", "timeoutMS is refreshed for getMore - failure": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", + // GODRIVER-3473: the implementation of DRIVERS-2868 makes it clear that the + // Go Driver does not correctly implement the following validation for + // tailable awaitData cursors: + // + // Drivers MUST error if this option is set, timeoutMS is set to a + // non-zero value, and maxAwaitTimeMS is greater than or equal to + // timeoutMS. + // + // Once GODRIVER-3473 is completed, we can continue running these tests. + "error if maxAwaitTimeMS is equal to timeoutMS": "Go Driver does not implement this behavior. See GODRIVER-3473", + "error if maxAwaitTimeMS is greater than timeoutMS": "Go Driver does not implement this behavior. See GODRIVER-3473", + // DRIVERS-2953: This test requires that the driver sends a "getMore" // with "maxTimeMS" set. However, "getMore" can only include "maxTimeMS" // for tailable awaitData cursors. Including "maxTimeMS" on "getMore" @@ -182,14 +194,14 @@ func runTestFile(t *testing.T, filepath string, expectValidFail bool, opts ...*O mt.Skip("Skipping CSOT spec test because SKIP_CSOT_TESTS=true") } - //defer func() { - // // catch panics from looking up elements and fail if it's unexpected - // if r := recover(); r != nil { - // if !expectValidFail { - // mt.Fatal(r) - // } - // } - //}() + defer func() { + // catch panics from looking up elements and fail if it's unexpected + if r := recover(); r != nil { + if !expectValidFail { + mt.Fatal(r) + } + } + }() err := testCase.Run(mt) if expectValidFail { if err != nil { diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.json b/testdata/client-side-operations-timeout/tailable-awaitData.json index e56f8f5ea4..0ceb6cb1a3 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.json +++ b/testdata/client-side-operations-timeout/tailable-awaitData.json @@ -17,7 +17,6 @@ "client": { "id": "client", "uriOptions": { - "heartbeatFrequencyMS": 500, "timeoutMS": 200 }, "useMultipleMongoses": false, @@ -113,46 +112,6 @@ } ] }, - { - "description": "some test for us", - "operations": [ - { - "name": "wait", - "object": "testRunner", - "arguments": { - "ms": 750 - } - }, - { - "name": "createFindCursor", - "object": "collection", - "arguments": { - "filter": {}, - "cursorType": "tailableAwait", - "batchSize": 1, - "maxAwaitTimeMS": 10 - }, - "saveResultAsEntity": "tailableCursor" - }, - { - "name": "iterateOnce", - "object": "tailableCursor", - "arguments": { - "timeoutMS": 11 - } - }, - { - "name": "iterateOnce", - "object": "tailableCursor", - "arguments": { - "timeoutMS": 11 - }, - "expectError": { - "isTimeoutError": false - } - } - ] - }, { "description": "timeoutMS applied to find", "operations": [ @@ -458,6 +417,60 @@ ] } ] + }, + { + "description": "apply remaining timeoutMS if less than maxAwaitTimeMS ", + "operations": [ + { + "name": "createFindCursor", + "object": "collection", + "arguments": { + "filter": {}, + "cursorType": "tailableAwait", + "batchSize": 1, + "maxAwaitTimeMS": 100 + }, + "saveResultAsEntity": "tailableCursor" + }, + { + "name": "iterateOnce", + "object": "tailableCursor", + "arguments": { + "timeoutMS": 50 + } + }, + { + "name": "iterateOnce", + "object": "tailableCursor", + "arguments": { + "timeoutMS": 50 + } + } + ], + "expectEvents": [ + { + "client": "client", + "events": [ + { + "commandStartedEvent": { + "commandName": "find", + "databaseName": "test" + } + }, + { + "commandStartedEvent": { + "commandName": "getMore", + "databaseName": "test", + "command": { + "maxTimeMS": { + "$$lte": 50 + } + } + } + } + ] + } + ] } ] } diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.yml b/testdata/client-side-operations-timeout/tailable-awaitData.yml index 544f9db29d..cb5d03239e 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.yml +++ b/testdata/client-side-operations-timeout/tailable-awaitData.yml @@ -12,9 +12,6 @@ createEntities: - client: id: &client client uriOptions: - # Use a high heartbeatFrequencyMS to ensure, when needed, the RTT - # monitor has enough samples to produce a minRTT. - heartbeatFrequencyMS: 500 timeoutMS: 200 useMultipleMongoses: false observeEvents: @@ -74,36 +71,6 @@ tests: expectError: isClientError: true - - description: "some test for us" - operations: - # Wait for enough samples to be added to the RTT Monitor to ensure a - # minimum RTT is available. - - name: wait - object: testRunner - arguments: - ms: 750 - - name: createFindCursor - object: *collection - arguments: - filter: {} - cursorType: tailableAwait - batchSize: 1 - maxAwaitTimeMS: 10 - saveResultAsEntity: &tailableCursor tailableCursor - # Iterate twice to force a getMore. - - name: iterateOnce - object: *tailableCursor - arguments: - timeoutMS: 11 - # ms: 1 - # timeoutMS: 11 - - name: iterateOnce - object: *tailableCursor - arguments: - timeoutMS: 11 - expectError: - isTimeoutError: false - - description: "timeoutMS applied to find" operations: - name: failPoint @@ -278,3 +245,34 @@ tests: command: getMore: { $$type: ["int", "long"] } collection: *collectionName + + - description: "apply remaining timeoutMS if less than maxAwaitTimeMS " + operations: + - name: createFindCursor + object: *collection + arguments: + filter: {} + cursorType: tailableAwait + batchSize: 1 + maxAwaitTimeMS: 100 + saveResultAsEntity: &tailableCursor tailableCursor + # Iterate twice to force a getMore. + - name: iterateOnce + object: *tailableCursor + arguments: + timeoutMS: 50 + - name: iterateOnce + object: *tailableCursor + arguments: + timeoutMS: 50 + expectEvents: + - client: *client + events: + - commandStartedEvent: + commandName: find + databaseName: *databaseName + - commandStartedEvent: + commandName: getMore + databaseName: *databaseName + command: + maxTimeMS: { $$lte: 50 } diff --git a/x/mongo/driver/batch_cursor.go b/x/mongo/driver/batch_cursor.go index 03a9fc03e0..575bc66012 100644 --- a/x/mongo/driver/batch_cursor.go +++ b/x/mongo/driver/batch_cursor.go @@ -373,31 +373,28 @@ func (bc *BatchCursor) getMore(ctx context.Context) { return } - dl, ok := ctx.Deadline() - fmt.Println("bc deadline: ", time.Until(dl), ok) - fmt.Println("bc maxAwaitTime: ", *bc.maxAwaitTime) - if bc.maxAwaitTime != nil { - } - bc.err = Operation{ CommandFn: func(dst []byte, _ description.SelectedServer) ([]byte, error) { - conn, err := bc.Server().Connection(context.Background()) - if err != nil { - panic(err) - } - - rttMonitor := bc.Server().RTTMonitor() - maxTimeMS, err := driverutil.CalculateMaxTimeMS(ctx, rttMonitor.Min(), rttMonitor.Stats(), ErrDeadlineWouldBeExceeded) - if bc.maxAwaitTime != nil && int64(*bc.maxAwaitTime/time.Millisecond) >= maxTimeMS { - fmt.Println(int64(*bc.maxAwaitTime/time.Millisecond), maxTimeMS) - return nil, ErrDeadlineWouldBeExceeded - } - - dl, ok := ctx.Deadline() - fmt.Println("bc deadline: ", time.Until(dl), ok) - fmt.Println("min (bc): ", bc.Server().RTTMonitor().Min(), conn.Describer.ID(), conn.Describer.Address(), maxTimeMS, time.Until(dl), ok, bc.maxAwaitTime) - if err != nil { - return nil, err + // If maxAwaitTime > remaining timeoutMS - minRoundTripTime, then use + // send remaining TimeoutMS - minRoundTripTime allowing the server an + // opportunity to respond with an empty batch. + var maxTimeMS int64 + if bc.maxAwaitTime != nil { + _, ctxDeadlineSet := ctx.Deadline() + + if ctxDeadlineSet { + rttMonitor := bc.Server().RTTMonitor() + + var err error + maxTimeMS, err = driverutil.CalculateMaxTimeMS(ctx, rttMonitor.Min(), rttMonitor.Stats(), ErrDeadlineWouldBeExceeded) + if err != nil { + return nil, err + } + } + + if !ctxDeadlineSet || bc.maxAwaitTime.Milliseconds() < maxTimeMS { + maxTimeMS = bc.maxAwaitTime.Milliseconds() + } } dst = bsoncore.AppendInt64Element(dst, "getMore", bc.id) @@ -406,10 +403,8 @@ func (bc *BatchCursor) getMore(ctx context.Context) { dst = bsoncore.AppendInt32Element(dst, "batchSize", numToReturn) } - if bc.maxAwaitTime != nil && *bc.maxAwaitTime > 0 { + if maxTimeMS > 0 { dst = bsoncore.AppendInt64Element(dst, "maxTimeMS", maxTimeMS) - - //dst = bsoncore.AppendInt64Element(dst, "maxTimeMS", int64(*bc.maxAwaitTime)/int64(time.Millisecond)) } comment, err := codecutil.MarshalValue(bc.comment, bc.encoderFn) diff --git a/x/mongo/driver/topology/connection.go b/x/mongo/driver/topology/connection.go index 6b51ed5e59..24ad6a3a51 100644 --- a/x/mongo/driver/topology/connection.go +++ b/x/mongo/driver/topology/connection.go @@ -405,8 +405,6 @@ func (c *connection) readWireMessage(ctx context.Context) ([]byte, error) { return nil, ConnectionError{ConnectionID: c.id, Wrapped: err, message: "failed to set read deadline"} } - fmt.Println("contextDeadlineUsed", contextDeadlineUsed, time.Until(deadline)) - dst, errMsg, err := c.read(ctx) if err != nil { if c.awaitRemainingBytes == nil { From a0fa4b7de048bd01f099afdcbbf43f47f6465c3c Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Fri, 31 Jan 2025 10:02:11 -0700 Subject: [PATCH 03/20] GODRIVER-3444 Add test when maxAwaitTimeMS is lt remaining timeout --- .../tailable-awaitData.json | 54 +++++++++++++++++++ .../tailable-awaitData.yml | 31 +++++++++++ 2 files changed, 85 insertions(+) diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.json b/testdata/client-side-operations-timeout/tailable-awaitData.json index 0ceb6cb1a3..f49ae45622 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.json +++ b/testdata/client-side-operations-timeout/tailable-awaitData.json @@ -471,6 +471,60 @@ ] } ] + }, + { + "description": "apply maxAwaitTimeMS if less than remaining timeout", + "operations": [ + { + "name": "createFindCursor", + "object": "collection", + "arguments": { + "filter": {}, + "cursorType": "tailableAwait", + "batchSize": 1, + "maxAwaitTimeMS": 50 + }, + "saveResultAsEntity": "tailableCursor" + }, + { + "name": "iterateOnce", + "object": "tailableCursor", + "arguments": { + "timeoutMS": 100 + } + }, + { + "name": "iterateOnce", + "object": "tailableCursor", + "arguments": { + "timeoutMS": 100 + } + } + ], + "expectEvents": [ + { + "client": "client", + "events": [ + { + "commandStartedEvent": { + "commandName": "find", + "databaseName": "test" + } + }, + { + "commandStartedEvent": { + "commandName": "getMore", + "databaseName": "test", + "command": { + "maxTimeMS": { + "$$lte": 50 + } + } + } + } + ] + } + ] } ] } diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.yml b/testdata/client-side-operations-timeout/tailable-awaitData.yml index cb5d03239e..8137d3af7d 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.yml +++ b/testdata/client-side-operations-timeout/tailable-awaitData.yml @@ -276,3 +276,34 @@ tests: databaseName: *databaseName command: maxTimeMS: { $$lte: 50 } + + - description: "apply maxAwaitTimeMS if less than remaining timeout" + operations: + - name: createFindCursor + object: *collection + arguments: + filter: {} + cursorType: tailableAwait + batchSize: 1 + maxAwaitTimeMS: 50 + saveResultAsEntity: &tailableCursor tailableCursor + # Iterate twice to force a getMore. + - name: iterateOnce + object: *tailableCursor + arguments: + timeoutMS: 100 + - name: iterateOnce + object: *tailableCursor + arguments: + timeoutMS: 100 + expectEvents: + - client: *client + events: + - commandStartedEvent: + commandName: find + databaseName: *databaseName + - commandStartedEvent: + commandName: getMore + databaseName: *databaseName + command: + maxTimeMS: { $$lte: 50 } From a6fbd2cefb0ded7de14a49455cbc2d9a483825c1 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Mon, 3 Feb 2025 10:53:24 -0700 Subject: [PATCH 04/20] GODRIVER-3444 Serverless does not apply to tailable awaitData cursors --- .../client-side-operations-timeout/tailable-awaitData.json | 3 ++- testdata/client-side-operations-timeout/tailable-awaitData.yml | 1 + 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.json b/testdata/client-side-operations-timeout/tailable-awaitData.json index f49ae45622..886101ba08 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.json +++ b/testdata/client-side-operations-timeout/tailable-awaitData.json @@ -3,7 +3,8 @@ "schemaVersion": "1.9", "runOnRequirements": [ { - "minServerVersion": "4.4" + "minServerVersion": "4.4", + "serverless": "forbid" } ], "createEntities": [ diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.yml b/testdata/client-side-operations-timeout/tailable-awaitData.yml index 8137d3af7d..401d6311a7 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.yml +++ b/testdata/client-side-operations-timeout/tailable-awaitData.yml @@ -4,6 +4,7 @@ schemaVersion: "1.9" runOnRequirements: - minServerVersion: "4.4" + serverless: forbid # Capped collections are not allowed for serverless. createEntities: - client: From fdeddb1b881d19833643c0696508b5af5c466156 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Wed, 26 Feb 2025 14:54:23 -0700 Subject: [PATCH 05/20] GODRIVER-3444 Use prose tests --- internal/integration/cursor_test.go | 70 +++++++++++++++++++ .../unified/unified_spec_runner.go | 6 +- .../tailable-awaitData.json | 24 +++---- .../tailable-awaitData.yml | 8 +-- 4 files changed, 86 insertions(+), 22 deletions(-) diff --git a/internal/integration/cursor_test.go b/internal/integration/cursor_test.go index 5ee9986ec2..6376e78e74 100644 --- a/internal/integration/cursor_test.go +++ b/internal/integration/cursor_test.go @@ -17,6 +17,7 @@ import ( "go.mongodb.org/mongo-driver/v2/internal/assert" "go.mongodb.org/mongo-driver/v2/internal/failpoint" "go.mongodb.org/mongo-driver/v2/internal/integration/mtest" + "go.mongodb.org/mongo-driver/v2/internal/require" "go.mongodb.org/mongo-driver/v2/mongo" "go.mongodb.org/mongo-driver/v2/mongo/options" ) @@ -303,6 +304,75 @@ func TestCursor(t *testing.T) { batchSize = sizeVal.Int32() assert.Equal(mt, int32(4), batchSize, "expected batchSize 4, got %v", batchSize) }) + + tailableAwaitDataCursorOpts := mtest.NewOptions().MinServerVersion("4.4"). + Topologies(mtest.ReplicaSet, mtest.Sharded, mtest.LoadBalanced, mtest.Single) + + mt.RunOpts("tailable awaitData cursor", tailableAwaitDataCursorOpts, func(mt *mtest.T) { + mt.Run("apply remaining timeoutMS if less than maxAwaitTimeMS", func(mt *mtest.T) { + initCollection(mt, mt.Coll) + mt.ClearEvents() + + // Create a find cursor + opts := options.Find().SetBatchSize(1).SetMaxAwaitTime(100 * time.Millisecond) + + cursor, err := mt.Coll.Find(context.Background(), bson.D{}, opts) + require.NoError(mt, err) + + _ = mt.GetStartedEvent() // Empty find from started list. + + defer cursor.Close(context.Background()) + + ctx, cancel := context.WithTimeout(context.Background(), 50*time.Millisecond) + defer cancel() + + // Iterate twice to force a getMore + cursor.Next(ctx) + cursor.Next(ctx) + + cmd := mt.GetStartedEvent().Command + + maxTimeMSRaw, err := cmd.LookupErr("maxTimeMS") + require.NoError(mt, err) + + got, ok := maxTimeMSRaw.AsInt64OK() + require.True(mt, ok) + + assert.LessOrEqual(mt, got, int64(50)) + }) + + mt.RunOpts("apply maxAwaitTimeMS if less than remaining timeout", tailableAwaitDataCursorOpts, func(mt *mtest.T) { + initCollection(mt, mt.Coll) + mt.ClearEvents() + + // Create a find cursor + opts := options.Find().SetBatchSize(1).SetMaxAwaitTime(50 * time.Millisecond) + + cursor, err := mt.Coll.Find(context.Background(), bson.D{}, opts) + require.NoError(mt, err) + + _ = mt.GetStartedEvent() // Empty find from started list. + + defer cursor.Close(context.Background()) + + ctx, cancel := context.WithTimeout(context.Background(), 100*time.Millisecond) + defer cancel() + + // Iterate twice to force a getMore + cursor.Next(ctx) + cursor.Next(ctx) + + cmd := mt.GetStartedEvent().Command + + maxTimeMSRaw, err := cmd.LookupErr("maxTimeMS") + require.NoError(mt, err) + + got, ok := maxTimeMSRaw.AsInt64OK() + require.True(mt, ok) + + assert.LessOrEqual(mt, got, int64(50)) + }) + }) } type tryNextCursor interface { diff --git a/internal/integration/unified/unified_spec_runner.go b/internal/integration/unified/unified_spec_runner.go index 516768a745..9499d738a1 100644 --- a/internal/integration/unified/unified_spec_runner.go +++ b/internal/integration/unified/unified_spec_runner.go @@ -92,8 +92,10 @@ var ( // timeoutMS. // // Once GODRIVER-3473 is completed, we can continue running these tests. - "error if maxAwaitTimeMS is equal to timeoutMS": "Go Driver does not implement this behavior. See GODRIVER-3473", - "error if maxAwaitTimeMS is greater than timeoutMS": "Go Driver does not implement this behavior. See GODRIVER-3473", + "error if maxAwaitTimeMS is equal to timeoutMS": "Go Driver does not implement this behavior. See GODRIVER-3473", + "error if maxAwaitTimeMS is greater than timeoutMS": "Go Driver does not implement this behavior. See GODRIVER-3473", + "apply remaining timeoutMS if less than maxAwaitTimeMS": "Go Driver does not implement this behavior. See GODRIVER-3473", + "apply maxAwaitTimeMS if less than remaining timeout": "Go Driver does not implement this behavior. See GODRIVER-3473", // DRIVERS-2953: This test requires that the driver sends a "getMore" // with "maxTimeMS" set. However, "getMore" can only include "maxTimeMS" diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.json b/testdata/client-side-operations-timeout/tailable-awaitData.json index 886101ba08..434b0d44b0 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.json +++ b/testdata/client-side-operations-timeout/tailable-awaitData.json @@ -420,7 +420,7 @@ ] }, { - "description": "apply remaining timeoutMS if less than maxAwaitTimeMS ", + "description": "apply remaining timeoutMS if less than maxAwaitTimeMS", "operations": [ { "name": "createFindCursor", @@ -429,23 +429,20 @@ "filter": {}, "cursorType": "tailableAwait", "batchSize": 1, - "maxAwaitTimeMS": 100 + "maxAwaitTimeMS": 100, + "timeoutMS": 50 }, "saveResultAsEntity": "tailableCursor" }, { "name": "iterateOnce", "object": "tailableCursor", - "arguments": { - "timeoutMS": 50 - } + "arguments": null }, { "name": "iterateOnce", "object": "tailableCursor", - "arguments": { - "timeoutMS": 50 - } + "arguments": null } ], "expectEvents": [ @@ -483,23 +480,20 @@ "filter": {}, "cursorType": "tailableAwait", "batchSize": 1, - "maxAwaitTimeMS": 50 + "maxAwaitTimeMS": 50, + "timeoutMS": 100 }, "saveResultAsEntity": "tailableCursor" }, { "name": "iterateOnce", "object": "tailableCursor", - "arguments": { - "timeoutMS": 100 - } + "arguments": null }, { "name": "iterateOnce", "object": "tailableCursor", - "arguments": { - "timeoutMS": 100 - } + "arguments": null } ], "expectEvents": [ diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.yml b/testdata/client-side-operations-timeout/tailable-awaitData.yml index 401d6311a7..22f0eaaa5b 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.yml +++ b/testdata/client-side-operations-timeout/tailable-awaitData.yml @@ -247,7 +247,7 @@ tests: getMore: { $$type: ["int", "long"] } collection: *collectionName - - description: "apply remaining timeoutMS if less than maxAwaitTimeMS " + - description: "apply remaining timeoutMS if less than maxAwaitTimeMS" operations: - name: createFindCursor object: *collection @@ -256,16 +256,15 @@ tests: cursorType: tailableAwait batchSize: 1 maxAwaitTimeMS: 100 + timeoutMS: 50 saveResultAsEntity: &tailableCursor tailableCursor # Iterate twice to force a getMore. - name: iterateOnce object: *tailableCursor arguments: - timeoutMS: 50 - name: iterateOnce object: *tailableCursor arguments: - timeoutMS: 50 expectEvents: - client: *client events: @@ -287,16 +286,15 @@ tests: cursorType: tailableAwait batchSize: 1 maxAwaitTimeMS: 50 + timeoutMS: 100 saveResultAsEntity: &tailableCursor tailableCursor # Iterate twice to force a getMore. - name: iterateOnce object: *tailableCursor arguments: - timeoutMS: 100 - name: iterateOnce object: *tailableCursor arguments: - timeoutMS: 100 expectEvents: - client: *client events: From 2da26275bc32e4f3b2a35f372f15dc3029d2b898 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Thu, 27 Feb 2025 13:35:30 -0700 Subject: [PATCH 06/20] GODRIVER-3444 Remove arguments from tests --- .../tailable-awaitData.json | 12 ++++-------- .../tailable-awaitData.yml | 4 ---- 2 files changed, 4 insertions(+), 12 deletions(-) diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.json b/testdata/client-side-operations-timeout/tailable-awaitData.json index 434b0d44b0..505ff27373 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.json +++ b/testdata/client-side-operations-timeout/tailable-awaitData.json @@ -436,13 +436,11 @@ }, { "name": "iterateOnce", - "object": "tailableCursor", - "arguments": null + "object": "tailableCursor" }, { "name": "iterateOnce", - "object": "tailableCursor", - "arguments": null + "object": "tailableCursor" } ], "expectEvents": [ @@ -487,13 +485,11 @@ }, { "name": "iterateOnce", - "object": "tailableCursor", - "arguments": null + "object": "tailableCursor" }, { "name": "iterateOnce", - "object": "tailableCursor", - "arguments": null + "object": "tailableCursor" } ], "expectEvents": [ diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.yml b/testdata/client-side-operations-timeout/tailable-awaitData.yml index 22f0eaaa5b..361e3cb081 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.yml +++ b/testdata/client-side-operations-timeout/tailable-awaitData.yml @@ -261,10 +261,8 @@ tests: # Iterate twice to force a getMore. - name: iterateOnce object: *tailableCursor - arguments: - name: iterateOnce object: *tailableCursor - arguments: expectEvents: - client: *client events: @@ -291,10 +289,8 @@ tests: # Iterate twice to force a getMore. - name: iterateOnce object: *tailableCursor - arguments: - name: iterateOnce object: *tailableCursor - arguments: expectEvents: - client: *client events: From 5e7921ba6efdde00e7056381282b7fa3cb335f77 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Thu, 6 Mar 2025 19:27:42 -0700 Subject: [PATCH 07/20] GODRIVER-3444 Update unified spect tests --- .../tailable-awaitData.json | 27 +++++++++++++++---- .../tailable-awaitData.yml | 17 ++++++++---- 2 files changed, 34 insertions(+), 10 deletions(-) diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.json b/testdata/client-side-operations-timeout/tailable-awaitData.json index 505ff27373..6042c38fcc 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.json +++ b/testdata/client-side-operations-timeout/tailable-awaitData.json @@ -426,11 +426,13 @@ "name": "createFindCursor", "object": "collection", "arguments": { - "filter": {}, + "filter": { + "_id": 1 + }, "cursorType": "tailableAwait", "batchSize": 1, "maxAwaitTimeMS": 100, - "timeoutMS": 50 + "timeoutMS": 200 }, "saveResultAsEntity": "tailableCursor" }, @@ -439,13 +441,17 @@ "object": "tailableCursor" }, { - "name": "iterateOnce", - "object": "tailableCursor" + "name": "iterateUntilDocumentOrError", + "object": "tailableCursor", + "expectError": { + "isTimeoutError": true + } } ], "expectEvents": [ { "client": "client", + "ignoreExtraEvents": true, "events": [ { "commandStartedEvent": { @@ -459,7 +465,18 @@ "databaseName": "test", "command": { "maxTimeMS": { - "$$lte": 50 + "$$lte": 100 + } + } + } + }, + { + "commandStartedEvent": { + "commandName": "getMore", + "databaseName": "test", + "command": { + "maxTimeMS": { + "$$lte": 99 } } } diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.yml b/testdata/client-side-operations-timeout/tailable-awaitData.yml index 361e3cb081..a0e5c736a9 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.yml +++ b/testdata/client-side-operations-timeout/tailable-awaitData.yml @@ -252,19 +252,21 @@ tests: - name: createFindCursor object: *collection arguments: - filter: {} + filter: { _id: 1 } cursorType: tailableAwait batchSize: 1 maxAwaitTimeMS: 100 - timeoutMS: 50 + timeoutMS: 200 saveResultAsEntity: &tailableCursor tailableCursor - # Iterate twice to force a getMore. - name: iterateOnce object: *tailableCursor - - name: iterateOnce + - name: iterateUntilDocumentOrError object: *tailableCursor + expectError: + isTimeoutError: true expectEvents: - client: *client + ignoreExtraEvents: true events: - commandStartedEvent: commandName: find @@ -273,7 +275,12 @@ tests: commandName: getMore databaseName: *databaseName command: - maxTimeMS: { $$lte: 50 } + maxTimeMS: { $$lte: 100 } + - commandStartedEvent: + commandName: getMore + databaseName: *databaseName + command: + maxTimeMS: { $$lte: 99 } - description: "apply maxAwaitTimeMS if less than remaining timeout" operations: From a435efe6b17cba9c706fba7832a328ceb83617f1 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Fri, 14 Mar 2025 11:41:36 -0600 Subject: [PATCH 08/20] GODRIVER-3444 Update tests to reduce event race --- .../tailable-awaitData.json | 20 +++++++++++++++++++ .../tailable-awaitData.yml | 11 ++++++++++ 2 files changed, 31 insertions(+) diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.json b/testdata/client-side-operations-timeout/tailable-awaitData.json index 6042c38fcc..4509d7f3f4 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.json +++ b/testdata/client-side-operations-timeout/tailable-awaitData.json @@ -422,6 +422,26 @@ { "description": "apply remaining timeoutMS if less than maxAwaitTimeMS", "operations": [ + { + "name": "failPoint", + "object": "testRunner", + "arguments": { + "client": "failPointClient", + "failPoint": { + "configureFailPoint": "failCommand", + "mode": { + "times": 1 + }, + "data": { + "failCommands": [ + "getMore" + ], + "blockConnection": true, + "blockTimeMS": 30 + } + } + } + }, { "name": "createFindCursor", "object": "collection", diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.yml b/testdata/client-side-operations-timeout/tailable-awaitData.yml index a0e5c736a9..37653e445f 100644 --- a/testdata/client-side-operations-timeout/tailable-awaitData.yml +++ b/testdata/client-side-operations-timeout/tailable-awaitData.yml @@ -249,6 +249,17 @@ tests: - description: "apply remaining timeoutMS if less than maxAwaitTimeMS" operations: + - name: failPoint + object: testRunner + arguments: + client: *failPointClient + failPoint: + configureFailPoint: failCommand + mode: { times: 1 } + data: + failCommands: ["getMore"] + blockConnection: true + blockTimeMS: 30 - name: createFindCursor object: *collection arguments: From 8459cd908397dd8f15f5ab4d72a0c83f27c58b7a Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Wed, 2 Apr 2025 16:33:45 -0600 Subject: [PATCH 09/20] GODRIVER-3444 Remove error parameter from CalculateMaxTimeMS --- internal/driverutil/operation.go | 17 +++++------------ x/mongo/driver/batch_cursor.go | 12 ++++++++---- x/mongo/driver/operation.go | 16 +++++++++++++--- x/mongo/driver/operation_test.go | 3 ++- 4 files changed, 28 insertions(+), 20 deletions(-) diff --git a/internal/driverutil/operation.go b/internal/driverutil/operation.go index 544c2de1a1..a331d7625b 100644 --- a/internal/driverutil/operation.go +++ b/internal/driverutil/operation.go @@ -38,25 +38,18 @@ const ( BulkWriteOp = "bulkWrite" // BulkWriteOp is the name for client-level bulk write ) -func CalculateMaxTimeMS(ctx context.Context, rttMin time.Duration, rttStats string, err error) (int64, error) { +func CalculateMaxTimeMS(ctx context.Context, rttMin time.Duration) (int64, bool) { deadline, ok := ctx.Deadline() if !ok { - return 0, nil + return 0, true } remainingTimeout := time.Until(deadline) + fmt.Println(remainingTimeout, rttMin) // Always round up to the next millisecond value so we never truncate the calculated // maxTimeMS value (e.g. 400 microseconds evaluates to 1ms, not 0ms). maxTimeMS := int64((remainingTimeout - rttMin) / time.Millisecond) - if maxTimeMS <= 0 { - return 0, fmt.Errorf( - "remaining time %v until context deadline is less than or equal to min network round-trip time %v (%v): %w", - remainingTimeout, - rttMin, - rttStats, - err) - } // The server will return a "BadValue" error if maxTimeMS is greater // than the maximum positive int32 value (about 24.9 days). If the @@ -64,8 +57,8 @@ func CalculateMaxTimeMS(ctx context.Context, rttMin time.Duration, rttStats stri // and let the client-side timeout handle cancelling the op if the // timeout is ever reached. if maxTimeMS > math.MaxInt32 { - return 0, nil + return 0, false } - return maxTimeMS, nil + return maxTimeMS, true } diff --git a/x/mongo/driver/batch_cursor.go b/x/mongo/driver/batch_cursor.go index 2209f7c572..6d6cd211a5 100644 --- a/x/mongo/driver/batch_cursor.go +++ b/x/mongo/driver/batch_cursor.go @@ -391,10 +391,14 @@ func (bc *BatchCursor) getMore(ctx context.Context) { if ctxDeadlineSet { rttMonitor := bc.Server().RTTMonitor() - var err error - maxTimeMS, err = driverutil.CalculateMaxTimeMS(ctx, rttMonitor.Min(), rttMonitor.Stats(), ErrDeadlineWouldBeExceeded) - if err != nil { - return nil, err + var ok bool + maxTimeMS, ok = driverutil.CalculateMaxTimeMS(ctx, rttMonitor.Min()) + if !ok && maxTimeMS <= 0 { + return nil, fmt.Errorf( + "calculated server-side timeout (%v ms) is less than or equal to 0 (%v): %w", + maxTimeMS, + rttMonitor.Stats(), + ErrDeadlineWouldBeExceeded) } } diff --git a/x/mongo/driver/operation.go b/x/mongo/driver/operation.go index ec79442079..a51316753c 100644 --- a/x/mongo/driver/operation.go +++ b/x/mongo/driver/operation.go @@ -698,7 +698,7 @@ func (op Operation) Execute(ctx context.Context) error { } // Calculate maxTimeMS value to potentially be appended to the wire message. - maxTimeMS, err := op.calculateMaxTimeMS(ctx, srvr.RTTMonitor().Min(), srvr.RTTMonitor().Stats()) + maxTimeMS, err := op.calculateMaxTimeMS(ctx, srvr.RTTMonitor().Min()) if err != nil { return err } @@ -1719,12 +1719,22 @@ func (op Operation) addClusterTime(dst []byte, desc description.SelectedServer) // if the ctx is a Timeout context. If the context is not a Timeout context, it uses the // operation's MaxTimeMS if set. If no MaxTimeMS is set on the operation, and context is // not a Timeout context, calculateMaxTimeMS returns 0. -func (op Operation) calculateMaxTimeMS(ctx context.Context, rttMin time.Duration, rttStats string) (int64, error) { +func (op Operation) calculateMaxTimeMS(ctx context.Context, rttMin time.Duration) (int64, error) { if op.OmitMaxTimeMS { return 0, nil } - return driverutil.CalculateMaxTimeMS(ctx, rttMin, rttStats, ErrDeadlineWouldBeExceeded) + // Calculate maxTimeMS value to potentially be appended to the wire message. + maxTimeMS, ok := driverutil.CalculateMaxTimeMS(ctx, rttMin) + if !ok && maxTimeMS <= 0 { + return 0, fmt.Errorf( + "calculated server-side timeout (%v ms) is less than or equal to 0 (%v): %w", + maxTimeMS, + rttMin, + ErrDeadlineWouldBeExceeded) + } + + return maxTimeMS, nil } // updateClusterTimes updates the cluster times for the session and cluster clock attached to this diff --git a/x/mongo/driver/operation_test.go b/x/mongo/driver/operation_test.go index 911f32dbf5..eec9da8f7a 100644 --- a/x/mongo/driver/operation_test.go +++ b/x/mongo/driver/operation_test.go @@ -312,13 +312,14 @@ func TestOperation(t *testing.T) { t.Run(tc.name, func(t *testing.T) { t.Parallel() - got, err := tc.op.calculateMaxTimeMS(tc.ctx, tc.rttMin, tc.rttStats) + got, err := tc.op.calculateMaxTimeMS(tc.ctx, tc.rttMin) // Assert that the calculated maxTimeMS is less than or equal to the expected value. A few // milliseconds will have elapsed toward the context deadline, and (remainingTimeout // - rtt90) will be slightly smaller than the expected value. if got > tc.want { t.Errorf("maxTimeMS value higher than expected. got %v; wanted at most %v", got, tc.want) + //t.Errorf("calculated server-side timeout (%v ms) is less than or equal to 0 (%v): %w",got, ) } if !errors.Is(err, tc.err) { t.Errorf("error values do not match. got %v; want %v", err, tc.err) From e5d5bcef0edfbe804642491f54c716861c2b21c7 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Wed, 2 Apr 2025 16:40:55 -0600 Subject: [PATCH 10/20] GODRIVER-3444 Run pre-commit --- x/mongo/driver/operation_test.go | 1 - 1 file changed, 1 deletion(-) diff --git a/x/mongo/driver/operation_test.go b/x/mongo/driver/operation_test.go index eec9da8f7a..a2d68c8aef 100644 --- a/x/mongo/driver/operation_test.go +++ b/x/mongo/driver/operation_test.go @@ -319,7 +319,6 @@ func TestOperation(t *testing.T) { // - rtt90) will be slightly smaller than the expected value. if got > tc.want { t.Errorf("maxTimeMS value higher than expected. got %v; wanted at most %v", got, tc.want) - //t.Errorf("calculated server-side timeout (%v ms) is less than or equal to 0 (%v): %w",got, ) } if !errors.Is(err, tc.err) { t.Errorf("error values do not match. got %v; want %v", err, tc.err) From 0f2ec20c904bae7a4c3259aae5e0944bd02ef384 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Wed, 2 Apr 2025 17:01:27 -0600 Subject: [PATCH 11/20] GODRIVER-3444 Check max int --- internal/driverutil/operation.go | 11 ++++++++--- 1 file changed, 8 insertions(+), 3 deletions(-) diff --git a/internal/driverutil/operation.go b/internal/driverutil/operation.go index a331d7625b..aec2b20eb2 100644 --- a/internal/driverutil/operation.go +++ b/internal/driverutil/operation.go @@ -8,7 +8,6 @@ package driverutil import ( "context" - "fmt" "math" "time" ) @@ -38,6 +37,10 @@ const ( BulkWriteOp = "bulkWrite" // BulkWriteOp is the name for client-level bulk write ) +// CalculateMaxTimeMS calculates the maxTimeMS value to send to the server +// based on the context deadline and the minimum round trip time. If the +// calculated maxTimeMS is likely to cause a socket timeout, then this function +// will return 0 and false. func CalculateMaxTimeMS(ctx context.Context, rttMin time.Duration) (int64, bool) { deadline, ok := ctx.Deadline() if !ok { @@ -45,11 +48,13 @@ func CalculateMaxTimeMS(ctx context.Context, rttMin time.Duration) (int64, bool) } remainingTimeout := time.Until(deadline) - fmt.Println(remainingTimeout, rttMin) // Always round up to the next millisecond value so we never truncate the calculated // maxTimeMS value (e.g. 400 microseconds evaluates to 1ms, not 0ms). maxTimeMS := int64((remainingTimeout - rttMin) / time.Millisecond) + if maxTimeMS <= 0 { + return 0, false + } // The server will return a "BadValue" error if maxTimeMS is greater // than the maximum positive int32 value (about 24.9 days). If the @@ -57,7 +62,7 @@ func CalculateMaxTimeMS(ctx context.Context, rttMin time.Duration) (int64, bool) // and let the client-side timeout handle cancelling the op if the // timeout is ever reached. if maxTimeMS > math.MaxInt32 { - return 0, false + return 0, true } return maxTimeMS, true From 210e653073f0b51bd316e01f1c415154738d2561 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Wed, 2 Apr 2025 17:54:57 -0600 Subject: [PATCH 12/20] GORIVER-3444 Extend skip to include twd --- internal/spectest/skip.go | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/internal/spectest/skip.go b/internal/spectest/skip.go index 4efa8f428e..0ff0fc34b3 100644 --- a/internal/spectest/skip.go +++ b/internal/spectest/skip.go @@ -126,6 +126,10 @@ var skipTests = map[string]string{ "TestUnifiedSpec/client-side-operations-timeout/retryability-timeoutMS.json/operation_is_retried_multiple_times_for_non-zero_timeoutMS_-_aggregate_on_collection": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", "TestUnifiedSpec/client-side-operations-timeout/retryability-timeoutMS.json/operation_is_retried_multiple_times_for_non-zero_timeoutMS_-_aggregate_on_database": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", "TestUnifiedSpec/client-side-operations-timeout/gridfs-find.json/timeoutMS_applied_to_find_command": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", + "TestUnifiedSpec/client-side-operations-timeout/tailable-awaitData.json/timeoutMS_applied_to_find": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", + "TestUnifiedSpec/client-side-operations-timeout/tailable-awaitData.json/timeoutMS_is_refreshed_for_getMore_if_maxAwaitTimeMS_is_not_set": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", + "TestUnifiedSpec/client-side-operations-timeout/tailable-awaitData.json/timeoutMS_is_refreshed_for_getMore_if_maxAwaitTimeMS_is_set": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", + "TestUnifiedSpec/client-side-operations-timeout/tailable-awaitData.json/timeoutMS_is_refreshed_for_getMore_-_failure": "maxTimeMS is disabled on find and aggregate. See DRIVERS-2722.", // DRIVERS-2953: This test requires that the driver sends a "getMore" with // "maxTimeMS" set. However, "getMore" can only include "maxTimeMS" for @@ -152,6 +156,18 @@ var skipTests = map[string]string{ "TestUnifiedSpec/server-discovery-and-monitoring/unified/sharded-emit-topology-changed-before-close.json/Topology_lifecycle": "Implement GODRIVER-2967", "TestUnifiedSpec/server-discovery-and-monitoring/unified/replicaset-emit-topology-changed-before-close.json/Topology_lifecycle": "Implement GODRIVER-2967", "TestUnifiedSpec/server-discovery-and-monitoring/unified/standalone-emit-topology-changed-before-close.json/Topology_lifecycle": "Implement GODRIVER-2967", + + // GODRIVER-3473: the implementation of DRIVERS-2868 makes it clear that the + // Go Driver does not correctly implement the following validation for + // tailable awaitData cursors: + // + // Drivers MUST error if this option is set, timeoutMS is set to a + // non-zero value, and maxAwaitTimeMS is greater than or equal to + // timeoutMS. + // + // Once GODRIVER-3473 is completed, we can continue running these tests. + "TestUnifiedSpec/client-side-operations-timeout/tailable-awaitData.json/apply_remaining_timeoutMS_if_less_than_maxAwaitTimeMS": "Go Driver does not implement this behavior. See GODRIVER-3473", + "TestUnifiedSpec/client-side-operations-timeout/tailable-awaitData.json/error_if_maxAwaitTimeMS_is_equal_to_timeoutMS": "Go Driver does not implement this behavior. See GODRIVER-3473", } // CheckSkip checks if the fully-qualified test name matches a skipped test From 06692da4c471822587c8b1f8a7a25f65cc809d93 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Wed, 2 Apr 2025 18:13:04 -0600 Subject: [PATCH 13/20] GORIVER-3444 Extend skip to include twd --- internal/spectest/skip.go | 1 + 1 file changed, 1 insertion(+) diff --git a/internal/spectest/skip.go b/internal/spectest/skip.go index 0ff0fc34b3..94f7b9d68e 100644 --- a/internal/spectest/skip.go +++ b/internal/spectest/skip.go @@ -168,6 +168,7 @@ var skipTests = map[string]string{ // Once GODRIVER-3473 is completed, we can continue running these tests. "TestUnifiedSpec/client-side-operations-timeout/tailable-awaitData.json/apply_remaining_timeoutMS_if_less_than_maxAwaitTimeMS": "Go Driver does not implement this behavior. See GODRIVER-3473", "TestUnifiedSpec/client-side-operations-timeout/tailable-awaitData.json/error_if_maxAwaitTimeMS_is_equal_to_timeoutMS": "Go Driver does not implement this behavior. See GODRIVER-3473", + "TestUnifiedSpec/client-side-operations-timeout/tailable-awaitData.json/error_if_maxAwaitTimeMS_is_greater_than_timeoutMS": "Go Driver does not implement this behavior. See GODRIVER-3473", } // CheckSkip checks if the fully-qualified test name matches a skipped test From 92b8b5bf0e459a34b263346e5845fb766d20d9ab Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Wed, 2 Apr 2025 20:01:40 -0600 Subject: [PATCH 14/20] GODRIVER-3444 Update error messages --- internal/integration/unified/cursor_operation_execution.go | 1 - x/mongo/driver/operation.go | 6 +++--- x/mongo/driver/operation_test.go | 2 +- 3 files changed, 4 insertions(+), 5 deletions(-) diff --git a/internal/integration/unified/cursor_operation_execution.go b/internal/integration/unified/cursor_operation_execution.go index 03fa0d81a5..894bb87ce3 100644 --- a/internal/integration/unified/cursor_operation_execution.go +++ b/internal/integration/unified/cursor_operation_execution.go @@ -30,7 +30,6 @@ func executeIterateOnce(ctx context.Context, operation *operation) (*operationRe return newDocumentResult(res, nil), nil } - return newErrorResult(cursor.Err()), nil } diff --git a/x/mongo/driver/operation.go b/x/mongo/driver/operation.go index a51316753c..50136456e4 100644 --- a/x/mongo/driver/operation.go +++ b/x/mongo/driver/operation.go @@ -698,7 +698,7 @@ func (op Operation) Execute(ctx context.Context) error { } // Calculate maxTimeMS value to potentially be appended to the wire message. - maxTimeMS, err := op.calculateMaxTimeMS(ctx, srvr.RTTMonitor().Min()) + maxTimeMS, err := op.calculateMaxTimeMS(ctx, srvr.RTTMonitor().Min(), srvr.RTTMonitor().Stats()) if err != nil { return err } @@ -1719,7 +1719,7 @@ func (op Operation) addClusterTime(dst []byte, desc description.SelectedServer) // if the ctx is a Timeout context. If the context is not a Timeout context, it uses the // operation's MaxTimeMS if set. If no MaxTimeMS is set on the operation, and context is // not a Timeout context, calculateMaxTimeMS returns 0. -func (op Operation) calculateMaxTimeMS(ctx context.Context, rttMin time.Duration) (int64, error) { +func (op Operation) calculateMaxTimeMS(ctx context.Context, rttMin time.Duration, rttStats string) (int64, error) { if op.OmitMaxTimeMS { return 0, nil } @@ -1730,7 +1730,7 @@ func (op Operation) calculateMaxTimeMS(ctx context.Context, rttMin time.Duration return 0, fmt.Errorf( "calculated server-side timeout (%v ms) is less than or equal to 0 (%v): %w", maxTimeMS, - rttMin, + rttStats, ErrDeadlineWouldBeExceeded) } diff --git a/x/mongo/driver/operation_test.go b/x/mongo/driver/operation_test.go index a2d68c8aef..911f32dbf5 100644 --- a/x/mongo/driver/operation_test.go +++ b/x/mongo/driver/operation_test.go @@ -312,7 +312,7 @@ func TestOperation(t *testing.T) { t.Run(tc.name, func(t *testing.T) { t.Parallel() - got, err := tc.op.calculateMaxTimeMS(tc.ctx, tc.rttMin) + got, err := tc.op.calculateMaxTimeMS(tc.ctx, tc.rttMin, tc.rttStats) // Assert that the calculated maxTimeMS is less than or equal to the expected value. A few // milliseconds will have elapsed toward the context deadline, and (remainingTimeout From 34dff0f3d2992272fc02a34ab14ccfc1411da67c Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Wed, 16 Apr 2025 17:48:18 -0600 Subject: [PATCH 15/20] Update internal/driverutil/operation.go Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com> --- internal/driverutil/operation.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/driverutil/operation.go b/internal/driverutil/operation.go index aec2b20eb2..74142a56e8 100644 --- a/internal/driverutil/operation.go +++ b/internal/driverutil/operation.go @@ -51,7 +51,7 @@ func CalculateMaxTimeMS(ctx context.Context, rttMin time.Duration) (int64, bool) // Always round up to the next millisecond value so we never truncate the calculated // maxTimeMS value (e.g. 400 microseconds evaluates to 1ms, not 0ms). - maxTimeMS := int64((remainingTimeout - rttMin) / time.Millisecond) + maxTimeMS := int64((remainingTimeout - rttMin + time.Millisecond - 1) / time.Millisecond) if maxTimeMS <= 0 { return 0, false } From 5ccba5d5df2125c05966244257485c92efefa5d4 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Thu, 17 Apr 2025 12:42:05 -0600 Subject: [PATCH 16/20] GODRIVER-3444 Add tests for CalculateMaxTimeMS --- internal/driverutil/operation_test.go | 107 ++++++++++++++++++++++++++ 1 file changed, 107 insertions(+) create mode 100644 internal/driverutil/operation_test.go diff --git a/internal/driverutil/operation_test.go b/internal/driverutil/operation_test.go new file mode 100644 index 0000000000..d63285c18f --- /dev/null +++ b/internal/driverutil/operation_test.go @@ -0,0 +1,107 @@ +package driverutil + +import ( + "context" + "math" + "testing" + "time" + + "go.mongodb.org/mongo-driver/v2/internal/assert" +) + +//nolint:govet +func TestCalculateMaxTimeMS(t *testing.T) { + tests := []struct { + name string + ctx context.Context + rttMin time.Duration + wantZero bool + wantOk bool + wantPositive bool + wantExact int64 + }{ + { + name: "no deadline", + ctx: context.Background(), + rttMin: 10 * time.Millisecond, + wantZero: true, + wantOk: true, + wantPositive: false, + }, + { + name: "deadline expired", + ctx: func() context.Context { + ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(-1*time.Second)) //nolint:govet + return ctx + }(), + wantZero: true, + wantOk: false, + wantPositive: false, + }, + { + name: "remaining timeout < rttMin", + ctx: func() context.Context { + ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(1*time.Millisecond)) + return ctx + }(), + rttMin: 10 * time.Millisecond, + wantZero: true, + wantOk: false, + wantPositive: false, + }, + { + name: "normal positive result", + ctx: func() context.Context { + ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(100*time.Millisecond)) + return ctx + }(), + wantZero: false, + wantOk: true, + wantPositive: true, + }, + { + name: "beyond maxInt32", + ctx: func() context.Context { + ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(time.Duration(math.MaxInt32+1000)*time.Millisecond)) + return ctx + }(), + wantZero: true, + wantOk: true, + wantPositive: false, + }, + { + name: "round up to 1ms", + ctx: func() context.Context { + ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(999*time.Microsecond)) + return ctx + }(), + wantOk: true, + wantExact: 1, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + got, got1 := CalculateMaxTimeMS(tt.ctx, tt.rttMin) + + assert.Equal(t, tt.wantOk, got1) + + if tt.wantExact > 0 && got != tt.wantExact { + t.Errorf("CalculateMaxTimeMS() got = %v, want %v", got, tt.wantExact) + } + + if tt.wantZero && got != 0 { + t.Errorf("CalculateMaxTimeMS() got = %v, want 0", got) + } + + if !tt.wantZero && got == 0 { + t.Errorf("CalculateMaxTimeMS() got = %v, want > 0", got) + } + + if !tt.wantZero && tt.wantPositive && got <= 0 { + t.Errorf("CalculateMaxTimeMS() got = %v, want > 0", got) + } + }) + } + +} From 90b91716161320d49285a46567e3687dd0e727fc Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Thu, 17 Apr 2025 12:42:51 -0600 Subject: [PATCH 17/20] GODRIVER-3444 Add tests for CalculateMaxTimeMS --- internal/driverutil/operation_test.go | 9 ++++----- 1 file changed, 4 insertions(+), 5 deletions(-) diff --git a/internal/driverutil/operation_test.go b/internal/driverutil/operation_test.go index d63285c18f..6cd62aaab9 100644 --- a/internal/driverutil/operation_test.go +++ b/internal/driverutil/operation_test.go @@ -9,7 +9,6 @@ import ( "go.mongodb.org/mongo-driver/v2/internal/assert" ) -//nolint:govet func TestCalculateMaxTimeMS(t *testing.T) { tests := []struct { name string @@ -41,7 +40,7 @@ func TestCalculateMaxTimeMS(t *testing.T) { { name: "remaining timeout < rttMin", ctx: func() context.Context { - ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(1*time.Millisecond)) + ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(1*time.Millisecond)) //nolint:govet return ctx }(), rttMin: 10 * time.Millisecond, @@ -52,7 +51,7 @@ func TestCalculateMaxTimeMS(t *testing.T) { { name: "normal positive result", ctx: func() context.Context { - ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(100*time.Millisecond)) + ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(100*time.Millisecond)) //nolint:govet return ctx }(), wantZero: false, @@ -62,7 +61,7 @@ func TestCalculateMaxTimeMS(t *testing.T) { { name: "beyond maxInt32", ctx: func() context.Context { - ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(time.Duration(math.MaxInt32+1000)*time.Millisecond)) + ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(time.Duration(math.MaxInt32+1000)*time.Millisecond)) //nolint:govet return ctx }(), wantZero: true, @@ -72,7 +71,7 @@ func TestCalculateMaxTimeMS(t *testing.T) { { name: "round up to 1ms", ctx: func() context.Context { - ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(999*time.Microsecond)) + ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(999*time.Microsecond)) //nolint:govet return ctx }(), wantOk: true, From 0ff2ec76e9e4a34232a7933877d42f7bc4d27070 Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Thu, 17 Apr 2025 12:43:13 -0600 Subject: [PATCH 18/20] GODRIVER-3444 Add tests for CalculateMaxTimeMS --- internal/driverutil/operation_test.go | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/internal/driverutil/operation_test.go b/internal/driverutil/operation_test.go index 6cd62aaab9..498fd984b9 100644 --- a/internal/driverutil/operation_test.go +++ b/internal/driverutil/operation_test.go @@ -61,7 +61,8 @@ func TestCalculateMaxTimeMS(t *testing.T) { { name: "beyond maxInt32", ctx: func() context.Context { - ctx, _ := context.WithDeadline(context.Background(), time.Now().Add(time.Duration(math.MaxInt32+1000)*time.Millisecond)) //nolint:govet + dur := time.Now().Add(time.Duration(math.MaxInt32+1000) * time.Millisecond) + ctx, _ := context.WithDeadline(context.Background(), dur) //nolint:govet return ctx }(), wantZero: true, From 18f715858892443b73cc6c1c252d458ac531130b Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Fri, 18 Apr 2025 19:54:06 -0600 Subject: [PATCH 19/20] GODRIVER-3444 Remove legacy unified spec tests --- internal/spectest/skip.go | 9 +- .../tailable-awaitData.json | 558 ------------------ .../tailable-awaitData.yml | 322 ---------- 3 files changed, 3 insertions(+), 886 deletions(-) delete mode 100644 testdata/client-side-operations-timeout/tailable-awaitData.json delete mode 100644 testdata/client-side-operations-timeout/tailable-awaitData.yml diff --git a/internal/spectest/skip.go b/internal/spectest/skip.go index 92ec4061d4..c3c5d04fe3 100644 --- a/internal/spectest/skip.go +++ b/internal/spectest/skip.go @@ -452,7 +452,6 @@ var skipTests = map[string][]string{ "TestUnifiedSpec/client-side-operations-timeout/tests/change-streams.json/change_stream_can_be_iterated_again_if_previous_iteration_times_out", "TestUnifiedSpec/client-side-operations-timeout/tests/change-streams.json/timeoutMS_is_refreshed_for_getMore_-_failure", "TestUnifiedSpec/client-side-operations-timeout/tests/change-streams.json/error_if_maxAwaitTimeMS_is_greater_than_timeoutMS", - "TestUnifiedSpec/client-side-operations-timeout/tests/change-streams.json/error_if_maxAwaitTimeMS_is_equal_to_timeoutMS", }, // Unknown CSOT: @@ -588,12 +587,10 @@ var skipTests = map[string][]string{ "TestUnifiedSpec/client-side-operations-timeout/tests/sessions-override-timeoutMS.json", "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-awaitData.json/error_if_timeoutMode_is_cursor_lifetime", "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-awaitData.json/error_if_maxAwaitTimeMS_is_greater_than_timeoutMS", - "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-awaitData.json/error_if_maxAwaitTimeMS_is_equal_to_timeoutMS", "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-awaitData.json/timeoutMS_applied_to_find", "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-awaitData.json/timeoutMS_is_refreshed_for_getMore_if_maxAwaitTimeMS_is_not_set", "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-awaitData.json/timeoutMS_is_refreshed_for_getMore_if_maxAwaitTimeMS_is_set", "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-awaitData.json/timeoutMS_is_refreshed_for_getMore_-_failure", - "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-awaitData.json/apply_remaining_timeoutMS_if_less_than_maxAwaitTimeMS", "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-awaitData.json/apply_maxAwaitTimeMS_if_less_than_remaining_timeout", "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-non-awaitData.json/error_if_timeoutMode_is_cursor_lifetime", "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-non-awaitData.json/timeoutMS_applied_to_find", @@ -834,9 +831,9 @@ var skipTests = map[string][]string{ // // Once GODRIVER-3473 is completed, we can continue running these tests. "When constructing tailable awaitData cusors must validate, timeoutMS is set to a non-zero value, and maxAwaitTimeMS is greater than or equal to timeoutMS (GODRIVER-3473)": { - "TestUnifiedSpec/client-side-operations-timeout/tailable-awaitData.json/apply_remaining_timeoutMS_if_less_than_maxAwaitTimeMS", - "TestUnifiedSpec/client-side-operations-timeout/tailable-awaitData.json/error_if_maxAwaitTimeMS_is_equal_to_timeoutMS", - "TestUnifiedSpec/client-side-operations-timeout/tailable-awaitData.json/error_if_maxAwaitTimeMS_is_greater_than_timeoutMS", + "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-awaitData.json/apply_remaining_timeoutMS_if_less_than_maxAwaitTimeMS", + "TestUnifiedSpec/client-side-operations-timeout/tests/tailable-awaitData.json/error_if_maxAwaitTimeMS_is_equal_to_timeoutMS", + "TestUnifiedSpec/client-side-operations-timeout/tests/change-streams.json/error_if_maxAwaitTimeMS_is_equal_to_timeoutMS", }, } diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.json b/testdata/client-side-operations-timeout/tailable-awaitData.json deleted file mode 100644 index 4509d7f3f4..0000000000 --- a/testdata/client-side-operations-timeout/tailable-awaitData.json +++ /dev/null @@ -1,558 +0,0 @@ -{ - "description": "timeoutMS behaves correctly for tailable awaitData cursors", - "schemaVersion": "1.9", - "runOnRequirements": [ - { - "minServerVersion": "4.4", - "serverless": "forbid" - } - ], - "createEntities": [ - { - "client": { - "id": "failPointClient", - "useMultipleMongoses": false - } - }, - { - "client": { - "id": "client", - "uriOptions": { - "timeoutMS": 200 - }, - "useMultipleMongoses": false, - "observeEvents": [ - "commandStartedEvent" - ] - } - }, - { - "database": { - "id": "database", - "client": "client", - "databaseName": "test" - } - }, - { - "collection": { - "id": "collection", - "database": "database", - "collectionName": "coll" - } - } - ], - "initialData": [ - { - "collectionName": "coll", - "databaseName": "test", - "createOptions": { - "capped": true, - "size": 500 - }, - "documents": [ - { - "_id": 0 - }, - { - "_id": 1 - } - ] - } - ], - "tests": [ - { - "description": "error if timeoutMode is cursor_lifetime", - "operations": [ - { - "name": "find", - "object": "collection", - "arguments": { - "filter": {}, - "timeoutMode": "cursorLifetime", - "cursorType": "tailableAwait" - }, - "expectError": { - "isClientError": true - } - } - ] - }, - { - "description": "error if maxAwaitTimeMS is greater than timeoutMS", - "operations": [ - { - "name": "find", - "object": "collection", - "arguments": { - "filter": {}, - "cursorType": "tailableAwait", - "timeoutMS": 5, - "maxAwaitTimeMS": 10 - }, - "expectError": { - "isClientError": true - } - } - ] - }, - { - "description": "error if maxAwaitTimeMS is equal to timeoutMS", - "operations": [ - { - "name": "find", - "object": "collection", - "arguments": { - "filter": {}, - "cursorType": "tailableAwait", - "timeoutMS": 5, - "maxAwaitTimeMS": 5 - }, - "expectError": { - "isClientError": true - } - } - ] - }, - { - "description": "timeoutMS applied to find", - "operations": [ - { - "name": "failPoint", - "object": "testRunner", - "arguments": { - "client": "failPointClient", - "failPoint": { - "configureFailPoint": "failCommand", - "mode": { - "times": 1 - }, - "data": { - "failCommands": [ - "find" - ], - "blockConnection": true, - "blockTimeMS": 300 - } - } - } - }, - { - "name": "find", - "object": "collection", - "arguments": { - "filter": {}, - "cursorType": "tailableAwait" - }, - "expectError": { - "isTimeoutError": true - } - } - ], - "expectEvents": [ - { - "client": "client", - "events": [ - { - "commandStartedEvent": { - "commandName": "find", - "databaseName": "test", - "command": { - "find": "coll", - "tailable": true, - "awaitData": true, - "maxTimeMS": { - "$$exists": true - } - } - } - } - ] - } - ] - }, - { - "description": "timeoutMS is refreshed for getMore if maxAwaitTimeMS is not set", - "operations": [ - { - "name": "failPoint", - "object": "testRunner", - "arguments": { - "client": "failPointClient", - "failPoint": { - "configureFailPoint": "failCommand", - "mode": { - "times": 2 - }, - "data": { - "failCommands": [ - "find", - "getMore" - ], - "blockConnection": true, - "blockTimeMS": 150 - } - } - } - }, - { - "name": "createFindCursor", - "object": "collection", - "arguments": { - "filter": {}, - "cursorType": "tailableAwait", - "timeoutMS": 250, - "batchSize": 1 - }, - "saveResultAsEntity": "tailableCursor" - }, - { - "name": "iterateUntilDocumentOrError", - "object": "tailableCursor" - }, - { - "name": "iterateUntilDocumentOrError", - "object": "tailableCursor" - } - ], - "expectEvents": [ - { - "client": "client", - "events": [ - { - "commandStartedEvent": { - "commandName": "find", - "databaseName": "test", - "command": { - "find": "coll", - "tailable": true, - "awaitData": true, - "maxTimeMS": { - "$$exists": true - } - } - } - }, - { - "commandStartedEvent": { - "commandName": "getMore", - "databaseName": "test", - "command": { - "getMore": { - "$$type": [ - "int", - "long" - ] - }, - "collection": "coll", - "maxTimeMS": { - "$$exists": false - } - } - } - } - ] - } - ] - }, - { - "description": "timeoutMS is refreshed for getMore if maxAwaitTimeMS is set", - "operations": [ - { - "name": "failPoint", - "object": "testRunner", - "arguments": { - "client": "failPointClient", - "failPoint": { - "configureFailPoint": "failCommand", - "mode": { - "times": 2 - }, - "data": { - "failCommands": [ - "find", - "getMore" - ], - "blockConnection": true, - "blockTimeMS": 150 - } - } - } - }, - { - "name": "createFindCursor", - "object": "collection", - "arguments": { - "filter": {}, - "cursorType": "tailableAwait", - "timeoutMS": 250, - "batchSize": 1, - "maxAwaitTimeMS": 1 - }, - "saveResultAsEntity": "tailableCursor" - }, - { - "name": "iterateUntilDocumentOrError", - "object": "tailableCursor" - }, - { - "name": "iterateUntilDocumentOrError", - "object": "tailableCursor" - } - ], - "expectEvents": [ - { - "client": "client", - "events": [ - { - "commandStartedEvent": { - "commandName": "find", - "databaseName": "test", - "command": { - "find": "coll", - "tailable": true, - "awaitData": true, - "maxTimeMS": { - "$$exists": true - } - } - } - }, - { - "commandStartedEvent": { - "commandName": "getMore", - "databaseName": "test", - "command": { - "getMore": { - "$$type": [ - "int", - "long" - ] - }, - "collection": "coll", - "maxTimeMS": 1 - } - } - } - ] - } - ] - }, - { - "description": "timeoutMS is refreshed for getMore - failure", - "operations": [ - { - "name": "failPoint", - "object": "testRunner", - "arguments": { - "client": "failPointClient", - "failPoint": { - "configureFailPoint": "failCommand", - "mode": { - "times": 1 - }, - "data": { - "failCommands": [ - "getMore" - ], - "blockConnection": true, - "blockTimeMS": 250 - } - } - } - }, - { - "name": "createFindCursor", - "object": "collection", - "arguments": { - "filter": {}, - "cursorType": "tailableAwait", - "batchSize": 1 - }, - "saveResultAsEntity": "tailableCursor" - }, - { - "name": "iterateUntilDocumentOrError", - "object": "tailableCursor" - }, - { - "name": "iterateUntilDocumentOrError", - "object": "tailableCursor", - "expectError": { - "isTimeoutError": true - } - } - ], - "expectEvents": [ - { - "client": "client", - "events": [ - { - "commandStartedEvent": { - "commandName": "find", - "databaseName": "test", - "command": { - "find": "coll", - "tailable": true, - "awaitData": true, - "maxTimeMS": { - "$$exists": true - } - } - } - }, - { - "commandStartedEvent": { - "commandName": "getMore", - "databaseName": "test", - "command": { - "getMore": { - "$$type": [ - "int", - "long" - ] - }, - "collection": "coll" - } - } - } - ] - } - ] - }, - { - "description": "apply remaining timeoutMS if less than maxAwaitTimeMS", - "operations": [ - { - "name": "failPoint", - "object": "testRunner", - "arguments": { - "client": "failPointClient", - "failPoint": { - "configureFailPoint": "failCommand", - "mode": { - "times": 1 - }, - "data": { - "failCommands": [ - "getMore" - ], - "blockConnection": true, - "blockTimeMS": 30 - } - } - } - }, - { - "name": "createFindCursor", - "object": "collection", - "arguments": { - "filter": { - "_id": 1 - }, - "cursorType": "tailableAwait", - "batchSize": 1, - "maxAwaitTimeMS": 100, - "timeoutMS": 200 - }, - "saveResultAsEntity": "tailableCursor" - }, - { - "name": "iterateOnce", - "object": "tailableCursor" - }, - { - "name": "iterateUntilDocumentOrError", - "object": "tailableCursor", - "expectError": { - "isTimeoutError": true - } - } - ], - "expectEvents": [ - { - "client": "client", - "ignoreExtraEvents": true, - "events": [ - { - "commandStartedEvent": { - "commandName": "find", - "databaseName": "test" - } - }, - { - "commandStartedEvent": { - "commandName": "getMore", - "databaseName": "test", - "command": { - "maxTimeMS": { - "$$lte": 100 - } - } - } - }, - { - "commandStartedEvent": { - "commandName": "getMore", - "databaseName": "test", - "command": { - "maxTimeMS": { - "$$lte": 99 - } - } - } - } - ] - } - ] - }, - { - "description": "apply maxAwaitTimeMS if less than remaining timeout", - "operations": [ - { - "name": "createFindCursor", - "object": "collection", - "arguments": { - "filter": {}, - "cursorType": "tailableAwait", - "batchSize": 1, - "maxAwaitTimeMS": 50, - "timeoutMS": 100 - }, - "saveResultAsEntity": "tailableCursor" - }, - { - "name": "iterateOnce", - "object": "tailableCursor" - }, - { - "name": "iterateOnce", - "object": "tailableCursor" - } - ], - "expectEvents": [ - { - "client": "client", - "events": [ - { - "commandStartedEvent": { - "commandName": "find", - "databaseName": "test" - } - }, - { - "commandStartedEvent": { - "commandName": "getMore", - "databaseName": "test", - "command": { - "maxTimeMS": { - "$$lte": 50 - } - } - } - } - ] - } - ] - } - ] -} diff --git a/testdata/client-side-operations-timeout/tailable-awaitData.yml b/testdata/client-side-operations-timeout/tailable-awaitData.yml deleted file mode 100644 index 37653e445f..0000000000 --- a/testdata/client-side-operations-timeout/tailable-awaitData.yml +++ /dev/null @@ -1,322 +0,0 @@ -description: "timeoutMS behaves correctly for tailable awaitData cursors" - -schemaVersion: "1.9" - -runOnRequirements: - - minServerVersion: "4.4" - serverless: forbid # Capped collections are not allowed for serverless. - -createEntities: - - client: - id: &failPointClient failPointClient - useMultipleMongoses: false - - client: - id: &client client - uriOptions: - timeoutMS: 200 - useMultipleMongoses: false - observeEvents: - - commandStartedEvent - - database: - id: &database database - client: *client - databaseName: &databaseName test - - collection: - id: &collection collection - database: *database - collectionName: &collectionName coll - -initialData: - - collectionName: *collectionName - databaseName: *databaseName - createOptions: - capped: true - size: 500 - documents: - - { _id: 0 } - - { _id: 1 } - -tests: - - description: "error if timeoutMode is cursor_lifetime" - operations: - - name: find - object: *collection - arguments: - filter: {} - timeoutMode: cursorLifetime - cursorType: tailableAwait - expectError: - isClientError: true - - - description: "error if maxAwaitTimeMS is greater than timeoutMS" - operations: - - name: find - object: *collection - arguments: - filter: {} - cursorType: tailableAwait - timeoutMS: 5 - maxAwaitTimeMS: 10 - expectError: - isClientError: true - - - description: "error if maxAwaitTimeMS is equal to timeoutMS" - operations: - - name: find - object: *collection - arguments: - filter: {} - cursorType: tailableAwait - timeoutMS: 5 - maxAwaitTimeMS: 5 - expectError: - isClientError: true - - - description: "timeoutMS applied to find" - operations: - - name: failPoint - object: testRunner - arguments: - client: *failPointClient - failPoint: - configureFailPoint: failCommand - mode: { times: 1 } - data: - failCommands: ["find"] - blockConnection: true - blockTimeMS: 300 - - name: find - object: *collection - arguments: - filter: {} - cursorType: tailableAwait - expectError: - isTimeoutError: true - expectEvents: - - client: *client - events: - - commandStartedEvent: - commandName: find - databaseName: *databaseName - command: - find: *collectionName - tailable: true - awaitData: true - maxTimeMS: { $$exists: true } - - # If maxAwaitTimeMS is not set, timeoutMS should be refreshed for the getMore and the getMore should not have a - # maxTimeMS field. - - description: "timeoutMS is refreshed for getMore if maxAwaitTimeMS is not set" - operations: - - name: failPoint - object: testRunner - arguments: - client: *failPointClient - failPoint: - configureFailPoint: failCommand - mode: { times: 2 } - data: - failCommands: ["find", "getMore"] - blockConnection: true - blockTimeMS: 150 - - name: createFindCursor - object: *collection - arguments: - filter: {} - cursorType: tailableAwait - timeoutMS: 250 - batchSize: 1 - saveResultAsEntity: &tailableCursor tailableCursor - # Iterate twice to force a getMore. The first iteration will return the document from the first batch and the - # second will do a getMore. - - name: iterateUntilDocumentOrError - object: *tailableCursor - - name: iterateUntilDocumentOrError - object: *tailableCursor - expectEvents: - - client: *client - events: - - commandStartedEvent: - commandName: find - databaseName: *databaseName - command: - find: *collectionName - tailable: true - awaitData: true - maxTimeMS: { $$exists: true } - - commandStartedEvent: - commandName: getMore - databaseName: *databaseName - command: - getMore: { $$type: ["int", "long"] } - collection: *collectionName - maxTimeMS: { $$exists: false } - - # If maxAwaitTimeMS is set for the initial command, timeoutMS should still be refreshed for the getMore and the - # getMore command should have a maxTimeMS field. - - description: "timeoutMS is refreshed for getMore if maxAwaitTimeMS is set" - operations: - - name: failPoint - object: testRunner - arguments: - client: *failPointClient - failPoint: - configureFailPoint: failCommand - mode: { times: 2 } - data: - failCommands: ["find", "getMore"] - blockConnection: true - blockTimeMS: 150 - - name: createFindCursor - object: *collection - arguments: - filter: {} - cursorType: tailableAwait - timeoutMS: 250 - batchSize: 1 - maxAwaitTimeMS: 1 - saveResultAsEntity: &tailableCursor tailableCursor - # Iterate twice to force a getMore. - - name: iterateUntilDocumentOrError - object: *tailableCursor - - name: iterateUntilDocumentOrError - object: *tailableCursor - expectEvents: - - client: *client - events: - - commandStartedEvent: - commandName: find - databaseName: *databaseName - command: - find: *collectionName - tailable: true - awaitData: true - maxTimeMS: { $$exists: true } - - commandStartedEvent: - commandName: getMore - databaseName: *databaseName - command: - getMore: { $$type: ["int", "long"] } - collection: *collectionName - maxTimeMS: 1 - - # The timeoutMS value should be refreshed for getMore's. This is a failure test. The find inherits timeoutMS=200 from - # the collection and the getMore blocks for 250ms, causing iteration to fail with a timeout error. - - description: "timeoutMS is refreshed for getMore - failure" - operations: - - name: failPoint - object: testRunner - arguments: - client: *failPointClient - failPoint: - configureFailPoint: failCommand - mode: { times: 1 } - data: - failCommands: ["getMore"] - blockConnection: true - blockTimeMS: 250 - - name: createFindCursor - object: *collection - arguments: - filter: {} - cursorType: tailableAwait - batchSize: 1 - saveResultAsEntity: &tailableCursor tailableCursor - # Iterate twice to force a getMore. - - name: iterateUntilDocumentOrError - object: *tailableCursor - - name: iterateUntilDocumentOrError - object: *tailableCursor - expectError: - isTimeoutError: true - expectEvents: - - client: *client - events: - - commandStartedEvent: - commandName: find - databaseName: *databaseName - command: - find: *collectionName - tailable: true - awaitData: true - maxTimeMS: { $$exists: true } - - commandStartedEvent: - commandName: getMore - databaseName: *databaseName - command: - getMore: { $$type: ["int", "long"] } - collection: *collectionName - - - description: "apply remaining timeoutMS if less than maxAwaitTimeMS" - operations: - - name: failPoint - object: testRunner - arguments: - client: *failPointClient - failPoint: - configureFailPoint: failCommand - mode: { times: 1 } - data: - failCommands: ["getMore"] - blockConnection: true - blockTimeMS: 30 - - name: createFindCursor - object: *collection - arguments: - filter: { _id: 1 } - cursorType: tailableAwait - batchSize: 1 - maxAwaitTimeMS: 100 - timeoutMS: 200 - saveResultAsEntity: &tailableCursor tailableCursor - - name: iterateOnce - object: *tailableCursor - - name: iterateUntilDocumentOrError - object: *tailableCursor - expectError: - isTimeoutError: true - expectEvents: - - client: *client - ignoreExtraEvents: true - events: - - commandStartedEvent: - commandName: find - databaseName: *databaseName - - commandStartedEvent: - commandName: getMore - databaseName: *databaseName - command: - maxTimeMS: { $$lte: 100 } - - commandStartedEvent: - commandName: getMore - databaseName: *databaseName - command: - maxTimeMS: { $$lte: 99 } - - - description: "apply maxAwaitTimeMS if less than remaining timeout" - operations: - - name: createFindCursor - object: *collection - arguments: - filter: {} - cursorType: tailableAwait - batchSize: 1 - maxAwaitTimeMS: 50 - timeoutMS: 100 - saveResultAsEntity: &tailableCursor tailableCursor - # Iterate twice to force a getMore. - - name: iterateOnce - object: *tailableCursor - - name: iterateOnce - object: *tailableCursor - expectEvents: - - client: *client - events: - - commandStartedEvent: - commandName: find - databaseName: *databaseName - - commandStartedEvent: - commandName: getMore - databaseName: *databaseName - command: - maxTimeMS: { $$lte: 50 } From 3b62991fa243f372cf8710234525ecbc191e99df Mon Sep 17 00:00:00 2001 From: Preston Vasquez Date: Mon, 21 Apr 2025 11:16:56 -0600 Subject: [PATCH 20/20] GODRIVER-3444 Add license --- internal/driverutil/operation_test.go | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/internal/driverutil/operation_test.go b/internal/driverutil/operation_test.go index 498fd984b9..474c3e1aa1 100644 --- a/internal/driverutil/operation_test.go +++ b/internal/driverutil/operation_test.go @@ -1,3 +1,9 @@ +// Copyright (C) MongoDB, Inc. 2025-present. +// +// Licensed under the Apache License, Version 2.0 (the "License"); you may +// not use this file except in compliance with the License. You may obtain +// a copy of the License at http://www.apache.org/licenses/LICENSE-2.0 + package driverutil import (