SERVER-21959 Do not truncate stack traces in log messages.

(cherry picked from commit 7e7ea93facc494fbc393f7170d50b371fbf5f9f0)

8 files changed, 35 insertions, 15 deletions

diff --git a/jstests/core/loglong.js b/jstests/core/loglong.js
index 06cbf296c09..74f56a8f494 100644
--- a/jstests/core/loglong.js
+++ b/jstests/core/loglong.js
@@ -23,10 +23,10 @@ log = db.adminCommand( { getLog : "global" } ).log
 
 found = false
 for ( i=log.length - 1; i>= 0; i-- ) {
-    if ( log[i].indexOf( "warning: log line attempted (16k)" ) >= 0 ) {
+    if ( log[i].indexOf( "warning: log line attempted (16kB)" ) >= 0 ) {
         found = true;
         break;
     }
 }
 
-assert( found )
+assert(found, tojson(log));
diff --git a/src/mongo/logger/logstream_builder.cpp b/src/mongo/logger/logstream_builder.cpp
index aa5d9d63eac..2577704aad0 100644
--- a/src/mongo/logger/logstream_builder.cpp
+++ b/src/mongo/logger/logstream_builder.cpp
@@ -102,7 +102,8 @@ LogstreamBuilder::LogstreamBuilder(LogstreamBuilder&& other)
       _component(std::move(other._component)),
       _baseMessage(std::move(other._baseMessage)),
       _os(std::move(other._os)),
-      _tee(std::move(other._tee)) {}
+      _tee(std::move(other._tee)),
+      _isTruncatable(other._isTruncatable) {}
 
 LogstreamBuilder& LogstreamBuilder::operator=(LogstreamBuilder&& other) {
     _domain = std::move(other._domain);
@@ -112,6 +113,7 @@ LogstreamBuilder& LogstreamBuilder::operator=(LogstreamBuilder&& other) {
     _baseMessage = std::move(other._baseMessage);
     _os = std::move(other._os);
     _tee = std::move(other._tee);
+    _isTruncatable = std::move(other._isTruncatable);
     return *this;
 }
 
@@ -123,6 +125,7 @@ LogstreamBuilder::~LogstreamBuilder() {
         _baseMessage += _os->str();
         MessageEventEphemeral message(
             Date_t::now(), _severity, _component, _contextName, _baseMessage);
+        message.setIsTruncatable(_isTruncatable);
         _domain->append(message);
         if (_tee) {
             _os->str("");
diff --git a/src/mongo/logger/logstream_builder.h b/src/mongo/logger/logstream_builder.h
index 275ce871bdd..40f56ccf75f 100644
--- a/src/mongo/logger/logstream_builder.h
+++ b/src/mongo/logger/logstream_builder.h
@@ -115,6 +115,11 @@ public:
         return *this;
     }
 
+    LogstreamBuilder& setIsTruncatable(bool isTruncatable) {
+        _isTruncatable = isTruncatable;
+        return *this;
+    }
+
     std::ostream& stream() {
         if (!_os)
             makeStream();
@@ -230,6 +235,7 @@ private:
     std::string _baseMessage;
     std::unique_ptr<std::ostringstream> _os;
     Tee* _tee;
+    bool _isTruncatable = true;
 };
 
 
diff --git a/src/mongo/logger/message_event.h b/src/mongo/logger/message_event.h
index 331e46282eb..edc6542a79f 100644
--- a/src/mongo/logger/message_event.h
+++ b/src/mongo/logger/message_event.h
@@ -49,11 +49,7 @@ public:
                           LogSeverity severity,
                           StringData contextName,
                           StringData message)
-        : _date(date),
-          _severity(severity),
-          _component(LogComponent::kDefault),
-          _contextName(contextName),
-          _message(message) {}
+        : MessageEventEphemeral(date, severity, LogComponent::kDefault, contextName, message) {}
 
     MessageEventEphemeral(Date_t date,
                           LogSeverity severity,
@@ -66,6 +62,11 @@ public:
           _contextName(contextName),
           _message(message) {}
 
+    MessageEventEphemeral& setIsTruncatable(bool value) {
+        _isTruncatable = value;
+        return *this;
+    }
+
     Date_t getDate() const {
         return _date;
     }
@@ -81,6 +82,9 @@ public:
     StringData getMessage() const {
         return _message;
     }
+    bool isTruncatable() const {
+        return _isTruncatable;
+    }
 
 private:
     Date_t _date;
@@ -88,6 +92,7 @@ private:
     LogComponent _component;
     StringData _contextName;
     StringData _message;
+    bool _isTruncatable = true;
 };
 
 }  // namespace logger
diff --git a/src/mongo/logger/message_event_utf8_encoder.cpp b/src/mongo/logger/message_event_utf8_encoder.cpp
index ee9bfa19e8b..3483a113d1e 100644
--- a/src/mongo/logger/message_event_utf8_encoder.cpp
+++ b/src/mongo/logger/message_event_utf8_encoder.cpp
@@ -67,9 +67,9 @@ std::ostream& MessageEventDetailsEncoder::encode(const MessageEventEphemeral& ev
     }
 
     StringData msg = event.getMessage();
-    if (msg.size() > maxLogLine) {
-        os << "warning: log line attempted (" << msg.size() / 1024 << "k) over max size ("
-           << maxLogLine / 1024 << "k), printing beginning and end ... ";
+    if (event.isTruncatable() && msg.size() > maxLogLine) {
+        os << "warning: log line attempted (" << msg.size() / 1024 << "kB) over max size ("
+           << maxLogLine / 1024 << "kB), printing beginning and end ... ";
         os << msg.substr(0, maxLogLine / 3);
         os << " .......... ";
         os << msg.substr(msg.size() - (maxLogLine / 3));
diff --git a/src/mongo/util/log.cpp b/src/mongo/util/log.cpp
index 75463d32858..75720dbcf7f 100644
--- a/src/mongo/util/log.cpp
+++ b/src/mongo/util/log.cpp
@@ -131,7 +131,9 @@ void logContext(const char* errmsg) {
     if (errmsg) {
         log() << errmsg << endl;
     }
-    printStackTrace(log().stream());
+    // NOTE: We disable long-line truncation for the stack trace, because the JSON representation of
+    // the stack trace can sometimes exceed the long line limit.
+    printStackTrace(log().setIsTruncatable(false).stream());
 }
 
 Tee* const warnings = RamLog::get("warnings");  // Things put here go in serverStatus
diff --git a/src/mongo/util/signal_handlers_synchronous.cpp b/src/mongo/util/signal_handlers_synchronous.cpp
index 1d83968afac..a9bca4d21cc 100644
--- a/src/mongo/util/signal_handlers_synchronous.cpp
+++ b/src/mongo/util/signal_handlers_synchronous.cpp
@@ -167,8 +167,10 @@ int MallocFreeOStreamGuard::terminateDepth = 0;
 
 // must hold MallocFreeOStreamGuard to call
 void writeMallocFreeStreamToLog() {
-    logger::globalLogDomain()->append(logger::MessageEventEphemeral(
-        Date_t::now(), logger::LogSeverity::Severe(), getThreadName(), mallocFreeOStream.str()));
+    logger::globalLogDomain()->append(
+        logger::MessageEventEphemeral(
+            Date_t::now(), logger::LogSeverity::Severe(), getThreadName(), mallocFreeOStream.str())
+            .setIsTruncatable(false));
     mallocFreeOStream.rewind();
 }
 
diff --git a/src/mongo/util/stacktrace.cpp b/src/mongo/util/stacktrace.cpp
index 651f9647a61..d1976dff1df 100644
--- a/src/mongo/util/stacktrace.cpp
+++ b/src/mongo/util/stacktrace.cpp
@@ -38,7 +38,9 @@
 namespace mongo {
 
 void printStackTrace() {
-    printStackTrace(log().stream());
+    // NOTE: We disable long-line truncation for the stack trace, because the JSON representation of
+    // the stack trace can sometimes exceed the long line limit.
+    printStackTrace(log().setIsTruncatable(false).stream());
 }
 
 #if defined(_WIN32)