From ec3cabaf411dabf38931b4dec8f990ea058afb9a Mon Sep 17 00:00:00 2001 From: Durran Jordan Date: Mon, 17 Jun 2024 21:46:46 +0200 Subject: [PATCH] test(NODE-6202): use single mongos in unacknowledged write tests (#4149) Co-authored-by: Aditi Khare <106987683+aditi-khare-mongoDB@users.noreply.github.com> --- .../logging/unacknowledged-write.json | 151 ++++++++++++++++++ .../logging/unacknowledged-write.yml | 76 +++++++++ .../monitoring/unacknowledgedBulkWrite.json | 21 ++- .../monitoring/unacknowledgedBulkWrite.yml | 13 +- test/tools/unified-spec-runner/match.ts | 17 +- test/tools/unified-spec-runner/runner.ts | 11 +- test/tools/unified-spec-runner/schema.ts | 13 ++ test/unit/tools/unified_spec_runner.test.ts | 8 +- 8 files changed, 298 insertions(+), 12 deletions(-) create mode 100644 test/spec/command-logging-and-monitoring/logging/unacknowledged-write.json create mode 100644 test/spec/command-logging-and-monitoring/logging/unacknowledged-write.yml diff --git a/test/spec/command-logging-and-monitoring/logging/unacknowledged-write.json b/test/spec/command-logging-and-monitoring/logging/unacknowledged-write.json new file mode 100644 index 0000000000..0d33c020d5 --- /dev/null +++ b/test/spec/command-logging-and-monitoring/logging/unacknowledged-write.json @@ -0,0 +1,151 @@ +{ + "description": "unacknowledged-write", + "schemaVersion": "1.16", + "createEntities": [ + { + "client": { + "id": "client", + "useMultipleMongoses": false, + "observeLogMessages": { + "command": "debug" + } + } + }, + { + "database": { + "id": "database", + "client": "client", + "databaseName": "logging-tests" + } + }, + { + "collection": { + "id": "collection", + "database": "database", + "collectionName": "logging-tests-collection", + "collectionOptions": { + "writeConcern": { + "w": 0 + } + } + } + } + ], + "initialData": [ + { + "collectionName": "logging-tests-collection", + "databaseName": "logging-tests", + "documents": [ + { + "_id": 1 + } + ] + } + ], + "tests": [ + { + "description": "An unacknowledged write generates a succeeded log message with ok: 1 reply", + "operations": [ + { + "name": "insertOne", + "object": "collection", + "arguments": { + "document": { + "_id": 2 + } + } + }, + { + "name": "find", + "object": "collection", + "arguments": { + "filter": {} + }, + "expectResult": [ + { + "_id": 1 + }, + { + "_id": 2 + } + ] + } + ], + "expectLogMessages": [ + { + "client": "client", + "ignoreExtraMessages": true, + "messages": [ + { + "level": "debug", + "component": "command", + "data": { + "message": "Command started", + "databaseName": "logging-tests", + "commandName": "insert", + "command": { + "$$matchAsDocument": { + "$$matchAsRoot": { + "insert": "logging-tests-collection", + "$db": "logging-tests" + } + } + }, + "requestId": { + "$$type": [ + "int", + "long" + ] + }, + "serverHost": { + "$$type": "string" + }, + "serverPort": { + "$$type": [ + "int", + "long" + ] + } + } + }, + { + "level": "debug", + "component": "command", + "data": { + "message": "Command succeeded", + "commandName": "insert", + "reply": { + "$$matchAsDocument": { + "ok": 1 + } + }, + "requestId": { + "$$type": [ + "int", + "long" + ] + }, + "serverHost": { + "$$type": "string" + }, + "serverPort": { + "$$type": [ + "int", + "long" + ] + }, + "durationMS": { + "$$type": [ + "double", + "int", + "long" + ] + } + } + } + ] + } + ] + } + ] +} diff --git a/test/spec/command-logging-and-monitoring/logging/unacknowledged-write.yml b/test/spec/command-logging-and-monitoring/logging/unacknowledged-write.yml new file mode 100644 index 0000000000..6409fb408c --- /dev/null +++ b/test/spec/command-logging-and-monitoring/logging/unacknowledged-write.yml @@ -0,0 +1,76 @@ +description: "unacknowledged-write" + +schemaVersion: "1.16" + +createEntities: + - client: + id: &client client + useMultipleMongoses: false + observeLogMessages: + command: debug + - database: + id: &database database + client: *client + databaseName: &databaseName logging-tests + - collection: + id: &collection collection + database: *database + collectionName: &collectionName logging-tests-collection + collectionOptions: + writeConcern: { w: 0 } + +initialData: + - collectionName: *collectionName + databaseName: *databaseName + documents: + - { _id: 1 } + +tests: + - description: "An unacknowledged write generates a succeeded log message with ok: 1 reply" + operations: + - name: insertOne + object: *collection + arguments: + document: { _id: 2 } + # Force completion of the w: 0 write by executing a find on the same connection + - name: find + object: *collection + arguments: + filter: { } + expectResult: [ + { _id: 1 }, + { _id: 2 } + ] + expectLogMessages: + - client: *client + ignoreExtraMessages: true + messages: + - level: debug + component: command + data: + message: "Command started" + databaseName: *databaseName + commandName: insert + command: + $$matchAsDocument: + $$matchAsRoot: + insert: *collectionName + $db: *databaseName + requestId: { $$type: [int, long] } + serverHost: { $$type: string } + serverPort: { $$type: [int, long] } + + - level: debug + component: command + data: + message: "Command succeeded" + commandName: insert + reply: + $$matchAsDocument: + ok: 1 + requestId: { $$type: [int, long] } + serverHost: { $$type: string } + serverPort: { $$type: [int, long] } + durationMS: { $$type: [double, int, long] } + + diff --git a/test/spec/command-logging-and-monitoring/monitoring/unacknowledgedBulkWrite.json b/test/spec/command-logging-and-monitoring/monitoring/unacknowledgedBulkWrite.json index 4c16d6df11..ed6ceafa5f 100644 --- a/test/spec/command-logging-and-monitoring/monitoring/unacknowledgedBulkWrite.json +++ b/test/spec/command-logging-and-monitoring/monitoring/unacknowledgedBulkWrite.json @@ -1,10 +1,11 @@ { "description": "unacknowledgedBulkWrite", - "schemaVersion": "1.0", + "schemaVersion": "1.7", "createEntities": [ { "client": { "id": "client", + "useMultipleMongoses": false, "observeEvents": [ "commandStartedEvent", "commandSucceededEvent", @@ -64,11 +65,29 @@ ], "ordered": false } + }, + { + "name": "find", + "object": "collection", + "arguments": { + "filter": {} + }, + "expectResult": [ + { + "_id": 1, + "x": 11 + }, + { + "_id": "unorderedBulkWriteInsertW0", + "x": 44 + } + ] } ], "expectEvents": [ { "client": "client", + "ignoreExtraEvents": true, "events": [ { "commandStartedEvent": { diff --git a/test/spec/command-logging-and-monitoring/monitoring/unacknowledgedBulkWrite.yml b/test/spec/command-logging-and-monitoring/monitoring/unacknowledgedBulkWrite.yml index d7c8ce0d0c..4cf3396a7f 100644 --- a/test/spec/command-logging-and-monitoring/monitoring/unacknowledgedBulkWrite.yml +++ b/test/spec/command-logging-and-monitoring/monitoring/unacknowledgedBulkWrite.yml @@ -1,10 +1,11 @@ description: "unacknowledgedBulkWrite" -schemaVersion: "1.0" +schemaVersion: "1.7" createEntities: - client: id: &client client + useMultipleMongoses: false observeEvents: - commandStartedEvent - commandSucceededEvent @@ -36,8 +37,18 @@ tests: - insertOne: document: { _id: "unorderedBulkWriteInsertW0", x: 44 } ordered: false + # Force completion of the w: 0 write by executing a find on the same connection + - name: find + object: *collection + arguments: + filter: { } + expectResult: [ + { _id: 1, x: 11 }, + { _id: "unorderedBulkWriteInsertW0", x: 44 } + ] expectEvents: - client: *client + ignoreExtraEvents: true events: - commandStartedEvent: command: diff --git a/test/tools/unified-spec-runner/match.ts b/test/tools/unified-spec-runner/match.ts index 4808244e29..45048b2bec 100644 --- a/test/tools/unified-spec-runner/match.ts +++ b/test/tools/unified-spec-runner/match.ts @@ -241,13 +241,13 @@ export function resultCheck( } for (const [index, value] of expectedEntries) { path.push(`[${index}]`); - checkNestedDocuments(index, value, false); + checkNestedDocuments(index, value, checkExtraKeys); path.pop(); } } else { for (const [key, value] of expectedEntries) { path.push(`.${key}`); - checkNestedDocuments(key, value, true); + checkNestedDocuments(key, value, checkExtraKeys); path.pop(); } @@ -361,7 +361,7 @@ export function specialCheck( } else if (isMatchAsDocumentOperator(expected)) { if (typeof actual === 'string') { const actualDoc = EJSON.parse(actual, { relaxed: false }); - resultCheck(actualDoc, expected.$$matchAsDocument as any, entities, path, true); + resultCheck(actualDoc, expected.$$matchAsDocument as any, entities, path, checkExtraKeys); } else { expect.fail( `Expected value at path '${path.join('')}' to be string, but received ${inspect(actual)}` @@ -650,7 +650,7 @@ export function matchesEvents( } } -export function filterExtraLogs( +export function filterIgnoredMessages( logsToIgnore: ExpectedLogMessage[], actual: ExpectedLogMessage[], entities: EntitiesMap @@ -675,11 +675,16 @@ export function filterExtraLogs( export function compareLogs( expected: ExpectedLogMessage[], actual: ExpectedLogMessage[], - entities: EntitiesMap + entities: EntitiesMap, + ignoreExtraMessages = false ): void { - expect(actual).to.have.lengthOf(expected.length); + if (!ignoreExtraMessages) { + expect(actual).to.have.lengthOf(expected.length); + } for (const [index, actualLog] of actual.entries()) { + if (index >= expected.length && ignoreExtraMessages) return; + const rootPrefix = `expectLogMessages[${index}]`; const expectedLog = expected[index]; diff --git a/test/tools/unified-spec-runner/runner.ts b/test/tools/unified-spec-runner/runner.ts index 721d8497ce..1c12611a84 100644 --- a/test/tools/unified-spec-runner/runner.ts +++ b/test/tools/unified-spec-runner/runner.ts @@ -7,7 +7,7 @@ import { MONGODB_ERROR_CODES, ns, ReadPreference, TopologyType } from '../../mon import { ejson } from '../utils'; import { AstrolabeResultsWriter } from './astrolabe_results_writer'; import { EntitiesMap, type UnifiedMongoClient } from './entities'; -import { compareLogs, filterExtraLogs, matchesEvents } from './match'; +import { compareLogs, filterIgnoredMessages, matchesEvents } from './match'; import { executeOperationAndCheck } from './operations'; import * as uni from './schema'; import { isAnyRequirementSatisfied, patchVersion, zip } from './unified-utils'; @@ -247,13 +247,18 @@ async function runUnifiedTest( expect(testClient, `No client entity found with id ${clientId}`).to.exist; const filteredTestClientLogs = expectedLogsForClient.ignoreMessages - ? filterExtraLogs( + ? filterIgnoredMessages( expectedLogsForClient.ignoreMessages, testClient!.collectedLogs, entities ) : testClient!.collectedLogs; - compareLogs(expectedLogsForClient.messages, filteredTestClientLogs, entities); + compareLogs( + expectedLogsForClient.messages, + filteredTestClientLogs, + entities, + expectedLogsForClient.ignoreExtraMessages + ); } } diff --git a/test/tools/unified-spec-runner/schema.ts b/test/tools/unified-spec-runner/schema.ts index 8917426292..81b8172463 100644 --- a/test/tools/unified-spec-runner/schema.ts +++ b/test/tools/unified-spec-runner/schema.ts @@ -284,7 +284,20 @@ export type ExpectedEvent = ExpectedCommandEvent | ExpectedCmapEvent | ExpectedS export interface ExpectedLogMessagesForClient { client: string; messages: ExpectedLogMessage[]; + /** + * Optional array of expectedLogMessage objects. Unordered set of messages, which MUST + * be ignored on the corresponding client while executing operations. The test runner + * MUST exclude all log messages from observed messages that match any of the messages + * in ignoreMessages array before messages evaluation. Matching rules used to match + * messages in ignoreMessages are identical to match rules used for messages matching. + */ ignoreMessages: ExpectedLogMessage[]; + /** + * Specifies how the messages array is matched against the observed logs. If false, + * observed logs after all specified logs have matched MUST cause a test failure; + * if true, observed logs after all specified logs have been matched MUST NOT cause + * a test failure. Defaults to false. + */ ignoreExtraMessages: boolean; } diff --git a/test/unit/tools/unified_spec_runner.test.ts b/test/unit/tools/unified_spec_runner.test.ts index 647005411f..a0887be959 100644 --- a/test/unit/tools/unified_spec_runner.test.ts +++ b/test/unit/tools/unified_spec_runner.test.ts @@ -37,12 +37,18 @@ describe('Unified Spec Runner', function () { it('throws AssertionError when it finds extra keys', function () { actual = '{"data": {"$numberLong": "100"}, "a": {"$numberInt": "10"}, "b": {"$numberInt": "100"}}'; - expect(() => resultCheckSpy(actual, expected, entitiesMap, [])).to.throw( + expect(() => resultCheckSpy(actual, expected, entitiesMap, [], true)).to.throw( AssertionError, /object has more keys than expected/ ); }); + it('does not throw when it finds extra keys but checking is disabled', function () { + actual = + '{"data": {"$numberLong": "100"}, "a": {"$numberInt": "10"}, "b": {"$numberInt": "100"}}'; + expect(() => resultCheckSpy(actual, expected, entitiesMap, [], false)).to.not.throw(); + }); + it('passes when all keys match', function () { actual = '{"data": {"$numberLong": "100"}, "a": {"$numberInt": "10"}}'; resultCheckSpy(actual, expected, entitiesMap, []);