SERVER-112882 Implement conditional logging for both log and log_debug (#43727)

GitOrigin-RevId: b3fb495b3ba0fb18b03f800fc776072e7e40e9df
This commit is contained in:
Mariano Shaar 2025-11-10 16:58:45 -05:00 committed by MongoDB Bot
parent eef398999a
commit eebc034075
7 changed files with 95 additions and 22 deletions

View File

@ -9,19 +9,28 @@ import {iterateMatchingLogLines} from "jstests/libs/log.js";
const coll = db[jsTestName()];
function checkLogs(db, debugLogLevel) {
function checkLogs(db, debugLogLevel, shouldLog) {
const globalLogs = db.adminCommand({getLog: "global"});
// Parse() is called twice - once when the LiteParsed stage is created, and once when the full
// DocumentSource stage is created. Log lines are printed in both cases.
const parseCallCount = 2;
// The log code defined in debug_logging.cpp is 11134100.
// The component is "EXTENSION-MONGOT".
// The severity is "D<logLevel>", for example "D3" for a debug log with level 3.
const debugLog = {s: "D" + String(debugLogLevel), c: "EXTENSION-MONGOT", id: 11134100};
const matchingLogLines = [...iterateMatchingLogLines(globalLogs.log, debugLog)];
// Parse() is called twice - once when the LiteParsed stage is created, and once when the full
// DocumentSource stage is created. Log lines are printed in both cases.
const parseCallCount = 2;
const matchingDebugLogLines = [...iterateMatchingLogLines(globalLogs.log, debugLog)];
// Make sure there is at most one matching log line per parse call.
assert.lte(matchingLogLines.length, parseCallCount);
return matchingLogLines.length == parseCallCount;
assert.lte(matchingDebugLogLines.length, parseCallCount);
// After adding the 'shouldLog' optimization, $debugLog also prints a warning log indicating
// whether the debug log should be printed or not.
const warningLogShouldLog = {s: "W", c: "EXTENSION-MONGOT", id: shouldLog ? 11134101 : 11134102};
const matchingWarningLogLines = [...iterateMatchingLogLines(globalLogs.log, warningLogShouldLog)];
// Since the warning line always gets printed, we expect one warning log line per parse call.
assert.eq(matchingWarningLogLines.length, parseCallCount);
return matchingDebugLogLines.length == parseCallCount;
}
function testDebugLog({serverLogLevel, debugLogLevel, commandShouldLog}) {
@ -29,7 +38,7 @@ function testDebugLog({serverLogLevel, debugLogLevel, commandShouldLog}) {
assert.commandWorked(db.setLogLevel(serverLogLevel, "extension"));
coll.aggregate([{$debugLog: {level: debugLogLevel}}]);
const realLogLevel = Math.max(1, Math.min(5, debugLogLevel));
const wasLogged = checkLogs(db, realLogLevel);
const wasLogged = checkLogs(db, realLogLevel, commandShouldLog);
assert.eq(wasLogged, commandShouldLog, {serverLogLevel, debugLogLevel});
}

View File

@ -35,8 +35,6 @@
#include "mongo/db/extension/shared/extension_status.h"
#include "mongo/db/pipeline/search/document_source_internal_search_id_lookup.h"
#include "mongo/logv2/attribute_storage.h"
#include "mongo/logv2/log_detail.h"
#include "mongo/logv2/log_options.h"
namespace mongo::extension::host_connector {
@ -66,17 +64,7 @@ MongoExtensionStatus* HostServicesAdapter::_extLog(
std::int32_t code = static_cast<std::int32_t>(logMessage->code);
// Convert C enum to logv2 severity.
logv2::LogSeverity severity = [&]() {
switch (logMessage->severityOrLevel.severity) {
case ::MongoExtensionLogSeverity::kWarning:
return logv2::LogSeverity::Warning();
case ::MongoExtensionLogSeverity::kError:
return logv2::LogSeverity::Error();
case ::MongoExtensionLogSeverity::kInfo:
default:
return logv2::LogSeverity::Info();
}
}();
logv2::LogSeverity severity = convertSeverity(logMessage->severityOrLevel.severity);
// TODO SERVER-111339 Populate attributes from logMessage->attributes.
logv2::TypeErasedAttributeStorage attrs;
@ -181,4 +169,21 @@ MongoExtensionStatus* HostServicesAdapter::_extLogDebug(
std::make_unique<host::AggStageAstNode>(std::move(liteParsed))));
});
}
MongoExtensionStatus* HostServicesAdapter::_extShouldLog(
::MongoExtensionLogSeverity levelOrSeverity,
::MongoExtensionLogType logType,
bool* out) noexcept {
return extension::wrapCXXAndConvertExceptionToStatus([&]() {
logv2::LogSeverity severity = logv2::LogSeverity::Debug(5); // Dummy initialization.
if (logType == ::MongoExtensionLogType::kDebug) {
severity =
logv2::LogSeverity::Debug(std::min(5, std::max(1, int32_t(levelOrSeverity))));
} else {
severity = convertSeverity(levelOrSeverity);
}
bool result = logv2::shouldLog(logv2::LogComponent::kExtensionMongot, severity);
*out = result;
});
}
} // namespace mongo::extension::host_connector

View File

@ -29,6 +29,7 @@
#pragma once
#include "mongo/db/extension/public/api.h"
#include "mongo/logv2/log.h"
namespace mongo::extension::host_connector {
/**
@ -69,12 +70,29 @@ private:
static ::MongoExtensionStatus* _extCreateIdLookup(
::MongoExtensionByteView bsonSpec, ::MongoExtensionAggStageAstNode** node) noexcept;
static ::MongoExtensionStatus* _extShouldLog(::MongoExtensionLogSeverity levelOrSeverity,
::MongoExtensionLogType logType,
bool* out) noexcept;
static constexpr logv2::LogSeverity convertSeverity(::MongoExtensionLogSeverity severity) {
switch (severity) {
case ::MongoExtensionLogSeverity::kWarning:
return logv2::LogSeverity::Warning();
case ::MongoExtensionLogSeverity::kError:
return logv2::LogSeverity::Error();
case ::MongoExtensionLogSeverity::kInfo:
default:
return logv2::LogSeverity::Info();
}
}
static constexpr ::MongoExtensionHostServicesVTable VTABLE{
.log = &_extLog,
.log_debug = &_extLogDebug,
.user_asserted = &_extUserAsserted,
.tripwire_asserted = &_extTripwireAsserted,
.create_host_agg_stage_parse_node = &_extCreateHostAggStageParseNode,
.create_id_lookup = &_extCreateIdLookup};
.create_id_lookup = &_extCreateIdLookup,
.should_log = &_extShouldLog};
};
} // namespace mongo::extension::host_connector

View File

@ -694,6 +694,16 @@ typedef struct MongoExtensionHostServicesVTable {
*/
MongoExtensionStatus* (*create_id_lookup)(MongoExtensionByteView bsonSpec,
MongoExtensionAggStageAstNode** node);
/**
* This provides an optimization to the logging service, as it compares the provided log
* level/severity against the server's current log level before materializing and sending a log
* over the wire. 'logType' indicates whether levelOrSeverity is a level (kDebug) or a severity
* (kLog), as in the latter case in case we need to transform the value to a logv2::LogSeverity.
*/
MongoExtensionStatus* (*should_log)(MongoExtensionLogSeverity levelOrSeverity,
::MongoExtensionLogType logType,
bool* out);
} MongoExtensionHostServicesVTable;
/**

View File

@ -78,6 +78,7 @@ void HostServicesHandle::_assertVTableConstraints(const VTable_t& vtable) const
vtable.create_host_agg_stage_parse_node != nullptr);
sdk_tassert(
11134201, "Host services' 'create_id_lookup' is null", vtable.create_id_lookup != nullptr);
sdk_tassert(11288201, "Host services' 'should_log' is null", vtable.should_log != nullptr);
}
} // namespace mongo::extension::sdk

View File

@ -86,6 +86,11 @@ public:
MongoExtensionLogSeverity severity = MongoExtensionLogSeverity::kInfo) const {
assertValid();
// Prevent materializing log messages that would not be logged.
if (!shouldLog(severity, ::MongoExtensionLogType::kLog)) {
return;
}
// TODO SERVER-111339 Add attributes.
::MongoExtensionLogMessage logMessage = createLogMessageStruct(message, code, severity);
@ -95,6 +100,11 @@ public:
void logDebug(const std::string& message, std::int32_t code, std::int32_t level = 1) const {
assertValid();
// Prevent materializing log messages that would not be logged.
if (!shouldLog(::MongoExtensionLogSeverity(level), ::MongoExtensionLogType::kDebug)) {
return;
}
// TODO SERVER-111339 Add attributes.
::MongoExtensionLogMessage logMessage = createDebugLogMessageStruct(message, code, level);
@ -124,6 +134,15 @@ public:
return AggStageAstNodeHandle{result};
}
bool shouldLog(::MongoExtensionLogSeverity levelOrSeverity,
::MongoExtensionLogType logType) const {
assertValid();
bool out = false;
invokeCAndConvertStatusToException(
[&]() { return vtable().should_log(levelOrSeverity, logType, &out); });
return out;
}
private:
static HostServicesHandle _hostServices;

View File

@ -64,6 +64,17 @@ public:
bsonSpec.getField(kDebugLogLevelField).isNumber());
int level = bsonSpec.getIntField(kDebugLogLevelField);
// This tests the functionality of the shouldLog host service.
if (sdk::HostServicesHandle::getHostServices()->shouldLog(
::MongoExtensionLogSeverity(level), ::MongoExtensionLogType::kDebug)) {
sdk::HostServicesHandle::getHostServices()->log(
"Log level is enough", 11134101, ::MongoExtensionLogSeverity::kWarning);
} else {
sdk::HostServicesHandle::getHostServices()->log(
"Log level is not enough", 11134102, ::MongoExtensionLogSeverity::kWarning);
}
sdk::HostServicesHandle::getHostServices()->logDebug("Test log message", 11134100, level);
return std::make_unique<DebugLogParseNode>(stageBson);