SERVER-43246 Add a log line for when a cursor is reaped due to logical session cleanup

(cherry picked from commit 89c93866980e924c7ae91ca30b5bd3674727fe4f)

SERVER-45277 Temporarily blacklist sharding/kill_sessions.js in multiversion

(cherry picked from commit 532b4a761e27d3ffa3b852fd3e936190dd5d2461)

7 files changed, 64 insertions, 2 deletions

diff --git a/jstests/libs/kill_sessions.js b/jstests/libs/kill_sessions.js
index 4941274c02d..fb2f783b549 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/check_log.js");
 
 /**
  * Implements a kill session test helper
@@ -223,8 +224,14 @@ var _kill_sessions_api_module = (function() {
         });
     };
 
-    function CursorHandle(session) {
+    Fixture.prototype.assertCursorKillLogMessages = function(cursorHandles) {
+        cursorHandles.forEach(
+            cursorHandle => cursorHandle.assertCursorKillLogMessages(this._clientsToVerifyVia));
+    };
+
+    function CursorHandle(session, cursors) {
         this._session = session;
+        this._cursors = cursors;
     }
 
     CursorHandle.prototype.getLsid = function() {
@@ -235,6 +242,19 @@ var _kill_sessions_api_module = (function() {
         this._session.endSession();
     };
 
+    CursorHandle.prototype.assertCursorKillLogMessages = function(hostsToCheck) {
+        for (let hostToCheck of hostsToCheck) {
+            if (hostToCheck.host in this._cursors) {
+                let targetCursorId = this._cursors[hostToCheck.host].exactValueString;
+                assert.doesNotThrow(function() {
+                    checkLog.contains(
+                        hostToCheck,
+                        'killing cursor: ' + targetCursorId + ' as part of killing session(s)');
+                }, [], "cursor kill was not logged by " + hostToCheck.host);
+            }
+        }
+    };
+
     /**
      * We start cursors on all nodes in a very artificial way.  In particular, we run currentOp
      * (because it's a data source that's always there) and use an agg pipeline to get enough
@@ -259,18 +279,23 @@ var _kill_sessions_api_module = (function() {
             },
         };
 
+        var cursors = {};
         var result;
         if (this._clientToExecuteViaIsdbgrid) {
             result = db.runCommand({multicast: cmd});
+            for (let host of Object.keys(result.hosts)) {
+                cursors[host] = result.hosts[host].data.cursor.id;
+            }
         } else {
             result = db.runCommand(cmd);
+            cursors[db.getMongo().host] = result.cursor.id;
         }
         if (!result.ok) {
             print(tojson(result));
         }
         assert(result.ok);
 
-        return new CursorHandle(session);
+        return new CursorHandle(session, cursors);
     };
 
     /**
@@ -309,6 +334,7 @@ var _kill_sessions_api_module = (function() {
                 fixture.assertSessionsInCursors([handle], []);
                 fixture.kill("admin", obj);
                 fixture.assertNoSessionsInCursors();
+                fixture.assertCursorKillLogMessages([handle]);
                 handle.join();
             },
 
@@ -319,6 +345,7 @@ var _kill_sessions_api_module = (function() {
                 fixture.assertSessionsInCursors([handle1, handle2], []);
                 fixture.kill("admin", obj);
                 fixture.assertNoSessionsInCursors();
+                fixture.assertCursorKillLogMessages([handle1, handle2]);
                 handle1.join();
                 handle2.join();
             },
@@ -368,6 +395,7 @@ var _kill_sessions_api_module = (function() {
                     fixture.kill("admin", obj);
                 }
                 fixture.assertSessionsInCursors([handle3], [handle1, handle2]);
+                fixture.assertCursorKillLogMessages([handle1, handle2]);
                 handle1.join();
                 handle2.join();
 
@@ -377,6 +405,7 @@ var _kill_sessions_api_module = (function() {
                     fixture.kill("admin", obj);
                 }
                 fixture.assertNoSessionsInCursors();
+                fixture.assertCursorKillLogMessages([handle3]);
                 handle3.join();
             },
         ];
@@ -524,6 +553,7 @@ var _kill_sessions_api_module = (function() {
                     fixture.kill("admin", obj);
                 }
                 fixture.assertSessionsInCursors([handle3], [handle1, handle2]);
+                fixture.assertCursorKillLogMessages([handle1, handle2]);
                 handle1.join();
                 handle2.join();
 
@@ -533,6 +563,7 @@ var _kill_sessions_api_module = (function() {
                     fixture.kill("admin", obj);
                 }
                 fixture.assertNoSessionsInCursors();
+                fixture.assertCursorKillLogMessages([handle3]);
                 handle3.join();
             },
         ];
diff --git a/jstests/sharding/kill_sessions.js b/jstests/sharding/kill_sessions.js
index 2af0a6a0658..e30b7f75230 100644
--- a/jstests/sharding/kill_sessions.js
+++ b/jstests/sharding/kill_sessions.js
@@ -1,3 +1,11 @@
+/*
+ * Run the kill_sessions tests against a sharded cluster.
+ *
+ * TODO SERVER-45385: These tests can be enabled in multiversion once the logging of session cursor
+ * cleanup has been backported and released in last-stable.
+ * @tags: [multiversion_incompatible]
+ */
+
 load("jstests/libs/kill_sessions.js");
 
 (function() {
diff --git a/src/mongo/db/cursor_manager.cpp b/src/mongo/db/cursor_manager.cpp
index 961a72030be..bfb27d07254 100644
--- a/src/mongo/db/cursor_manager.cpp
+++ b/src/mongo/db/cursor_manager.cpp
@@ -334,6 +334,7 @@ std::pair<Status, int> CursorManager::killCursorsWithMatchingSessions(
     OperationContext* opCtx, const SessionKiller::Matcher& matcher) {
     auto eraser = [&](CursorManager& mgr, CursorId id) {
         uassertStatusOK(mgr.eraseCursor(opCtx, id, true));
+        log() << "killing cursor: " << id << " as part of killing session(s)";
     };
 
     auto visitor = makeKillSessionsCursorManagerVisitor(opCtx, matcher, std::move(eraser));
diff --git a/src/mongo/s/query/cluster_cursor_manager.cpp b/src/mongo/s/query/cluster_cursor_manager.cpp
index 246be0957a0..6ed2bc89e40 100644
--- a/src/mongo/s/query/cluster_cursor_manager.cpp
+++ b/src/mongo/s/query/cluster_cursor_manager.cpp
@@ -543,6 +543,7 @@ std::pair<Status, int> ClusterCursorManager::killCursorsWithMatchingSessions(
     OperationContext* opCtx, const SessionKiller::Matcher& matcher) {
     auto eraser = [&](ClusterCursorManager& mgr, CursorId id) {
         uassertStatusOK(mgr.killCursor(getNamespaceForCursorId(id).get(), id));
+        log() << "killing cursor: " << id << " as part of killing session(s)";
     };
 
     auto visitor = makeKillSessionsCursorManagerVisitor(opCtx, matcher, std::move(eraser));
diff --git a/src/mongo/scripting/mozjs/internedstring.defs b/src/mongo/scripting/mozjs/internedstring.defs
index 22d698b635e..b200572b8e5 100644
--- a/src/mongo/scripting/mozjs/internedstring.defs
+++ b/src/mongo/scripting/mozjs/internedstring.defs
@@ -17,6 +17,7 @@ MONGO_MOZJS_INTERNED_STRING(defaultDB, "defaultDB")
 MONGO_MOZJS_INTERNED_STRING(dollar_db, "$db")
 MONGO_MOZJS_INTERNED_STRING(dollar_id, "$id")
 MONGO_MOZJS_INTERNED_STRING(dollar_ref, "$ref")
+MONGO_MOZJS_INTERNED_STRING(exactValueString, "exactValueString")
 MONGO_MOZJS_INTERNED_STRING(_fields, "_fields")
 MONGO_MOZJS_INTERNED_STRING(flags, "flags")
 MONGO_MOZJS_INTERNED_STRING(floatApprox, "floatApprox")
diff --git a/src/mongo/scripting/mozjs/numberlong.cpp b/src/mongo/scripting/mozjs/numberlong.cpp
index ff60d031198..66d9fcb8824 100644
--- a/src/mongo/scripting/mozjs/numberlong.cpp
+++ b/src/mongo/scripting/mozjs/numberlong.cpp
@@ -131,6 +131,13 @@ void NumberLongInfo::Functions::floatApprox::call(JSContext* cx, JS::CallArgs ar
     ValueReader(cx, args.rval()).fromDouble(numLong);
 }
 
+void NumberLongInfo::Functions::exactValueString::call(JSContext* cx, JS::CallArgs args) {
+    str::stream ss;
+    int64_t val = NumberLongInfo::ToNumberLong(cx, args.thisv());
+    ss << val;
+    ValueReader(cx, args.rval()).fromStringData(ss.operator std::string());
+}
+
 void NumberLongInfo::Functions::top::call(JSContext* cx, JS::CallArgs args) {
     auto numULong = static_cast<uint64_t>(NumberLongInfo::ToNumberLong(cx, args.thisv()));
     ValueReader(cx, args.rval()).fromDouble(numULong >> 32);
@@ -240,6 +247,18 @@ void NumberLongInfo::postInstall(JSContext* cx, JS::HandleObject global, JS::Han
             nullptr)) {
         uasserted(ErrorCodes::JSInterpreterFailure, "Failed to JS_DefinePropertyById");
     }
+
+    // exactValueString
+    if (!JS_DefinePropertyById(
+            cx,
+            proto,
+            getScope(cx)->getInternedStringId(InternedString::exactValueString),
+            undef,
+            JSPROP_ENUMERATE | JSPROP_SHARED,
+            smUtils::wrapConstrainedMethod<Functions::exactValueString, false, NumberLongInfo>,
+            nullptr)) {
+        uasserted(ErrorCodes::JSInterpreterFailure, "Failed to JS_DefinePropertyById");
+    }
 }
 
 }  // namespace mozjs
diff --git a/src/mongo/scripting/mozjs/numberlong.h b/src/mongo/scripting/mozjs/numberlong.h
index e1e6ff52774..21b864844f5 100644
--- a/src/mongo/scripting/mozjs/numberlong.h
+++ b/src/mongo/scripting/mozjs/numberlong.h
@@ -64,6 +64,7 @@ struct NumberLongInfo : public BaseInfo {
         MONGO_DECLARE_JS_FUNCTION(floatApprox);
         MONGO_DECLARE_JS_FUNCTION(top);
         MONGO_DECLARE_JS_FUNCTION(bottom);
+        MONGO_DECLARE_JS_FUNCTION(exactValueString);
     };
 
     static const JSFunctionSpec methods[6];