Details
Description
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);
|
|