From fc161a8e3db42643a4d17678c91dc369c4a1376b Mon Sep 17 00:00:00 2001 From: HanaPearlman Date: Tue, 19 Nov 2024 14:05:14 -0500 Subject: [PATCH] SERVER-96135: Ensure commands are appropriately redacted for tassert/invariant log extensions (#29305) GitOrigin-RevId: 9bff640e85e216b416eaaa1f24d1365888f1a774 --- src/mongo/db/curop.h | 16 +- src/mongo/db/query/BUILD.bazel | 14 +- src/mongo/db/query/SConscript | 6 + .../db/query/command_diagnostic_printer.h | 35 +++- .../query/command_diagnostic_printer_test.cpp | 151 ++++++++++++++++++ 5 files changed, 213 insertions(+), 9 deletions(-) create mode 100644 src/mongo/db/query/command_diagnostic_printer_test.cpp diff --git a/src/mongo/db/curop.h b/src/mongo/db/curop.h index bf31d25bdff..e75ff3287f6 100644 --- a/src/mongo/db/curop.h +++ b/src/mongo/db/curop.h @@ -275,6 +275,14 @@ public: OpDebug() = default; + /** + * Adds information about the current operation to "pAttrs". Since this information will end up + * in logs, typically as part of "Slow Query" logging, this method also handles redaction and + * removal of sensitive fields from any command BSON. + * + * The metrics/fields reported here should generally be kept in line with what is reported in + * append(). + */ void report(OperationContext* opCtx, const SingleThreadedLockStats* lockStats, const ResourceConsumption::OperationMetrics* operationMetrics, @@ -283,10 +291,14 @@ public: void reportStorageStats(logv2::DynamicAttributes* pAttrs) const; /** - * Appends information about the current operation to "builder" + * Appends information about the current operation to "builder". This info typically ends up in + * the DB's profile collection. It is not ready to be logged as-is; redaction and removal of + * sensitive command fields are required first. * - * @param curop reference to the CurOp that owns this OpDebug * @param lockStats lockStats object containing locking information about the operation + * + * The metrics/fields reported here should generally be kept in line with what is reported in + * report(). */ void append(OperationContext* opCtx, const SingleThreadedLockStats& lockStats, diff --git a/src/mongo/db/query/BUILD.bazel b/src/mongo/db/query/BUILD.bazel index 5c37714cf6a..4845b46dcdb 100644 --- a/src/mongo/db/query/BUILD.bazel +++ b/src/mongo/db/query/BUILD.bazel @@ -1,4 +1,4 @@ -load("//bazel:mongo_src_rules.bzl", "idl_generator", "mongo_cc_library") +load("//bazel:mongo_src_rules.bzl", "idl_generator", "mongo_cc_library", "mongo_cc_unit_test") package(default_visibility = ["//visibility:public"]) @@ -645,6 +645,18 @@ mongo_cc_library( ], ) +mongo_cc_unit_test( + name = "command_diagnostic_printer_test", + srcs = [ + "command_diagnostic_printer_test.cpp", + "//src/mongo/db/query:command_diagnostic_printer.h", + ], + deps = [ + "//src/mongo/db:commands", + "//src/mongo/db:service_context_test_fixture", + ], +) + # TODO(SERVER-96860): Remove cycle created by moving //src/mongo/db/query:explain_options.h to //src/mongo/db/query:common_query_enums_and_helpers filegroup( name = "explain_options_hdrs", diff --git a/src/mongo/db/query/SConscript b/src/mongo/db/query/SConscript index fb089676c11..7d5592fcca0 100644 --- a/src/mongo/db/query/SConscript +++ b/src/mongo/db/query/SConscript @@ -85,6 +85,12 @@ env.Library( ], ) +env.CppUnitTest( + target="command_diagnostic_printer_test", + source=[], + LIBDEPS=[], +) + env.CppUnitTest( target="db_query_test", source=[ diff --git a/src/mongo/db/query/command_diagnostic_printer.h b/src/mongo/db/query/command_diagnostic_printer.h index 70f26310cd9..ecb6028977c 100644 --- a/src/mongo/db/query/command_diagnostic_printer.h +++ b/src/mongo/db/query/command_diagnostic_printer.h @@ -47,19 +47,42 @@ namespace mongo::command_diagnostics { struct Printer { auto format(auto& fc) const { - // It's assumed that 'opCtx' is a valid pointer and has been decorated with a CurOp. This - // class should not be used in scopes where that assumption doesn't hold. + // All operations have an OperationContext, and all OpContexts are decorated with a + // CurOpStack. This access should always be valid while 'opCtx' is a valid pointer. auto& curOp = *CurOp::get(opCtx); auto out = fc.out(); + + // Do not log any information if asked to omit it. + if (curOp.getShouldOmitDiagnosticInformation()) { + out = format_to(out, FMT_STRING("omitted")); + return out; + } + + // Remove sensitive fields from the command object before logging. + // TODO SERVER-74604: When the implementations of OpDebug::append() and OpDebug::report() + // are merged, we should be able to remove the duplicated logic here that handles + // 'snipForLogging()' and 'redact()'. + BSONObj cmd; + if (const Command* curCommand = curOp.getCommand()) { + mutablebson::Document cmdToLog(curOp.opDescription(), + mutablebson::Document::kInPlaceDisabled); + curCommand->snipForLogging(&cmdToLog); + cmd = cmdToLog.getObject(); + } + + auto opDesc = redact(cmd).toString(); + auto opDebug = redact(serializeOpDebug(curOp)).toString(); + auto origCommand = redact(curOp.originatingCommand()).toString(); out = format_to( out, - FMT_STRING("{{'currentOp': {}, 'opDescription': {}, 'originatingCommand': {}}}"), - redact(serializeOpDebug(curOp)).toString(), - redact(curOp.opDescription()).toString(), - redact(curOp.originatingCommand()).toString()); + FMT_STRING("{{'currentOp': {}, 'opDescription': {}{}}}"), + opDebug, + opDesc, + curOp.originatingCommand().isEmpty() ? "" : ", 'originatingCommand': " + origCommand); return out; } + // This pointer must outlive this class. OperationContext* opCtx; private: diff --git a/src/mongo/db/query/command_diagnostic_printer_test.cpp b/src/mongo/db/query/command_diagnostic_printer_test.cpp new file mode 100644 index 00000000000..5a97876043c --- /dev/null +++ b/src/mongo/db/query/command_diagnostic_printer_test.cpp @@ -0,0 +1,151 @@ +/** + * Copyright (C) 2024-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 + * . + * + * 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/db/commands.h" +#include "mongo/db/curop.h" +#include "mongo/db/namespace_string.h" +#include "mongo/db/query/command_diagnostic_printer.h" +#include "mongo/db/service_context_test_fixture.h" +#include "mongo/logv2/log_util.h" +#include "mongo/unittest/assert.h" +#include "mongo/unittest/framework.h" + +namespace mongo { + +namespace { + +using namespace fmt::literals; + +static constexpr StringData kCmdName = "mockCmd"_sd; +static constexpr StringData kCmdValue = "abcdefgh"_sd; +static constexpr StringData kSensitiveFieldName = "sensitive"_sd; +static constexpr StringData kSensitiveValue = "12345678"_sd; + +class MockCmd : public BasicCommand { +public: + MockCmd() : BasicCommand{kCmdName} {} + + std::set sensitiveFieldNames() const final { + return {kSensitiveFieldName}; + } + + bool run(OperationContext*, const DatabaseName&, const BSONObj&, BSONObjBuilder&) override { + return true; + } + AllowedOnSecondary secondaryAllowed(ServiceContext*) const override { + return AllowedOnSecondary::kAlways; + } + bool supportsWriteConcern(const BSONObj&) const override { + return true; + } + Status checkAuthForOperation(OperationContext*, + const DatabaseName&, + const BSONObj&) const override { + return Status::OK(); + } +}; + +class CommandDiagnosticPrinterTest : public ServiceContextTest { +public: + CommandDiagnosticPrinterTest() { + _nss = NamespaceString::createNamespaceString_forTest("myDb"); + _opCtxHolder = makeOperationContext(); + _cmdBson = BSON(kCmdName << kCmdValue << kSensitiveFieldName << kSensitiveValue); + } + + OperationContext* opCtx() { + return _opCtxHolder.get(); + } + + CurOp* curOp() { + return CurOp::get(opCtx()); + } + + void setMockCmdOnCurOp() { + stdx::lock_guard clientLock(*opCtx()->getClient()); + curOp()->setGenericOpRequestDetails(clientLock, _nss, &_cmd, _cmdBson, NetworkOp::dbQuery); + } + + std::string printCommandDiagnostics() { + command_diagnostics::Printer printer{opCtx()}; + return "{}"_format(printer); + } + +private: + MockCmd _cmd; + NamespaceString _nss; + ServiceContext::UniqueOperationContext _opCtxHolder; + BSONObj _cmdBson; +}; + +TEST_F(CommandDiagnosticPrinterTest, PrinterOmitsCommandFieldsWhenThereIsNoCommandSet) { + // When CurOp doesn't have a command object on it, the diagnostic printer shouldn't log any + // command fields, since it's unclear if any of them are sensitive. + auto str = printCommandDiagnostics(); + ASSERT_STRING_OMITS(str, kCmdName); + ASSERT_STRING_OMITS(str, kCmdValue); + ASSERT_STRING_OMITS(str, kSensitiveFieldName); + ASSERT_STRING_OMITS(str, kSensitiveValue); +} + +TEST_F(CommandDiagnosticPrinterTest, PrinterOmitsAllFieldsWhenRequested) { + // When a command requests to omit diagnostic logging, the diagnostic printer shouldn't log any + // fields. + setMockCmdOnCurOp(); + { + stdx::lock_guard clientLock(*opCtx()->getClient()); + curOp()->setShouldOmitDiagnosticInformation(clientLock, true); + } + ASSERT_EQ("omitted", printCommandDiagnostics()); +} + +TEST_F(CommandDiagnosticPrinterTest, PrinterRedactsSensitiveCommandFields) { + // The diagnostic printer should always redact the values of fields specified as sensitive by + // the command. + setMockCmdOnCurOp(); + auto str = printCommandDiagnostics(); + ASSERT_STRING_CONTAINS(str, kCmdName); + ASSERT_STRING_CONTAINS(str, kCmdValue); + ASSERT_STRING_CONTAINS(str, kSensitiveFieldName); + ASSERT_STRING_OMITS(str, kSensitiveValue); +} + +TEST_F(CommandDiagnosticPrinterTest, PrinterRedactsWhenRedactionIsEnabled) { + // When redaction is enabled, all field values should be redacted. + setMockCmdOnCurOp(); + logv2::setShouldRedactLogs(true); + auto str = printCommandDiagnostics(); + ASSERT_STRING_CONTAINS(str, kCmdName); + ASSERT_STRING_OMITS(str, kCmdValue); + ASSERT_STRING_CONTAINS(str, kSensitiveFieldName); + ASSERT_STRING_OMITS(str, kSensitiveValue); +} +} // namespace + +} // namespace mongo