Major - P3 Certain test suites (like noPassthrough) are reponsible for starting their own mongods. As part of this, the shell started by resmoke is responsible for printing/redirecting the servers output. The logging mechanism responsible for this has truncation enabled by default, meaning a log line which is marked as "truncation disabled" (like below) may still ultimately get truncated when running under certain test suites.
LOGV2_OPTIONS(31431, {logv2::LogTruncation::Disabled}, "{bt}", "bt"_attr = obj);
A quick way to reproduce this is to add an absurdly long log message somewhere in the server and exercise it in a noPassthrough test. Here's a patch which adds one to the $planCacheStats agg stage (not a common code path). Base rev 2b61edc505e45acc7927aee40e4e8abeb99420cd.
diff --git a/src/mongo/db/pipeline/document_source_plan_cache_stats.cpp b/src/mongo/db/pipeline/document_source_plan_cache_stats.cpp index 1d871a9521..19c7fe3d20 100644 --- a/src/mongo/db/pipeline/document_source_plan_cache_stats.cpp +++ b/src/mongo/db/pipeline/document_source_plan_cache_stats.cpp @@ -27,9 +27,12 @@ * it in the license file. */ +#define MONGO_LOG_DEFAULT_COMPONENT ::mongo::logger::LogComponent::kQuery + #include "mongo/platform/basic.h" #include "mongo/db/pipeline/document_source_plan_cache_stats.h" +#include "mongo/logv2/log.h" namespace mongo { @@ -49,6 +52,15 @@ boost::intrusive_ptr<DocumentSource> DocumentSourcePlanCacheStats::createFromBso << " parameters object must be empty. Found: " << typeName(spec.type()), spec.embeddedObject().isEmpty()); + static constexpr char fmtBt[] = "message from me: {bt}"; + std::string giantStr; + for (int i = 0; i < 10232; ++i) { + giantStr += 's'; + } + giantStr += "remainder"; + + LOGV2_OPTIONS(99999, {logv2::LogTruncation::Disabled}, fmtBt, "bt"_attr = giantStr); + return new DocumentSourcePlanCacheStats(pExpCtx); }
Then run a test which exercises this code:
myresmoke --suites=no_passthrough jstests/noPassthrough/plan_cache_stats_agg_source.js
One would expect the entire string to be printed (including the word "remainder"), but only a prefix is printed.
I am using the following fix locally (so that I can continue other work). It might actually make sense to commit this (or something similar), since I doubt we use the ProgramOutputMultiplexer for anything besides testing, and we can enforce that log lines are truncated on mongod/mongos separately.
diff --git a/src/mongo/shell/shell_utils_launcher.cpp b/src/mongo/shell/shell_utils_launcher.cpp index 592eda259d..869c948712 100644 --- a/src/mongo/shell/shell_utils_launcher.cpp +++ b/src/mongo/shell/shell_utils_launcher.cpp @@ -251,6 +251,7 @@ void ProgramOutputMultiplexer::appendLine(int port, auto plainShellOutputDomain = logger::globalLogManager()->getNamedDomain("plainShellOutput"); logger::LogstreamBuilder builder( plainShellOutputDomain, getThreadName(), logger::LogSeverity::Log()); + builder.setIsTruncatable(false); sinkProgramOutput(_buffer); sinkProgramOutput(builder);