SERVER-121895 fix document validation log messages (#50542)
GitOrigin-RevId: ca5ef0299dfe2825bbb0bec793b7d5a67d30152a
This commit is contained in:
Mickey J Winters
MongoDB Bot
parent
1c7b07a7b0
commit
dfe461c174
@ -19,6 +19,7 @@ import {ShardingTest} from "jstests/libs/shardingtest.js";
|
||||
const collName = jsTestName();
|
||||
const warnLogId = 20294;
|
||||
const errorAndLogId = 7488700;
|
||||
const hasEnterpriseModule = getBuildInfo().modules.includes("enterprise");
|
||||
|
||||
function checkLogsForFailedValidation(db, logId) {
|
||||
// In case of sharded deployments, look on all shards and expect the log to be found on one of
|
||||
@ -84,11 +85,75 @@ function runTest(db) {
|
||||
assert.eq("warn", info.options.validationAction, tojson(info));
|
||||
}
|
||||
|
||||
function runTestWithRedaction(db) {
|
||||
if (!hasEnterpriseModule) {
|
||||
jsTest.log.info("Skipping redaction test: enterprise module not available");
|
||||
return;
|
||||
}
|
||||
|
||||
const t = db[collName + "_redact"];
|
||||
t.drop();
|
||||
|
||||
const redactedErrInfo = {
|
||||
failingDocumentId: 1,
|
||||
details: {
|
||||
operatorName: "$eq",
|
||||
specifiedAs: {a: 1},
|
||||
reason: "comparison failed",
|
||||
consideredValue: "###",
|
||||
},
|
||||
};
|
||||
|
||||
// Test warn mode with redaction.
|
||||
assert.commandWorked(db.createCollection(t.getName(), {validator: {a: 1}, validationAction: "warn"}));
|
||||
assert.commandWorked(t.insert({_id: 1, a: 1}));
|
||||
|
||||
assert.commandWorked(db.adminCommand({setParameter: 1, redactClientLogData: true}));
|
||||
try {
|
||||
assert.commandWorked(t.update({}, {$set: {a: 2}}));
|
||||
} finally {
|
||||
assert.commandWorked(db.adminCommand({setParameter: 1, redactClientLogData: false}));
|
||||
}
|
||||
|
||||
assert(
|
||||
checkLog.checkContainsOnceJson(db, warnLogId, {
|
||||
"errInfo": function (obj) {
|
||||
return documentEq(obj, redactedErrInfo);
|
||||
},
|
||||
}),
|
||||
);
|
||||
|
||||
// Test errorAndLog mode with redaction.
|
||||
if (FeatureFlagUtil.isPresentAndEnabled(db, "ErrorAndLogValidationAction")) {
|
||||
const res = assert.commandWorkedOrFailedWithCode(
|
||||
t.runCommand("collMod", {validationAction: "errorAndLog"}),
|
||||
ErrorCodes.InvalidOptions,
|
||||
);
|
||||
if (res.ok) {
|
||||
assert.commandWorked(db.adminCommand({setParameter: 1, redactClientLogData: true}));
|
||||
try {
|
||||
assertFailsValidation(t.update({_id: 1}, {$set: {a: 3}}));
|
||||
} finally {
|
||||
assert.commandWorked(db.adminCommand({setParameter: 1, redactClientLogData: false}));
|
||||
}
|
||||
|
||||
assert(
|
||||
checkLog.checkContainsOnceJson(db, errorAndLogId, {
|
||||
"errInfo": function (obj) {
|
||||
return documentEq(obj, redactedErrInfo);
|
||||
},
|
||||
}),
|
||||
);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
(function testStandalone() {
|
||||
const conn = MongoRunner.runMongod();
|
||||
const db = conn.getDB(jsTestName());
|
||||
try {
|
||||
runTest(db);
|
||||
runTestWithRedaction(db);
|
||||
} finally {
|
||||
MongoRunner.stopMongod(conn);
|
||||
}
|
||||
|
||||
@ -25,6 +25,7 @@ mongo_cc_unit_test(
|
||||
name = "doc_validation_test",
|
||||
srcs = [
|
||||
"doc_validation_error_json_schema_test.cpp",
|
||||
"doc_validation_error_redaction_test.cpp",
|
||||
"doc_validation_error_test.cpp",
|
||||
],
|
||||
tags = ["mongo_unittest_fourth_group"],
|
||||
|
||||
@ -71,6 +71,8 @@
|
||||
#include "mongo/db/matcher/schema/expression_internal_schema_xor.h"
|
||||
#include "mongo/db/query/compiler/parsers/matcher/schema/json_schema_parser.h"
|
||||
#include "mongo/db/query/tree_walker.h"
|
||||
#include "mongo/logv2/log_util.h"
|
||||
#include "mongo/logv2/redaction.h"
|
||||
#include "mongo/stdx/unordered_set.h"
|
||||
#include "mongo/util/assert_util.h"
|
||||
#include "mongo/util/fail_point.h"
|
||||
@ -2467,6 +2469,45 @@ const BSONObj& DocumentValidationFailureInfo::getDetails() const {
|
||||
return _details;
|
||||
}
|
||||
|
||||
namespace {
|
||||
// Search the object recursively and redact the content of "consideredValue" and "consideredValues"
|
||||
// fields wherever they are.
|
||||
BSONObj redactConsideredValues(const BSONObj& obj) {
|
||||
BSONObjBuilder bob;
|
||||
for (auto&& elem : obj) {
|
||||
StringData fieldName = elem.fieldNameStringData();
|
||||
if (fieldName == "consideredValue"_sd || fieldName == "consideredValues"_sd) {
|
||||
// use temp object to recycle redact() behavior.
|
||||
BSONObjBuilder temp;
|
||||
temp.append(elem);
|
||||
const BSONObj redacted = redact(temp.obj());
|
||||
bob.append(redacted.firstElement());
|
||||
} else if (elem.type() == BSONType::object) {
|
||||
bob.append(fieldName, redactConsideredValues(elem.Obj()));
|
||||
} else if (elem.type() == BSONType::array) {
|
||||
BSONArrayBuilder arrayBuilder(bob.subarrayStart(fieldName));
|
||||
for (auto&& arrElem : elem.Obj()) {
|
||||
if (arrElem.type() == BSONType::object) {
|
||||
arrayBuilder.append(redactConsideredValues(arrElem.Obj()));
|
||||
} else {
|
||||
arrayBuilder.append(arrElem);
|
||||
}
|
||||
}
|
||||
} else {
|
||||
bob.append(elem);
|
||||
}
|
||||
}
|
||||
return bob.obj();
|
||||
}
|
||||
} // namespace
|
||||
|
||||
BSONObj DocumentValidationFailureInfo::getRedactedDetails() const {
|
||||
if (!logv2::shouldRedactLogs() && !logv2::shouldRedactBinDataEncrypt()) {
|
||||
return getDetails();
|
||||
}
|
||||
return redactConsideredValues(getDetails());
|
||||
}
|
||||
|
||||
BSONObj generateError(const MatchExpression& validatorExpr,
|
||||
const BSONObj& doc,
|
||||
const int maxDocValidationErrorSize,
|
||||
|
||||
@ -61,6 +61,7 @@ public:
|
||||
!err.isEmpty());
|
||||
}
|
||||
const BSONObj& getDetails() const;
|
||||
BSONObj getRedactedDetails() const;
|
||||
void serialize(BSONObjBuilder* bob) const override;
|
||||
|
||||
private:
|
||||
|
||||
@ -0,0 +1,190 @@
|
||||
/**
|
||||
* Copyright (C) 2026-present MongoDB, Inc.
|
||||
*
|
||||
* This program is free software: you can redistribute it and/or modify
|
||||
* it under the terms of the Server Side Public License, version 1,
|
||||
* as published by MongoDB, Inc.
|
||||
*
|
||||
* This program is distributed in the hope that it will be useful,
|
||||
* but WITHOUT ANY WARRANTY; without even the implied warranty of
|
||||
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
|
||||
* Server Side Public License for more details.
|
||||
*
|
||||
* You should have received a copy of the Server Side Public License
|
||||
* along with this program. If not, see
|
||||
* <http://www.mongodb.com/licensing/server-side-public-license>.
|
||||
*
|
||||
* As a special exception, the copyright holders give permission to link the
|
||||
* code of portions of this program with the OpenSSL library under certain
|
||||
* conditions as described in each individual source file and distribute
|
||||
* linked combinations including the program with the OpenSSL library. You
|
||||
* must comply with the Server Side Public License in all respects for
|
||||
* all of the code used other than as permitted herein. If you modify file(s)
|
||||
* with this exception, you may extend this exception to your version of the
|
||||
* file(s), but you are not obligated to do so. If you do not wish to do so,
|
||||
* delete this exception statement from your version. If you delete this
|
||||
* exception statement from all source files in the program, then also delete
|
||||
* it in the license file.
|
||||
*/
|
||||
|
||||
#include "mongo/bson/bsonobj.h"
|
||||
#include "mongo/bson/bsonobjbuilder.h"
|
||||
#include "mongo/bson/bsontypes.h"
|
||||
#include "mongo/bson/json.h"
|
||||
#include "mongo/db/exec/matcher/matcher.h"
|
||||
#include "mongo/db/matcher/doc_validation/doc_validation_error.h"
|
||||
#include "mongo/db/pipeline/expression_context_for_test.h"
|
||||
#include "mongo/db/query/compiler/parsers/matcher/expression_parser.h"
|
||||
#include "mongo/logv2/log_util.h"
|
||||
#include "mongo/unittest/unittest.h"
|
||||
|
||||
#include <boost/smart_ptr/intrusive_ptr.hpp>
|
||||
|
||||
namespace mongo::doc_validation_error {
|
||||
namespace {
|
||||
|
||||
// RAII guard that restores both redaction flags on destruction.
|
||||
struct RedactionGuard {
|
||||
RedactionGuard(bool redactLogs, bool redactBinDataEncrypt) {
|
||||
logv2::setShouldRedactLogs(redactLogs);
|
||||
logv2::setShouldRedactBinDataEncrypt(redactBinDataEncrypt);
|
||||
}
|
||||
~RedactionGuard() {
|
||||
logv2::setShouldRedactLogs(false);
|
||||
logv2::setShouldRedactBinDataEncrypt(false);
|
||||
}
|
||||
};
|
||||
|
||||
BSONObj makeError(const BSONObj& query, const BSONObj& doc) {
|
||||
boost::intrusive_ptr<ExpressionContextForTest> expCtx(new ExpressionContextForTest());
|
||||
expCtx->setIsParsingCollectionValidator(true);
|
||||
auto result = MatchExpressionParser::parse(query, expCtx);
|
||||
ASSERT_OK(result.getStatus());
|
||||
MatchExpression* expr = result.getValue().get();
|
||||
ASSERT_FALSE(exec::matcher::matchesBSON(expr, doc));
|
||||
return generateError(*expr,
|
||||
doc.hasField("_id") ? doc : doc.addField(BSON("_id" << 1).firstElement()),
|
||||
kDefaultMaxDocValidationErrorSize,
|
||||
10);
|
||||
}
|
||||
|
||||
// When neither redaction flag is set, getRedactedDetails() must return the same object as
|
||||
// getDetails().
|
||||
TEST(DocValidationRedaction, RedactionDisabled) {
|
||||
RedactionGuard guard(false, false);
|
||||
BSONObj details =
|
||||
BSON("failingDocumentId" << 1 << "details"
|
||||
<< BSON("operatorName" << "$eq"
|
||||
<< "consideredValue" << 42 << "reason"
|
||||
<< "comparison failed"));
|
||||
DocumentValidationFailureInfo info(details);
|
||||
ASSERT_BSONOBJ_EQ(info.getDetails(), info.getRedactedDetails());
|
||||
}
|
||||
|
||||
// With full log redaction enabled, only 'consideredValue' and 'consideredValues' fields should be
|
||||
// replaced with "###". Other fields (operatorName, specifiedAs, reason) must be left unchanged.
|
||||
TEST(DocValidationRedaction, OnlyConsideredValueFieldsAreRedacted) {
|
||||
RedactionGuard guard(true, false);
|
||||
BSONObj details = BSON("failingDocumentId"
|
||||
<< 1 << "details"
|
||||
<< BSON("operatorName" << "$eq"
|
||||
<< "specifiedAs" << BSON("a" << 1) << "reason"
|
||||
<< "comparison failed"
|
||||
<< "consideredValue" << 99));
|
||||
DocumentValidationFailureInfo info(details);
|
||||
BSONObj redacted = info.getRedactedDetails();
|
||||
|
||||
auto d = redacted["details"].Obj();
|
||||
ASSERT_EQ(d["operatorName"].str(), "$eq");
|
||||
ASSERT_EQ(d["reason"].str(), "comparison failed");
|
||||
ASSERT_BSONOBJ_EQ(d["specifiedAs"].Obj(), BSON("a" << 1));
|
||||
ASSERT_EQ(d["consideredValue"].str(), "###");
|
||||
}
|
||||
|
||||
// Trivial flat case: a top-level consideredValue field is redacted.
|
||||
TEST(DocValidationRedaction, TrivialFlatRedaction) {
|
||||
RedactionGuard guard(true, false);
|
||||
BSONObj details = BSON("consideredValue" << "sensitiveString");
|
||||
DocumentValidationFailureInfo info(details);
|
||||
BSONObj redacted = info.getRedactedDetails();
|
||||
ASSERT_EQ(redacted["consideredValue"].str(), "###");
|
||||
}
|
||||
|
||||
// A $jsonSchema with oneOf produces schemasNotSatisfied entries whose details each contain a
|
||||
// deeply nested consideredValue. With redaction enabled all consideredValues must be redacted while
|
||||
// the surrounding structural fields are preserved.
|
||||
TEST(DocValidationRedaction, NestedConsideredValueRedacted) {
|
||||
RedactionGuard guard(true, false);
|
||||
BSONObj query = fromjson(
|
||||
"{'$jsonSchema': {'properties': {'a': {'oneOf': [{'minimum': 4}, {'maximum': 1}]}}}}");
|
||||
BSONObj doc = fromjson("{a: 2}");
|
||||
|
||||
DocumentValidationFailureInfo info(makeError(query, doc));
|
||||
BSONObj redacted = info.getRedactedDetails();
|
||||
|
||||
// Navigate: details.schemaRulesNotSatisfied[0]
|
||||
// .propertiesNotSatisfied[0].details[0]
|
||||
// .schemasNotSatisfied[i].details[0].consideredValue
|
||||
auto schemaRules = redacted["details"].Obj()["schemaRulesNotSatisfied"].Array();
|
||||
auto propDetails =
|
||||
schemaRules[0].Obj()["propertiesNotSatisfied"].Array()[0].Obj()["details"].Array();
|
||||
auto schemasNotSatisfied = propDetails[0].Obj()["schemasNotSatisfied"].Array();
|
||||
ASSERT_EQ(schemasNotSatisfied.size(), 2u);
|
||||
for (const auto& schema : schemasNotSatisfied) {
|
||||
auto inner = schema.Obj()["details"].Array()[0].Obj();
|
||||
ASSERT_EQ(inner["consideredValue"].str(), "###");
|
||||
ASSERT_EQ(inner["reason"].str(), "comparison failed");
|
||||
}
|
||||
}
|
||||
|
||||
// consideredValues (plural) is also redacted. Because redact() recurses into arrays, each element
|
||||
// of the array is individually replaced with "###".
|
||||
TEST(DocValidationRedaction, ConsideredValuesArrayRedacted) {
|
||||
RedactionGuard guard(true, false);
|
||||
BSONObj details = BSON("failingDocumentId" << 1 << "details"
|
||||
<< BSON("operatorName" << "$in"
|
||||
<< "consideredValues"
|
||||
<< BSON_ARRAY(1 << 2 << 3)));
|
||||
DocumentValidationFailureInfo info(details);
|
||||
BSONObj redacted = info.getRedactedDetails();
|
||||
|
||||
auto d = redacted["details"].Obj();
|
||||
ASSERT_EQ(d["operatorName"].str(), "$in");
|
||||
std::vector<BSONElement> vals = d["consideredValues"].Array();
|
||||
ASSERT_EQ(vals.size(), 3u);
|
||||
for (const auto& v : vals) {
|
||||
ASSERT_EQ(v.str(), "###");
|
||||
}
|
||||
}
|
||||
|
||||
// When only shouldRedactBinDataEncrypt is set (not shouldRedactLogs), BinData::Encrypt values
|
||||
// inside consideredValue are redacted, but plain scalar values are not.
|
||||
TEST(DocValidationRedaction, BinDataEncryptRedactedWhenOnlyEncryptFlagSet) {
|
||||
RedactionGuard guard(false, true);
|
||||
|
||||
const char rawBytes[] = {0x01, 0x02, 0x03, 0x04};
|
||||
BSONBinData encryptedValue(rawBytes, sizeof(rawBytes), BinDataType::Encrypt);
|
||||
|
||||
BSONObj details = BSON("failingDocumentId"
|
||||
<< 1 << "details"
|
||||
<< BSON_ARRAY(BSON("operatorName" << "$eq"
|
||||
<< "reason"
|
||||
<< "comparison failed"
|
||||
<< "consideredValue" << encryptedValue)
|
||||
<< BSON("operatorName" << "$gt"
|
||||
<< "reason"
|
||||
<< "comparison failed"
|
||||
<< "consideredValue" << 42)));
|
||||
DocumentValidationFailureInfo info(details);
|
||||
BSONObj redacted = info.getRedactedDetails();
|
||||
|
||||
auto arr = redacted["details"].Array();
|
||||
ASSERT_EQ(arr.size(), 2u);
|
||||
// The BinData::Encrypt consideredValue must be redacted.
|
||||
ASSERT_EQ(arr[0].Obj()["consideredValue"].str(), "###");
|
||||
// The plain integer consideredValue must be preserved.
|
||||
ASSERT_EQ(arr[1].Obj()["consideredValue"].Int(), 42);
|
||||
}
|
||||
|
||||
} // namespace
|
||||
} // namespace mongo::doc_validation_error
|
||||
@ -634,7 +634,7 @@ Status CollectionImpl::checkValidationAndParseResult(OperationContext* opCtx,
|
||||
"document"_attr = redact(document),
|
||||
"errInfo"_attr =
|
||||
result.second.extraInfo<doc_validation_error::DocumentValidationFailureInfo>()
|
||||
->getDetails());
|
||||
->getRedactedDetails());
|
||||
return Status::OK();
|
||||
case SchemaValidationResult::kErrorAndLog:
|
||||
LOGV2_WARNING(
|
||||
@ -644,7 +644,7 @@ Status CollectionImpl::checkValidationAndParseResult(OperationContext* opCtx,
|
||||
"document"_attr = redact(document),
|
||||
"errInfo"_attr =
|
||||
result.second.extraInfo<doc_validation_error::DocumentValidationFailureInfo>()
|
||||
->getDetails());
|
||||
->getRedactedDetails());
|
||||
return result.second;
|
||||
case SchemaValidationResult::kError:
|
||||
return result.second;
|
||||
|
||||
Loading…
Reference in New Issue
Block a user