SERVER-37743 Debug logs should include the debug log level

6 files changed, 76 insertions, 54 deletions

diff --git a/src/mongo/logger/log_function_test.cpp b/src/mongo/logger/log_function_test.cpp
index 3f861c69437..6fbcabd6b28 100644
--- a/src/mongo/logger/log_function_test.cpp
+++ b/src/mongo/logger/log_function_test.cpp
@@ -66,7 +66,7 @@ TEST_F(LogTestDetailsEncoder, LogFunctionsOverrideGlobalComponent) {
     severe() << "This is logged";
     ASSERT_TRUE(shouldLog(LogSeverity::Severe()));
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " F " << componentB.getNameForLog()),
+    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " F  " << componentB.getNameForLog()),
                       std::string::npos);
 
     // severe() - with component.
@@ -74,7 +74,7 @@ TEST_F(LogTestDetailsEncoder, LogFunctionsOverrideGlobalComponent) {
     severe(componentA) << "This is logged";
     ASSERT_TRUE(logger::globalLogDomain()->shouldLog(componentA, LogSeverity::Severe()));
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " F " << componentA.getNameForLog()),
+    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " F  " << componentA.getNameForLog()),
                       std::string::npos);
 
     // error() - no component specified.
@@ -82,7 +82,7 @@ TEST_F(LogTestDetailsEncoder, LogFunctionsOverrideGlobalComponent) {
     error() << "This is logged";
     ASSERT_TRUE(shouldLog(LogSeverity::Error()));
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " E " << componentB.getNameForLog()),
+    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " E  " << componentB.getNameForLog()),
                       std::string::npos);
 
     // error() - with component.
@@ -90,7 +90,7 @@ TEST_F(LogTestDetailsEncoder, LogFunctionsOverrideGlobalComponent) {
     error(componentA) << "This is logged";
     ASSERT_TRUE(logger::globalLogDomain()->shouldLog(componentA, LogSeverity::Error()));
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " E " << componentA.getNameForLog()),
+    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " E  " << componentA.getNameForLog()),
                       std::string::npos);
 
     // warning() - no component specified.
@@ -98,7 +98,7 @@ TEST_F(LogTestDetailsEncoder, LogFunctionsOverrideGlobalComponent) {
     warning() << "This is logged";
     ASSERT_TRUE(shouldLog(LogSeverity::Warning()));
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " W " << componentB.getNameForLog()),
+    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " W  " << componentB.getNameForLog()),
                       std::string::npos);
 
     // warning() - with component.
@@ -106,7 +106,7 @@ TEST_F(LogTestDetailsEncoder, LogFunctionsOverrideGlobalComponent) {
     warning(componentA) << "This is logged";
     ASSERT_TRUE(logger::globalLogDomain()->shouldLog(componentA, LogSeverity::Warning()));
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " W " << componentA.getNameForLog()),
+    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " W  " << componentA.getNameForLog()),
                       std::string::npos);
 
     // log() - no component specified.
@@ -114,7 +114,7 @@ TEST_F(LogTestDetailsEncoder, LogFunctionsOverrideGlobalComponent) {
     log() << "This is logged";
     ASSERT_TRUE(shouldLog(LogSeverity::Log()));
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " I " << componentB.getNameForLog()),
+    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " I  " << componentB.getNameForLog()),
                       std::string::npos);
 
     // log() - with component.
@@ -122,7 +122,7 @@ TEST_F(LogTestDetailsEncoder, LogFunctionsOverrideGlobalComponent) {
     log(componentA) << "This is logged";
     ASSERT_TRUE(logger::globalLogDomain()->shouldLog(componentA, LogSeverity::Log()));
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " I " << componentA.getNameForLog()),
+    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " I  " << componentA.getNameForLog()),
                       std::string::npos);
 }
 
diff --git a/src/mongo/logger/log_severity-inl.h b/src/mongo/logger/log_severity-inl.h
index d50da3e5a2b..e76e10b91f5 100644
--- a/src/mongo/logger/log_severity-inl.h
+++ b/src/mongo/logger/log_severity-inl.h
@@ -48,7 +48,9 @@ LogSeverity LogSeverity::Log() {
     return LogSeverity(0);
 }
 LogSeverity LogSeverity::Debug(int debugLevel) {
-    return LogSeverity(debugLevel);
+    // It would be appropriate to use std::max or std::clamp instead,
+    // but it seems better not to drag in all of <algorithm> here.
+    return LogSeverity(debugLevel > kMaxDebugLevel ? kMaxDebugLevel : debugLevel);
 }
 
 LogSeverity LogSeverity::cast(int ll) {
diff --git a/src/mongo/logger/log_severity.cpp b/src/mongo/logger/log_severity.cpp
index e67db65391f..90ba9967e88 100644
--- a/src/mongo/logger/log_severity.cpp
+++ b/src/mongo/logger/log_severity.cpp
@@ -37,12 +37,18 @@ namespace mongo {
 namespace logger {
 
 namespace {
+
 constexpr auto unknownSeverityString = "UNKNOWN"_sd;
 constexpr auto severeSeverityString = "SEVERE"_sd;
 constexpr auto errorSeverityString = "ERROR"_sd;
 constexpr auto warningSeverityString = "warning"_sd;
 constexpr auto infoSeverityString = "info"_sd;
 constexpr auto debugSeverityString = "debug"_sd;
+
+constexpr StringData kDebugLevelStrings[LogSeverity::kMaxDebugLevel] = {
+    "D1"_sd, "D2"_sd, "D3"_sd, "D4"_sd, "D5"_sd,
+};
+
 }  // namespace
 
 StringData LogSeverity::toStringData() const {
@@ -61,24 +67,26 @@ StringData LogSeverity::toStringData() const {
     return unknownSeverityString;
 }
 
-char LogSeverity::toChar() const {
-    if (_severity > 0)
-        return 'D';
+StringData LogSeverity::toStringDataCompact() const {
+
+    if ((*this == LogSeverity::Log()) || (*this == LogSeverity::Info()))
+        return "I "_sd;
+
+    if ((_severity > 0) && (_severity <= kMaxDebugLevel))
+        return kDebugLevelStrings[_severity - 1];
+
+    if (*this == LogSeverity::Warning())
+        return "W "_sd;
+
+    if (*this == LogSeverity::Error())
+        return "E "_sd;
+
     // 'S' might be confused with "Success"
     // Return 'F' to imply Fatal instead.
     if (*this == LogSeverity::Severe())
-        return 'F';
-    if (*this == LogSeverity::Error())
-        return 'E';
-    if (*this == LogSeverity::Warning())
-        return 'W';
-    if (*this == LogSeverity::Info())
-        return 'I';
-    if (*this == LogSeverity::Log())
-        return 'I';
-    // Should not reach here - returning 'U' for Unknown severity
-    // to be consistent with toStringData().
-    return 'U';
+        return "F "_sd;
+
+    return "U "_sd;
 }
 
 std::ostream& operator<<(std::ostream& os, LogSeverity severity) {
diff --git a/src/mongo/logger/log_severity.h b/src/mongo/logger/log_severity.h
index d04537d77be..b0eeccbd859 100644
--- a/src/mongo/logger/log_severity.h
+++ b/src/mongo/logger/log_severity.h
@@ -54,6 +54,11 @@ public:
     static inline LogSeverity Warning();
     static inline LogSeverity Info();
     static inline LogSeverity Log();  // === Debug(0)
+
+    static constexpr int kMaxDebugLevel = 5;
+
+    // Construct a LogSeverity to represent the given debug level. Debug levels above
+    // kMaxDebugLevel will be reset to kMaxDebugLevel.
     static inline LogSeverity Debug(int debugLevel);
 
     /**
@@ -91,12 +96,14 @@ public:
     StringData toStringData() const;
 
     /**
-     * Returns a single capital letter naming this severity level.
-     * Equivalent to upper-case of first letter of toStringData() result.
+     * Returns two characters naming this severity level. For non-debug levels, returns
+     * a single character mapping to the first letter of the string returned by
+     * `toStringData`, followed by a space. For debug levels, returns 'DN', where N
+     * is an integer greater than zero.
      *
-     * Not all levels are uniquely named.
+     * All levels are uniquely named.
      */
-    char toChar() const;
+    StringData toStringDataCompact() const;
 
     //
     // Comparison operations.
diff --git a/src/mongo/logger/log_test.cpp b/src/mongo/logger/log_test.cpp
index 63a7c6feb8e..ffdf16815e5 100644
--- a/src/mongo/logger/log_test.cpp
+++ b/src/mongo/logger/log_test.cpp
@@ -393,18 +393,18 @@ TEST_F(LogTestUnadornedEncoder, MessageEventDetailsEncoderLogSeverity) {
     const auto ctx = "WHAT"_sd;
     const auto msg = "HUH"_sd;
     // Severe is indicated by (F)atal.
-    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Severe(), ctx, msg), " F ");
-    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Error(), ctx, msg), " E ");
-    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Warning(), ctx, msg), " W ");
-    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Info(), ctx, msg), " I ");
-    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Log(), ctx, msg), " I ");
-    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(0), ctx, msg), " I ");
-    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(1), ctx, msg), " D ");
-    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(2), ctx, msg), " D ");
-    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(3), ctx, msg), " D ");
-    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(4), ctx, msg), " D ");
-    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(5), ctx, msg), " D ");
-    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(100), ctx, msg), " D ");
+    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Severe(), ctx, msg), " F  ");
+    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Error(), ctx, msg), " E  ");
+    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Warning(), ctx, msg), " W  ");
+    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Info(), ctx, msg), " I  ");
+    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Log(), ctx, msg), " I  ");
+    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(0), ctx, msg), " I  ");
+    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(1), ctx, msg), " D1 ");
+    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(2), ctx, msg), " D2 ");
+    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(3), ctx, msg), " D3 ");
+    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(4), ctx, msg), " D4 ");
+    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(5), ctx, msg), " D5 ");
+    testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Debug(100), ctx, msg), " D5 ");
     // Unknown severity.
     testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Severe().moreSevere(), ctx, msg),
                        " U ");
@@ -418,7 +418,7 @@ TEST_F(LogTestUnadornedEncoder, MessageEventDetailsEncoderLogComponent) {
     for (int i = 0; i < int(LogComponent::kNumLogComponents); ++i) {
         LogComponent component = static_cast<LogComponent::Value>(i);
         testEncodedLogLine(MessageEventEphemeral(d, LogSeverity::Info(), component, ctx, msg),
-                           str::stream() << " I " << component.getNameForLog() << " [");
+                           str::stream() << " I  " << component.getNameForLog() << " [");
     }
 }
 
@@ -462,56 +462,60 @@ TEST_F(LogTestDetailsEncoder, LogFunctions) {
     // severe() - no component specified.
     severe() << "This is logged";
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " F " << componentDefault.getNameForLog()),
-                      std::string::npos);
+    ASSERT_NOT_EQUALS(
+        _logLines[0].find(str::stream() << " F  " << componentDefault.getNameForLog()),
+        std::string::npos);
 
     // severe() - with component.
     _logLines.clear();
     severe(componentA) << "This is logged";
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " F " << componentA.getNameForLog()),
+    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " F  " << componentA.getNameForLog()),
                       std::string::npos);
 
     // error() - no component specified.
     _logLines.clear();
     error() << "This is logged";
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " E " << componentDefault.getNameForLog()),
-                      std::string::npos);
+    ASSERT_NOT_EQUALS(
+        _logLines[0].find(str::stream() << " E  " << componentDefault.getNameForLog()),
+        std::string::npos);
 
     // error() - with component.
     _logLines.clear();
     error(componentA) << "This is logged";
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " E " << componentA.getNameForLog()),
+    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " E  " << componentA.getNameForLog()),
                       std::string::npos);
 
     // warning() - no component specified.
     _logLines.clear();
     warning() << "This is logged";
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " W " << componentDefault.getNameForLog()),
-                      std::string::npos);
+    ASSERT_NOT_EQUALS(
+        _logLines[0].find(str::stream() << " W  " << componentDefault.getNameForLog()),
+        std::string::npos);
 
     // warning() - with component.
     _logLines.clear();
     warning(componentA) << "This is logged";
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " W " << componentA.getNameForLog()),
+    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " W  " << componentA.getNameForLog()),
                       std::string::npos);
 
     // log() - no component specified.
     _logLines.clear();
     log() << "This is logged";
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " I " << componentDefault.getNameForLog()),
-                      std::string::npos);
+    ASSERT_NOT_EQUALS(
+        _logLines[0].find(str::stream() << " I  " << componentDefault.getNameForLog()),
+        std::string::npos);
 
     // log() - with component.
     _logLines.clear();
     log(componentA) << "This is logged";
     ASSERT_EQUALS(1U, _logLines.size());
-    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " I " << componentA.getNameForLog()),
+    ASSERT_NOT_EQUALS(_logLines[0].find(str::stream() << " I  " << componentA.getNameForLog()),
                       std::string::npos);
 }
 
diff --git a/src/mongo/logger/message_event_utf8_encoder.cpp b/src/mongo/logger/message_event_utf8_encoder.cpp
index 3233cc33590..3e9e4e8012c 100644
--- a/src/mongo/logger/message_event_utf8_encoder.cpp
+++ b/src/mongo/logger/message_event_utf8_encoder.cpp
@@ -92,7 +92,8 @@ std::ostream& MessageEventDetailsEncoder::encode(const MessageEventEphemeral& ev
     getDateFormatter()(os, event.getDate());
     os << ' ';
 
-    os << event.getSeverity().toChar();
+    const auto severity = event.getSeverity();
+    os << severity.toStringDataCompact();
     os << ' ';
 
     LogComponent component = event.getComponent();