SERVER-46026 Fix kill_sessions.js and logs_include_client_info.js to handle JSON logs

4 files changed, 82 insertions, 26 deletions

diff --git a/jstests/auth/logs_include_client_info.js b/jstests/auth/logs_include_client_info.js
index 31594a60de5..8d5115cc328 100644
--- a/jstests/auth/logs_include_client_info.js
+++ b/jstests/auth/logs_include_client_info.js
@@ -1,5 +1,6 @@
 // This test just checks that the success/failure messages for authentication include the IP
 // address of the client attempting to authenticate.
+load("jstests/libs/logv2_helpers.js");
 
 (function() {
 const conn = MongoRunner.runMongod({auth: ""});
@@ -18,12 +19,33 @@ failConn.getDB("admin").auth("root", "toot");
 
 const log = assert.commandWorked(admin.runCommand({getLog: "global"})).log;
 
-const successRegex =
-    /Successfully authenticated as principal root on admin from client (?:\d{1,3}\.){3}\d{1,3}:\d+/;
-const failRegex =
-    /SASL SCRAM-SHA-\d+ authentication failed for root on admin from client (?:\d{1,3}\.){3}\d{1,3}:\d+/;
+if (isJsonLog(conn)) {
+    function checkAuthSuccess(element, index, array) {
+        const log = JSON.parse(element);
+
+        return log.id === 20250 && log.attr.principalName === "root" &&
+            log.attr.authDB === "admin" && /(?:\d{1,3}\.){3}\d{1,3}:\d+/.test(log.attr.client);
+    }
+
+    function checkSCRAMfail(element, index, array) {
+        const log = JSON.parse(element);
+
+        return log.id === 20249 && /SCRAM-SHA-\d+/.test(log.attr.mechanism) &&
+            log.attr.principalName === "root" && log.attr.authDB === "admin" &&
+            /(?:\d{1,3}\.){3}\d{1,3}:\d+/.test(log.attr.client);
+    }
+
+    assert(log.some(checkAuthSuccess));
+    assert(log.some(checkSCRAMfail));
+} else {
+    const successRegex =
+        /Successfully authenticated as principal root on admin from client (?:\d{1,3}\.){3}\d{1,3}:\d+/;
+    const failRegex =
+        /SASL SCRAM-SHA-\d+ authentication failed for root on admin from client (?:\d{1,3}\.){3}\d{1,3}:\d+/;
+
+    assert(log.some((line) => successRegex.test(line)));
+    assert(log.some((line) => failRegex.test(line)));
+}
 
-assert(log.some((line) => successRegex.test(line)));
-assert(log.some((line) => failRegex.test(line)));
 MongoRunner.stopMongod(conn);
 })();
diff --git a/jstests/libs/kill_sessions.js b/jstests/libs/kill_sessions.js
index b56554d02c4..bf4a2c541b8 100644
--- a/jstests/libs/kill_sessions.js
+++ b/jstests/libs/kill_sessions.js
@@ -1,4 +1,5 @@
 load("jstests/libs/parallelTester.js");
+load("jstests/libs/logv2_helpers.js");
 
 /**
  * Implements a kill session test helper
@@ -248,11 +249,21 @@ var _kill_sessions_api_module = (function() {
     CursorHandle.prototype.assertCursorKillLogMessages = function(hostsToCheck) {
         for (let hostToCheck of hostsToCheck) {
             if (hostToCheck.host in this._cursors) {
-                assert(checkLog.checkContainsOnce(
-                           hostToCheck,
-                           'killing cursor: ' + this._cursors[hostToCheck.host].exactValueString +
-                               ' as part of killing session(s)'),
-                       "cursor kill was not logged by " + hostToCheck.host);
+                if (isJsonLog(hostToCheck)) {
+                    assert(checkLog.checkContainsOnceJson(
+                               hostToCheck,
+                               20528,
+                               'id',
+                               this._cursors[hostToCheck.host].exactValueString),
+                           "cursor kill was not logged by " + hostToCheck.host);
+                } else {
+                    assert(
+                        checkLog.checkContainsOnce(
+                            hostToCheck,
+                            'killing cursor: ' + this._cursors[hostToCheck.host].exactValueString +
+                                ' as part of killing session(s)'),
+                        "cursor kill was not logged by " + hostToCheck.host);
+                }
             }
         }
     };
diff --git a/src/mongo/db/auth/sasl_commands.cpp b/src/mongo/db/auth/sasl_commands.cpp
index 22403e23303..b91fa86b9a2 100644
--- a/src/mongo/db/auth/sasl_commands.cpp
+++ b/src/mongo/db/auth/sasl_commands.cpp
@@ -189,14 +189,14 @@ Status doSaslStep(OperationContext* opCtx,
 
     if (!swResponse.isOK()) {
         LOGV2(20249,
-              "SASL {mechanism_mechanismName} authentication failed for "
-              "{mechanism_getPrincipalName} on {mechanism_getAuthenticationDatabase} from client "
-              "{opCtx_getClient_getRemote} ; {swResponse_getStatus}",
-              "mechanism_mechanismName"_attr = mechanism.mechanismName(),
-              "mechanism_getPrincipalName"_attr = mechanism.getPrincipalName(),
-              "mechanism_getAuthenticationDatabase"_attr = mechanism.getAuthenticationDatabase(),
-              "opCtx_getClient_getRemote"_attr = opCtx->getClient()->getRemote().toString(),
-              "swResponse_getStatus"_attr = redact(swResponse.getStatus()));
+              "SASL {mechanism} authentication failed for "
+              "{principalName} on {authDB} from client "
+              "{client} ; {result}",
+              "mechanism"_attr = mechanism.mechanismName(),
+              "principalName"_attr = mechanism.getPrincipalName(),
+              "authDB"_attr = mechanism.getAuthenticationDatabase(),
+              "client"_attr = opCtx->getClient()->getRemote().toString(),
+              "result"_attr = redact(swResponse.getStatus()));
 
         sleepmillis(saslGlobalParams.authFailedDelay.load());
         // All the client needs to know is that authentication has failed.
@@ -218,13 +218,12 @@ Status doSaslStep(OperationContext* opCtx,
 
         if (!serverGlobalParams.quiet.load()) {
             LOGV2(20250,
-                  "Successfully authenticated as principal {mechanism_getPrincipalName} on "
-                  "{mechanism_getAuthenticationDatabase} from client "
-                  "{opCtx_getClient_session_remote}",
-                  "mechanism_getPrincipalName"_attr = mechanism.getPrincipalName(),
-                  "mechanism_getAuthenticationDatabase"_attr =
-                      mechanism.getAuthenticationDatabase(),
-                  "opCtx_getClient_session_remote"_attr = opCtx->getClient()->session()->remote());
+                  "Successfully authenticated as principal {principalName} on "
+                  "{authDB} from client "
+                  "{client}",
+                  "principalName"_attr = mechanism.getPrincipalName(),
+                  "authDB"_attr = mechanism.getAuthenticationDatabase(),
+                  "client"_attr = opCtx->getClient()->session()->remote());
         }
         if (session->isSpeculative()) {
             authCounter.incSpeculativeAuthenticateSuccessful(mechanism.mechanismName().toString());
diff --git a/src/mongo/shell/check_log.js b/src/mongo/shell/check_log.js
index e5152becf6e..cf514536f99 100644
--- a/src/mongo/shell/check_log.js
+++ b/src/mongo/shell/check_log.js
@@ -51,6 +51,29 @@ checkLog = (function() {
     };
 
     /*
+     * Calls the 'getLog' function on the provided connection 'conn' to see if a log with the
+     * provided id is found in the logs. If the id is found it looks up the specified attrribute by
+     * attrName and checks if the msg is found in its value. Note: this function does not throw an
+     * exception, so the return value should not be ignored.
+     */
+    const checkContainsOnceJson = function(conn, id, attrName, msg) {
+        const logMessages = getGlobalLog(conn);
+        if (logMessages === null) {
+            return false;
+        }
+
+        for (let logMsg of logMessages) {
+            if (logMsg.search(`\"id\":${id},`) != -1) {
+                if (logMsg.search(`\"${attrName}\":\"?[^\"|\\\"]*` + msg) != -1) {
+                    return true;
+                }
+            }
+        }
+
+        return false;
+    };
+
+    /*
      * Calls the 'getLog' function at regular intervals on the provided connection 'conn' until
      * the provided 'msg' is found in the logs, or it times out. Throws an exception on timeout.
      */
@@ -145,6 +168,7 @@ checkLog = (function() {
     return {
         getGlobalLog: getGlobalLog,
         checkContainsOnce: checkContainsOnce,
+        checkContainsOnceJson: checkContainsOnceJson,
         contains: contains,
         containsWithCount: containsWithCount,
         containsWithAtLeastCount: containsWithAtLeastCount,