From 490df8a7f93b4346e9c19fbcaed09f36d0cb2a32 Mon Sep 17 00:00:00 2001 From: auto-revert-processor Date: Sat, 30 Sep 2023 06:45:31 +0000 Subject: [PATCH] Revert "SERVER-78451: Add bson validation to dbCheck" This reverts commit 968b9ea86c5b620378fffe8a5b592314930f488f. --- .../variants/sanitizer.yml | 8 +- .../dbcheck_detects_data_corruption.js | 4 +- jstests/replsets/dbcheck.js | 105 +++++++---- jstests/replsets/dbcheck_validate_bson.js | 165 ------------------ jstests/replsets/libs/dbcheck_utils.js | 7 - src/mongo/db/commands/dbcheck.cpp | 57 +----- src/mongo/db/repl/dbcheck.cpp | 102 ++--------- src/mongo/db/repl/dbcheck.h | 5 +- 8 files changed, 102 insertions(+), 351 deletions(-) delete mode 100644 jstests/replsets/dbcheck_validate_bson.js diff --git a/etc/evergreen_yml_components/variants/sanitizer.yml b/etc/evergreen_yml_components/variants/sanitizer.yml index 9119b76e48c..70d26e4f99d 100644 --- a/etc/evergreen_yml_components/variants/sanitizer.yml +++ b/etc/evergreen_yml_components/variants/sanitizer.yml @@ -37,7 +37,7 @@ buildvariants: resmoke_jobs_factor: 0.3 # Avoid starting too many mongod's under ASAN build. hang_analyzer_dump_core: false scons_cache_scope: shared - test_flags: --excludeWithAnyTags=requires_fast_memory,requires_ocsp_stapling,corrupts_data + test_flags: --excludeWithAnyTags=requires_fast_memory,requires_ocsp_stapling separate_debug: off compile_variant: rhel80-asan tasks: @@ -69,7 +69,7 @@ buildvariants: --ssl --ocsp-stapling=off -j$(grep -c ^processor /proc/cpuinfo) - test_flags: --excludeWithAnyTags=requires_fast_memory,requires_ocsp_stapling,requires_increased_memlock_limits,corrupts_data + test_flags: --excludeWithAnyTags=requires_fast_memory,requires_ocsp_stapling,requires_increased_memlock_limits multiversion_platform: rhel80 multiversion_edition: enterprise resmoke_jobs_factor: 0.3 # Avoid starting too many mongod's under ASAN build. @@ -152,7 +152,7 @@ buildvariants: --ssl --ocsp-stapling=off -j$(grep -c ^processor /proc/cpuinfo) - test_flags: --excludeWithAnyTags=requires_ocsp_stapling,requires_increased_memlock_limits,corrupts_data + test_flags: --excludeWithAnyTags=requires_ocsp_stapling,requires_increased_memlock_limits multiversion_platform: rhel80 multiversion_edition: enterprise resmoke_jobs_factor: 0.3 # Avoid starting too many mongod's under UBSAN build. @@ -235,7 +235,7 @@ buildvariants: --ssl --ocsp-stapling=off -j$(grep -c ^processor /proc/cpuinfo) - test_flags: --excludeWithAnyTags=requires_ocsp_stapling,corrupts_data + test_flags: --excludeWithAnyTags=requires_ocsp_stapling resmoke_jobs_factor: 0.3 # Avoid starting too many mongod's under {A,UB}SAN build. hang_analyzer_dump_core: false scons_cache_scope: shared diff --git a/jstests/noPassthrough/dbcheck_detects_data_corruption.js b/jstests/noPassthrough/dbcheck_detects_data_corruption.js index aaacf910996..48b0e7b81eb 100644 --- a/jstests/noPassthrough/dbcheck_detects_data_corruption.js +++ b/jstests/noPassthrough/dbcheck_detects_data_corruption.js @@ -49,7 +49,9 @@ assert.commandWorked(db.runCommand({"dbCheck": 1})); print("checking " + tojson(node)); let entry = node.getDB('local').system.healthlog.findOne({severity: 'error'}); assert(entry, "No healthlog entry found on " + tojson(node)); - assert.eq("Error fetching record from record id", entry.msg, tojson(entry)); + assert.eq("Erroneous index key found with reference to non-existent record id", + entry.msg, + tojson(entry)); // The erroneous index key should not affect the hashes. The documents should still be the same. assert.eq(1, node.getDB('local').system.healthlog.count({severity: 'error'})); diff --git a/jstests/replsets/dbcheck.js b/jstests/replsets/dbcheck.js index 733ba06d238..4d01b418409 100644 --- a/jstests/replsets/dbcheck.js +++ b/jstests/replsets/dbcheck.js @@ -19,7 +19,6 @@ import { forEachNonArbiterNode, forEachNonArbiterSecondary, injectInconsistencyOnSecondary, - logEveryBatch, runDbCheck } from "jstests/replsets/libs/dbcheck_utils.js"; @@ -33,8 +32,6 @@ replSet.startSet(); replSet.initiate(); replSet.awaitSecondaryNodes(); -logEveryBatch(replSet); - let dbName = "dbCheck-test"; let collName = "dbcheck-collection"; @@ -49,24 +46,33 @@ replSet.getPrimary().getDB(dbName)[multiBatchSimpleCollName].insertMany( // inconsistencies. function checkLogAllConsistent(conn) { let healthlog = conn.getDB("local").system.healthlog; - assert(healthlog.find().count(), "dbCheck put no batches in health log"); - let maxResult = healthlog.aggregate( - [{$match: {operation: "dbCheckBatch"}}, {$group: {_id: 1, key: {$max: "$data.batchEnd"}}}]); + const debugBuild = conn.getDB('admin').adminCommand('buildInfo').debug; - assert(maxResult.hasNext(), "dbCheck put no batches in health log"); - assert.eq( - maxResult.next().key, {"_id": {"$maxKey": 1}}, "dbCheck batches should end at MaxKey"); + if (debugBuild) { + // These tests only run on debug builds because they rely on dbCheck health-logging + // all info-level batch results. + assert(healthlog.find().count(), "dbCheck put no batches in health log"); - let minResult = healthlog.aggregate([ - {$match: {operation: "dbCheckBatch"}}, - {$group: {_id: 1, key: {$min: "$data.batchStart"}}} - ]); + let maxResult = healthlog.aggregate([ + {$match: {operation: "dbCheckBatch"}}, + {$group: {_id: 1, key: {$max: "$data.batchEnd"}}} + ]); - assert(minResult.hasNext(), "dbCheck put no batches in health log"); - assert.eq( - minResult.next().key, {"_id": {"$minKey": 1}}, "dbCheck batches should start at MinKey"); + assert(maxResult.hasNext(), "dbCheck put no batches in health log"); + assert.eq( + maxResult.next().key, {"_id": {"$maxKey": 1}}, "dbCheck batches should end at MaxKey"); + let minResult = healthlog.aggregate([ + {$match: {operation: "dbCheckBatch"}}, + {$group: {_id: 1, key: {$min: "$data.batchStart"}}} + ]); + + assert(minResult.hasNext(), "dbCheck put no batches in health log"); + assert.eq(minResult.next().key, + {"_id": {"$minKey": 1}}, + "dbCheck batches should start at MinKey"); + } // Assert no errors (i.e., found inconsistencies). let errs = healthlog.find({"severity": {"$ne": "info"}}); if (errs.hasNext()) { @@ -79,24 +85,29 @@ function checkLogAllConsistent(conn) { assert(false, "dbCheck batch failed: " + tojson(failedChecks.next())); } - // Finds an entry with data.batchStart === MinKey, and then matches its batchEnd against - // another document's batchStart, and so on, and then checks that the result of that search - // has data.batchEnd === MaxKey. - let completeCoverage = healthlog.aggregate([ - {$match: {"operation": "dbCheckBatch", "data.batchStart._id": MinKey}}, - { - $graphLookup: { - from: "system.healthlog", - startWith: "$data.batchStart", - connectToField: "data.batchStart", - connectFromField: "data.batchEnd", - as: "batchLimits", - restrictSearchWithMatch: {"operation": "dbCheckBatch"} - } - }, - {$match: {"batchLimits.data.batchEnd._id": MaxKey}} - ]); - assert(completeCoverage.hasNext(), "dbCheck batches do not cover full key range"); + if (debugBuild) { + // These tests only run on debug builds because they rely on dbCheck health-logging + // all info-level batch results. + + // Finds an entry with data.batchStart === MinKey, and then matches its batchEnd against + // another document's batchStart, and so on, and then checks that the result of that search + // has data.batchEnd === MaxKey. + let completeCoverage = healthlog.aggregate([ + {$match: {"operation": "dbCheckBatch", "data.batchStart._id": MinKey}}, + { + $graphLookup: { + from: "system.healthlog", + startWith: "$data.batchStart", + connectToField: "data.batchStart", + connectFromField: "data.batchEnd", + as: "batchLimits", + restrictSearchWithMatch: {"operation": "dbCheckBatch"} + } + }, + {$match: {"batchLimits.data.batchEnd._id": MaxKey}} + ]); + assert(completeCoverage.hasNext(), "dbCheck batches do not cover full key range"); + } } // Check that the total of all batches in the health log on `conn` is equal to the total number @@ -105,6 +116,12 @@ function checkLogAllConsistent(conn) { // Returns a document with fields "totalDocs" and "totalBytes", representing the total size of // the batches in the health log. function healthLogCounts(healthlog) { + // These tests only run on debug builds because they rely on dbCheck health-logging + // all info-level batch results. + const debugBuild = healthlog.getDB().getSiblingDB('admin').adminCommand('buildInfo').debug; + if (!debugBuild) { + return; + } let result = healthlog.aggregate([ {$match: {"operation": "dbCheckBatch"}}, { @@ -122,6 +139,12 @@ function healthLogCounts(healthlog) { } function checkTotalCounts(conn, coll) { + // These tests only run on debug builds because they rely on dbCheck health-logging + // all info-level batch results. + const debugBuild = conn.getDB('admin').adminCommand('buildInfo').debug; + if (!debugBuild) { + return; + } let result = healthLogCounts(conn.getDB("local").system.healthlog); assert.eq(result.totalDocs, coll.count(), "dbCheck batches do not count all documents"); @@ -209,6 +232,12 @@ function testDbCheckParameters() { function checkEntryBounds(start, end) { forEachNonArbiterNode(replSet, function(node) { + // These tests only run on debug builds because they rely on dbCheck health-logging + // all info-level batch results. + const debugBuild = node.getDB('admin').adminCommand('buildInfo').debug; + if (!debugBuild) { + return; + } let healthlog = node.getDB("local").system.healthlog; let keyBoundsResult = healthlog.aggregate([ @@ -284,6 +313,14 @@ function testDbCheckParameters() { checkEntryBounds(start, start + maxCount); + // The remaining tests only run on debug builds because they rely on dbCheck health-logging + // all info-level batch results. + + const debugBuild = primary.getDB('admin').adminCommand('buildInfo').debug; + if (!debugBuild) { + return; + } + const healthlog = db.getSiblingDB('local').system.healthlog; { // Validate custom maxDocsPerBatch diff --git a/jstests/replsets/dbcheck_validate_bson.js b/jstests/replsets/dbcheck_validate_bson.js deleted file mode 100644 index 61af7fa62b0..00000000000 --- a/jstests/replsets/dbcheck_validate_bson.js +++ /dev/null @@ -1,165 +0,0 @@ -/** - * Test BSON validation in the dbCheck command. - * - * @tags: [ - * featureFlagSecondaryIndexChecksInDbCheck, - * corrupts_data, - * ] - */ - -import { - checkHealthLog, - clearHealthLog, - forEachNonArbiterNode, - resetAndInsert, - runDbCheck -} from "jstests/replsets/libs/dbcheck_utils.js"; - -// Skipping data consistency checks because invalid BSON is inserted into primary and secondary -// separately. -TestData.skipCollectionAndIndexValidation = true; -TestData.skipCheckDBHashes = true; - -const dbName = "dbCheckBSONValidation"; -const collName = "dbCheckBSONValidation-collection"; - -const replSet = new ReplSetTest({ - name: jsTestName(), - nodes: 2, - nodeOptions: {setParameter: {dbCheckHealthLogEveryNBatches: 1}} -}); -replSet.startSet(); -replSet.initiateWithHighElectionTimeout(); - -const primary = replSet.getPrimary(); -const primaryDb = primary.getDB(dbName); -const secondary = replSet.getSecondary(); -const secondaryDb = secondary.getDB(dbName); -const nDocs = 10; -const maxDocsPerBatch = 2; - -const errQuery = { - operation: "dbCheckBatch", - severity: "error", -}; -const invalidBSONQuery = { - operation: "dbCheckBatch", - severity: "error", - msg: "Document is not well-formed BSON", - "data.context.recordID": {$exists: true} -}; -const invalidHashQuery = { - operation: "dbCheckBatch", - severity: "error", - msg: "dbCheck batch inconsistent", - "data.md5": {$exists: true} -}; -const successfulBatchQuery = { - operation: "dbCheckBatch", - severity: "info", - msg: "dbCheck batch consistent", - "data.count": maxDocsPerBatch -}; - -const doc1 = { - _id: 0, - a: 1 -}; - -// The default WC is majority and godinsert command on a secondary is incompatible with -// wc:majority. -assert.commandWorked(primary.adminCommand( - {setDefaultRWConcern: 1, defaultWriteConcern: {w: 1}, writeConcern: {w: "majority"}})); - -// Insert corrupt document for testing via failpoint. -const insertCorruptDocument = function(db, collName) { - assert.commandWorked( - db.adminCommand({configureFailPoint: "corruptDocumentOnInsert", mode: "alwaysOn"})); - // Use godinsert to insert into the node directly. - assert.commandWorked(db.runCommand({godinsert: collName, obj: doc1})); - assert.commandWorked( - db.adminCommand({configureFailPoint: "corruptDocumentOnInsert", mode: "off"})); -}; - -function testKDefaultBSONValidation() { - jsTestLog("Testing that dbCheck logs error in health log when node has kDefault invalid BSON."); - - clearHealthLog(replSet); - - // Insert invalid BSON that fails the kDefault check into both nodes in the replica set. - assert.commandWorked(primaryDb.createCollection(collName)); - replSet.awaitReplication(); - forEachNonArbiterNode(replSet, function(node) { - insertCorruptDocument(node.getDB(dbName), collName); - }); - - // Both primary and secondary should have error in health log for invalid BSON. - runDbCheck( - replSet, primaryDb, collName, {validateMode: "dataConsistencyAndMissingIndexKeysCheck"}); - - // Primary and secondary have the same invalid BSON document so there is an error for invalid - // BSON but not data inconsistency. We check that the only errors in the health log are for - // invalid BSON. - checkHealthLog(primary.getDB("local").system.healthlog, invalidBSONQuery, 1); - checkHealthLog(secondary.getDB("local").system.healthlog, invalidBSONQuery, 1); - checkHealthLog(primary.getDB("local").system.healthlog, errQuery, 1); - checkHealthLog(secondary.getDB("local").system.healthlog, errQuery, 1); -} - -function testPrimaryInvalidBson() { - jsTestLog("Testing when the primary has invalid BSON but the secondary does not."); - - clearHealthLog(replSet); - - // Insert an invalid document on the primary. - insertCorruptDocument(primaryDb, collName); - - // Insert a normal document on the secondary. - assert.commandWorked(secondaryDb.runCommand({godinsert: collName, obj: doc1})); - - runDbCheck(replSet, primaryDb, collName, { - maxDocsPerBatch: maxDocsPerBatch, - validateMode: "dataConsistencyAndMissingIndexKeysCheck" - }); - - // Verify primary logs an error for invalid BSON and data inconsistency. - checkHealthLog(secondary.getDB("local").system.healthlog, invalidBSONQuery, 1); - checkHealthLog(secondary.getDB("local").system.healthlog, invalidHashQuery, 1); -} - -function testMultipleBatches() { - jsTestLog("Testing that invalid BSON check works across multiple batches."); - - clearHealthLog(replSet); - - // Primary contains 10 valid documents, secondary contains 9 valid and 1 invalid document. - resetAndInsert(replSet, primaryDb, collName, nDocs - 1); - assert.commandWorked(primaryDb.runCommand({godinsert: collName, obj: {_id: 0, a: nDocs}})); - insertCorruptDocument(secondaryDb, collName); - - runDbCheck(replSet, primaryDb, collName, { - maxDocsPerBatch: maxDocsPerBatch, - validateMode: "dataConsistencyAndMissingIndexKeysCheck" - }); - - // Secondary logs an error for invalid BSON and data inconsistency. - checkHealthLog(secondary.getDB("local").system.healthlog, invalidBSONQuery, 1); - checkHealthLog(secondary.getDB("local").system.healthlog, invalidHashQuery, 1); - - // Primary and secondary do not terminate after first batch and finish dbCheck successfully. - checkHealthLog( - primary.getDB("local").system.healthlog, successfulBatchQuery, nDocs / maxDocsPerBatch); - checkHealthLog(secondary.getDB("local").system.healthlog, - successfulBatchQuery, - (nDocs / maxDocsPerBatch) - 1); - // There should be no other error queries. - checkHealthLog(primary.getDB("local").system.healthlog, errQuery, 0); - checkHealthLog(secondary.getDB("local").system.healthlog, errQuery, 2); - checkHealthLog(primary.getDB("local").system.healthlog, {operation: "dbCheckStop"}, 1); - checkHealthLog(secondary.getDB("local").system.healthlog, {operation: "dbCheckStop"}, 1); -} - -testKDefaultBSONValidation(); -testMultipleBatches(); - -replSet.stopSet(); diff --git a/jstests/replsets/libs/dbcheck_utils.js b/jstests/replsets/libs/dbcheck_utils.js index 8b8045bcb17..10517b20f93 100644 --- a/jstests/replsets/libs/dbcheck_utils.js +++ b/jstests/replsets/libs/dbcheck_utils.js @@ -23,13 +23,6 @@ export const clearHealthLog = (replSet) => { replSet.awaitReplication(); }; -export const logEveryBatch = - (replSet) => { - forEachNonArbiterNode(replSet, conn => { - conn.adminCommand({setParameter: 1, "dbCheckHealthLogEveryNBatches": 1}); - }) - } - export const dbCheckCompleted = (db) => { return db.getSiblingDB("admin").currentOp().inprog == undefined || db.getSiblingDB("admin").currentOp().inprog.filter(x => x["desc"] == "dbCheck")[0] === diff --git a/src/mongo/db/commands/dbcheck.cpp b/src/mongo/db/commands/dbcheck.cpp index 69ed093b166..29023225b64 100644 --- a/src/mongo/db/commands/dbcheck.cpp +++ b/src/mongo/db/commands/dbcheck.cpp @@ -186,7 +186,6 @@ public: boost::none /*collectionUUID*/, SeverityEnum::Info, "", - ScopeEnum::Cluster, OplogEntriesEnum::Start, boost::none /*data*/); if (_info && _info.value().secondaryIndexCheckParameters) { @@ -214,7 +213,6 @@ public: boost::none /*collectionUUID*/, SeverityEnum::Info, "", - ScopeEnum::Cluster, OplogEntriesEnum::Stop, boost::none /*data*/); if (_info && _info.value().secondaryIndexCheckParameters) { @@ -493,7 +491,6 @@ protected: coll.uuid, "abandoning dbCheck batch because collection no longer exists, but " "there is a view with the identical name", - ScopeEnum::Collection, OplogEntriesEnum::Batch, Status(ErrorCodes::NamespaceNotFound, "Collection under dbCheck no longer exists, but there is a view " @@ -501,13 +498,8 @@ protected: HealthLogInterface::get(opCtx)->log(*entry); return; } catch (const DBException& e) { - std::unique_ptr logEntry = - dbCheckErrorHealthLogEntry(coll.nss, - coll.uuid, - "dbCheck failed", - ScopeEnum::Cluster, - OplogEntriesEnum::Batch, - e.toStatus()); + std::unique_ptr logEntry = dbCheckErrorHealthLogEntry( + coll.nss, coll.uuid, "dbCheck failed", OplogEntriesEnum::Batch, e.toStatus()); HealthLogInterface::get(Client::getCurrent()->getServiceContext())->log(*logEntry); return; } @@ -576,7 +568,6 @@ private: "abandoning dbCheck batch because collection no longer exists, but " "there " "is a view with the identical name", - ScopeEnum::Collection, OplogEntriesEnum::Batch, Status(ErrorCodes::NamespaceNotFound, "Collection under dbCheck no longer existsCollection under " @@ -588,7 +579,6 @@ private: dbCheckErrorHealthLogEntry(info.nss, info.uuid, "dbCheck batch failed", - ScopeEnum::Index, OplogEntriesEnum::Batch, ex.toStatus()); HealthLogInterface::get(opCtx)->log(*entry); @@ -625,7 +615,6 @@ private: info.nss, info.uuid, "abandoning dbCheck extra index keys check because collection no longer exists", - ScopeEnum::Collection, OplogEntriesEnum::Batch, status); HealthLogInterface::get(opCtx)->log(*logEntry); @@ -644,7 +633,6 @@ private: info.nss, info.uuid, "abandoning dbCheck extra index keys check because index no longer exists", - ScopeEnum::Index, OplogEntriesEnum::Batch, status); HealthLogInterface::get(opCtx)->log(*logEntry); @@ -734,7 +722,6 @@ private: // 2. Get the actual first and last keystrings processed from reverse lookup. batchFirst = batchStats.firstIndexKey; auto batchLast = batchStats.lastIndexKey; - // If batchLast is not initialized, that means there was an error with batching. if (batchLast.isEmpty()) { LOGV2_DEBUG(7844903, @@ -750,7 +737,6 @@ private: info.nss, info.uuid, "abandoning dbCheck extra index keys check because of error with batching", - ScopeEnum::Index, OplogEntriesEnum::Batch, status); HealthLogInterface::get(opCtx)->log(*logEntry); @@ -849,7 +835,6 @@ private: info.nss, info.uuid, "abandoning dbCheck extra index keys check because collection no longer exists", - ScopeEnum::Index, OplogEntriesEnum::Batch, status); HealthLogInterface::get(opCtx)->log(*logEntry); @@ -879,7 +864,6 @@ private: info.nss, info.uuid, "abandoning dbCheck extra index keys check because index no longer exists", - ScopeEnum::Index, OplogEntriesEnum::Batch, status); HealthLogInterface::get(opCtx)->log(*logEntry); @@ -961,7 +945,6 @@ private: info.uuid, SeverityEnum::Info, "dbcheck extra keys check batch on primary", - ScopeEnum::Index, OplogEntriesEnum::Batch, builder.obj()); @@ -1050,7 +1033,6 @@ private: info.nss, info.uuid, "abandoning dbCheck extra index keys check because collection no longer exists", - ScopeEnum::Collection, OplogEntriesEnum::Batch, status); HealthLogInterface::get(opCtx)->log(*logEntry); @@ -1072,7 +1054,6 @@ private: info.nss, info.uuid, "abandoning dbCheck extra index keys check because index no longer exists", - ScopeEnum::Index, OplogEntriesEnum::Batch, status); HealthLogInterface::get(opCtx)->log(*logEntry); @@ -1141,7 +1122,6 @@ private: info.uuid, "abandoning dbCheck extra index keys check because " "there are no keys left in the index", - ScopeEnum::Index, OplogEntriesEnum::Batch, status); HealthLogInterface::get(opCtx)->log(*logEntry); @@ -1267,7 +1247,6 @@ private: info.nss, info.uuid, "found extra index key entry without corresponding document", - ScopeEnum::Index, OplogEntriesEnum::Batch, status, context.done()); @@ -1346,7 +1325,6 @@ private: "found index key entry with corresponding " "document/keystring set that does not " "contain the expected key string", - ScopeEnum::Index, OplogEntriesEnum::Batch, status, context.done()); @@ -1395,7 +1373,6 @@ private: info.nss, info.uuid, "abandoning dbCheck batch because collection no longer exists", - ScopeEnum::Collection, OplogEntriesEnum::Batch, Status(ErrorCodes::NamespaceNotFound, collNotFoundMsg)); HealthLogInterface::get(Client::getCurrent()->getServiceContext())->log(*entry); @@ -1449,7 +1426,6 @@ private: info.nss, info.uuid, "retrying dbCheck batch after timeout due to lock unavailability", - ScopeEnum::Collection, OplogEntriesEnum::Batch, result.getStatus()); } else if (code == ErrorCodes::SnapshotUnavailable) { @@ -1458,7 +1434,6 @@ private: info.nss, info.uuid, "retrying dbCheck batch after conflict with pending catalog operation", - ScopeEnum::Collection, OplogEntriesEnum::Batch, result.getStatus()); } else if (code == ErrorCodes::NamespaceNotFound) { @@ -1466,7 +1441,6 @@ private: info.nss, info.uuid, "abandoning dbCheck batch because collection no longer exists", - ScopeEnum::Collection, OplogEntriesEnum::Batch, result.getStatus()); } else if (code == ErrorCodes::CommandNotSupportedOnView) { @@ -1475,7 +1449,6 @@ private: "abandoning dbCheck batch because " "collection no longer exists, but there " "is a view with the identical name", - ScopeEnum::Collection, OplogEntriesEnum::Batch, result.getStatus()); } else if (code == ErrorCodes::IndexNotFound) { @@ -1483,7 +1456,6 @@ private: info.nss, info.uuid, "skipping dbCheck on collection because it is missing an _id index", - ScopeEnum::Collection, OplogEntriesEnum::Batch, result.getStatus()); } else if (ErrorCodes::isA(code)) { @@ -1491,14 +1463,12 @@ private: info.nss, info.uuid, "stopping dbCheck because node is no longer primary", - ScopeEnum::Cluster, OplogEntriesEnum::Batch, result.getStatus()); } else { entry = dbCheckErrorHealthLogEntry(info.nss, info.uuid, "dbCheck batch failed", - ScopeEnum::Collection, OplogEntriesEnum::Batch, result.getStatus()); if (code == ErrorCodes::NoSuchKey) { @@ -1540,7 +1510,6 @@ private: auto entry = dbCheckWarningHealthLogEntry(info.nss, info.uuid, "dbCheck failed waiting for writeConcern", - ScopeEnum::Collection, OplogEntriesEnum::Batch, status); HealthLogInterface::get(opCtx)->log(*entry); @@ -1623,7 +1592,6 @@ private: readTimestamp); boost::optional hasher; - Status status = Status::OK(); try { hasher.emplace(opCtx, collectionPtr, @@ -1633,27 +1601,16 @@ private: boost::none, std::min(batchDocs, info.maxCount), std::min(batchBytes, info.maxSize)); - - const auto batchDeadline = Date_t::now() + Milliseconds(info.maxBatchTimeMillis); - status = hasher->hashForCollectionCheck(opCtx, collectionPtr, batchDeadline); } catch (const DBException& e) { return e.toStatus(); } + const auto batchDeadline = Date_t::now() + Milliseconds(info.maxBatchTimeMillis); + + Status status = hasher->hashForCollectionCheck(opCtx, collectionPtr, batchDeadline); + if (!status.isOK()) { - // dbCheck should still continue if we get an error fetching a record. - if (status.code() == ErrorCodes::KeyNotFound) { - std::unique_ptr healthLogEntry = - dbCheckErrorHealthLogEntry(info.nss, - info.uuid, - "Error fetching record from record id", - ScopeEnum::Index, - OplogEntriesEnum::Batch, - status); - HealthLogInterface::get(opCtx)->log(*healthLogEntry); - } else { - return status; - } + return status; } std::string md5 = hasher->total(); diff --git a/src/mongo/db/repl/dbcheck.cpp b/src/mongo/db/repl/dbcheck.cpp index d039348bd81..6c1a73a44cd 100644 --- a/src/mongo/db/repl/dbcheck.cpp +++ b/src/mongo/db/repl/dbcheck.cpp @@ -173,7 +173,6 @@ std::unique_ptr dbCheckHealthLogEntry(const boost::optional& collectionUUID, SeverityEnum severity, const std::string& msg, - ScopeEnum scope, OplogEntriesEnum operation, const boost::optional& data) { auto entry = std::make_unique(); @@ -185,7 +184,7 @@ std::unique_ptr dbCheckHealthLogEntry(const boost::optionalsetTimestamp(Date_t::now()); entry->setSeverity(severity); - entry->setScope(scope); + entry->setScope(ScopeEnum::Cluster); entry->setMsg(msg); entry->setOperation(renderForHealthLog(operation)); if (data) { @@ -201,7 +200,6 @@ std::unique_ptr dbCheckErrorHealthLogEntry( const boost::optional& nss, const boost::optional& collectionUUID, const std::string& msg, - ScopeEnum scope, OplogEntriesEnum operation, const Status& err, const BSONObj& context) { @@ -210,7 +208,6 @@ std::unique_ptr dbCheckErrorHealthLogEntry( collectionUUID, SeverityEnum::Error, msg, - scope, operation, BSON("success" << false << "error" << err.toString() << "context" << context)); } @@ -219,14 +216,12 @@ std::unique_ptr dbCheckWarningHealthLogEntry( const NamespaceString& nss, const boost::optional& collectionUUID, const std::string& msg, - ScopeEnum scope, OplogEntriesEnum operation, const Status& err) { return dbCheckHealthLogEntry(nss, collectionUUID, SeverityEnum::Warning, msg, - ScopeEnum::Cluster, operation, BSON("success" << false << "error" << err.toString())); } @@ -286,13 +281,8 @@ std::unique_ptr dbCheckBatchEntry( std::string msg = "dbCheck batch " + (hashesMatch ? std::string("consistent") : std::string("inconsistent")); - return dbCheckHealthLogEntry(nss, - collectionUUID, - severity, - msg, - ScopeEnum::Cluster, - OplogEntriesEnum::Batch, - builder.obj()); + return dbCheckHealthLogEntry( + nss, collectionUUID, severity, msg, OplogEntriesEnum::Batch, builder.obj()); } template @@ -347,7 +337,7 @@ DbCheckHasher::DbCheckHasher( BoundInclusion::kIncludeEndKeyOnly, PlanYieldPolicy::YieldPolicy::NO_YIELD, InternalPlanner::FORWARD, - InternalPlanner::IXSCAN_DEFAULT); + InternalPlanner::IXSCAN_FETCH); } else { CollectionScanParams params; params.minRecord = RecordIdBound(uassertStatusOK( @@ -536,62 +526,24 @@ Status DbCheckHasher::validateMissingKeys(OperationContext* opCtx, Status DbCheckHasher::hashForCollectionCheck(OperationContext* opCtx, const CollectionPtr& collPtr, Date_t deadline) { - BSONObj currentObjId; + BSONObj currentObj; RecordId currentRecordId; - RecordData record; PlanExecutor::ExecState lastState; - // Iterate through the _id index and obtain the object ID and record ID pair. If the _id index - // key entry is corrupt, getNext() will throw an exception and we will fail the batch. - while (PlanExecutor::ADVANCED == - (lastState = _exec->getNext(¤tObjId, ¤tRecordId))) { + while (PlanExecutor::ADVANCED == (lastState = _exec->getNext(nullptr, ¤tRecordId))) { SleepDbCheckInBatch.execute([opCtx](const BSONObj& data) { int sleepMs = data["sleepMs"].safeNumberInt(); opCtx->sleepFor(Milliseconds(sleepMs)); }); + RecordData record; if (!collPtr->getRecordStore()->findRecord(opCtx, currentRecordId, &record)) { // TODO (SERVER-81117): Determine if this is the correct error code to return. - const auto msg = "Error fetching record from record id"; - const auto status = Status(ErrorCodes::KeyNotFound, msg); - const auto logEntry = - dbCheckErrorHealthLogEntry(collPtr->ns(), - collPtr->uuid(), - msg, - ScopeEnum::Document, - OplogEntriesEnum::Batch, - status, - BSON("recordID" << currentRecordId.toString())); - HealthLogInterface::get(opCtx)->log(*logEntry); - - // If we cannot find the record in the record store, continue onto the next recordId. - // The inconsistency will be caught when we compare hashes. - continue; - } - - // We validate the record data before parsing it into a BSONObj, as parsing it into a - // BSONObj may hide some of the corruption. - int currentObjSize = record.size(); - const char* currentObjData = record.data(); - - if (_secondaryIndexCheckParameters && - _secondaryIndexCheckParameters.value().getValidateMode() == - DbCheckValidationModeEnum::dataConsistencyAndMissingIndexKeysCheck) { - const auto status = - validateBSON(currentObjData, currentObjSize, BSONValidateMode::kDefault); - if (!status.isOK()) { - const auto msg = "Document is not well-formed BSON"; - const auto logEntry = - dbCheckErrorHealthLogEntry(collPtr->ns(), - collPtr->uuid(), - msg, - ScopeEnum::Document, - OplogEntriesEnum::Batch, - status, - BSON("recordID" << currentRecordId.toString())); - HealthLogInterface::get(opCtx)->log(*logEntry); - } + return Status(ErrorCodes::NoSuchKey, + "Could not find record ID: " + currentRecordId.toString()); } + // If _id is corrupt, getNext() will throw an exception and we'll fail the batch. If any + // other field is invalid, toBson() will still parse the raw record data and get the hash. BSONObj currentObj = record.toBson(); if (!currentObj.hasField("_id")) { // TODO (SERVER-81117): Determine if this is the correct error code to return. @@ -617,7 +569,6 @@ Status DbCheckHasher::hashForCollectionCheck(OperationContext* opCtx, collPtr->ns(), collPtr->uuid(), msg, - ScopeEnum::Document, OplogEntriesEnum::Batch, status, BSON("recordID" << currentRecordId.toString() << "missingIndexKeys" @@ -627,17 +578,12 @@ Status DbCheckHasher::hashForCollectionCheck(OperationContext* opCtx, } } - // Update `last` every time. currentObjId was a BSONObj obtained from the _id index scan - // with 1 field in the form {"": _id}. We rehydrate it to add the field names back. - // - // We use the _id value obtained from the _id index walk so that we can store our last seen - // _id and proceed with dbCheck even if the previous record had corruption in its _id - // field. - _last = key_string::rehydrateKey(BSON("_id" << 1), currentObjId); - _countSeen += 1; + // Update `last` every time. + _last = BSON("_id" << currentObj["_id"]); _bytesSeen += currentObj.objsize(); + _countSeen += 1; - md5_append(&_state, md5Cast(currentObjData), currentObjSize); + md5_append(&_state, md5Cast(currentObj.objdata()), currentObj.objsize()); if (Date_t::now() > deadline) { break; @@ -718,7 +664,6 @@ Status dbCheckBatchOnSecondary(OperationContext* opCtx, boost::none, SeverityEnum::Info, "dbCheck failed", - ScopeEnum::Cluster, OplogEntriesEnum::Batch, BSON("success" << false << "info" << msg)); HealthLogInterface::get(opCtx)->log(*logEntry); @@ -770,7 +715,6 @@ Status dbCheckBatchOnSecondary(OperationContext* opCtx, boost::none, SeverityEnum::Error, "dbCheck failed", - ScopeEnum::Index, OplogEntriesEnum::Batch, BSON("success" << false << "info" << msg)); HealthLogInterface::get(opCtx)->log(*logEntry); @@ -809,19 +753,7 @@ Status dbCheckBatchOnSecondary(OperationContext* opCtx, } else { hasher.emplace( opCtx, collection, batchStart, batchEnd, entry.getSecondaryIndexCheckParameters()); - const auto status = hasher->hashForCollectionCheck(opCtx, collection); - if (!status.isOK() && status.code() == ErrorCodes::KeyNotFound) { - std::unique_ptr healthLogEntry = - dbCheckErrorHealthLogEntry(entry.getNss(), - collection->uuid(), - "Error fetching record from record id", - ScopeEnum::Index, - OplogEntriesEnum::Batch, - status); - HealthLogInterface::get(opCtx)->log(*healthLogEntry); - return Status::OK(); - } - uassertStatusOK(status); + uassertStatusOK(hasher->hashForCollectionCheck(opCtx, collection)); } std::string expected = entry.getMd5().toString(); @@ -865,7 +797,6 @@ Status dbCheckBatchOnSecondary(OperationContext* opCtx, auto logEntry = dbCheckErrorHealthLogEntry(entry.getNss(), boost::none, msg, - ScopeEnum::Cluster, OplogEntriesEnum::Batch, exception.toStatus(), entry.toBSON()); @@ -909,7 +840,6 @@ Status dbCheckOplogCommand(OperationContext* opCtx, boost::none /*collectionUUID*/, SeverityEnum::Info, "", - ScopeEnum::Cluster, type, boost::none /*data*/); const auto secondaryIndexCheckParameters = diff --git a/src/mongo/db/repl/dbcheck.h b/src/mongo/db/repl/dbcheck.h index 5743d7e4768..4e903189298 100644 --- a/src/mongo/db/repl/dbcheck.h +++ b/src/mongo/db/repl/dbcheck.h @@ -83,7 +83,6 @@ std::unique_ptr dbCheckHealthLogEntry(const boost::optional& collectionUUID, SeverityEnum severity, const std::string& msg, - ScopeEnum scope, OplogEntriesEnum operation, const boost::optional& data); @@ -94,7 +93,6 @@ std::unique_ptr dbCheckErrorHealthLogEntry( const boost::optional& nss, const boost::optional& collectionUUID, const std::string& msg, - ScopeEnum scope, OplogEntriesEnum operation, const Status& err, const BSONObj& context = BSONObj()); @@ -103,7 +101,6 @@ std::unique_ptr dbCheckWarningHealthLogEntry( const NamespaceString& nss, const boost::optional& collectionUUID, const std::string& msg, - ScopeEnum scope, OplogEntriesEnum operation, const Status& err); /** @@ -201,7 +198,7 @@ public: private: /** - * Checks if we can hash `obj` without going over our limits. + * Can we hash `obj` without going over our limits? */ bool _canHash(const BSONObj& obj);