SERVER-48352 logv2 cleanup for scripting/mozjs, shell/

o also, deduplicated the example log id's in src/mongo/logv2/README.md
  even though they were just examples, it was funny that there werre not
  unique

6 files changed, 39 insertions, 45 deletions

diff --git a/src/mongo/scripting/mozjs/cursor_handle.cpp b/src/mongo/scripting/mozjs/cursor_handle.cpp
index 80be58b5370..34ecada45f0 100644
--- a/src/mongo/scripting/mozjs/cursor_handle.cpp
+++ b/src/mongo/scripting/mozjs/cursor_handle.cpp
@@ -78,7 +78,6 @@ void CursorHandleInfo::finalize(js::FreeOp* fop, JSObject* obj) {
 
                 try {
                     LOGV2_INFO(22782,
-                               "Failed to kill cursor {cursorId} due to {error}",
                                "Failed to kill cursor",
                                "cursorId"_attr = cursorId,
                                "error"_attr = status);
diff --git a/src/mongo/scripting/mozjs/engine.cpp b/src/mongo/scripting/mozjs/engine.cpp
index 557d9a8c0f9..1bbef343399 100644
--- a/src/mongo/scripting/mozjs/engine.cpp
+++ b/src/mongo/scripting/mozjs/engine.cpp
@@ -83,37 +83,37 @@ mongo::Scope* MozJSScriptEngine::createScopeForCurrentThread(boost::optional<int
 
 void MozJSScriptEngine::interrupt(unsigned opId) {
     stdx::lock_guard<Latch> intLock(_globalInterruptLock);
+    auto knownOps = [&]() {
+        std::vector<unsigned> ret;
+        for (auto&& iSc : _opToScopeMap) {
+            ret.push_back(iSc.first);
+        }
+        return ret;
+    };
     OpIdToScopeMap::iterator iScope = _opToScopeMap.find(opId);
     if (iScope == _opToScopeMap.end()) {
         // got interrupt request for a scope that no longer exists
-        LOGV2_DEBUG(22783,
-                    1,
-                    "received interrupt request for unknown op: {opId}{printKnownOps_inlock}",
-                    "opId"_attr = opId,
-                    "printKnownOps_inlock"_attr = printKnownOps_inlock());
+        if (shouldLog(logv2::LogSeverity::Debug(2))) {
+            // This log record gets extra attributes when the log severity is at Debug(2)
+            // but we still log the record at log severity Debug(1). Simplify this if SERVER-48671
+            // gets done
+            LOGV2_DEBUG(22783,
+                        1,
+                        "Received interrupt request for unknown op",
+                        "opId"_attr = opId,
+                        "knownOps"_attr = knownOps());
+        } else {
+            LOGV2_DEBUG(22790, 1, "Received interrupt request for unknown op", "opId"_attr = opId);
+        }
         return;
     }
-
-    LOGV2_DEBUG(22784,
-                1,
-                "interrupting op: {opId}{printKnownOps_inlock}",
-                "opId"_attr = opId,
-                "printKnownOps_inlock"_attr = printKnownOps_inlock());
-    iScope->second->kill();
-}
-
-std::string MozJSScriptEngine::printKnownOps_inlock() {
-    str::stream out;
-
     if (shouldLog(logv2::LogSeverity::Debug(2))) {
-        out << "  known ops: \n";
-
-        for (auto&& iSc : _opToScopeMap) {
-            out << "  " << iSc.first << "\n";
-        }
+        // Like above, this log record gets extra attributes when the log severity is at Debug(2)
+        LOGV2_DEBUG(22809, 1, "Interrupting op", "opId"_attr = opId, "knownOps"_attr = knownOps());
+    } else {
+        LOGV2_DEBUG(22808, 1, "Interrupting op", "opId"_attr = opId);
     }
-
-    return out;
+    iScope->second->kill();
 }
 
 void MozJSScriptEngine::interruptAll() {
@@ -157,8 +157,8 @@ void MozJSScriptEngine::registerOperation(OperationContext* opCtx, MozJSImplScop
 
     LOGV2_DEBUG(22785,
                 2,
-                "SMScope {reinterpret_cast_uint64_t_scope} registered for op {opId}",
-                "reinterpret_cast_uint64_t_scope"_attr = reinterpret_cast<uint64_t>(scope),
+                "scope registered for op",
+                "scope"_attr = reinterpret_cast<uint64_t>(scope),
                 "opId"_attr = opId);
     Status status = opCtx->checkForInterruptNoAssert();
     if (!status.isOK()) {
@@ -171,8 +171,8 @@ void MozJSScriptEngine::unregisterOperation(unsigned int opId) {
 
     LOGV2_DEBUG(22786,
                 2,
-                "ImplScope {reinterpret_cast_uint64_t_this} unregistered for op {opId}",
-                "reinterpret_cast_uint64_t_this"_attr = reinterpret_cast<uint64_t>(this),
+                "scope unregistered for op",
+                "scope"_attr = reinterpret_cast<uint64_t>(this),
                 "opId"_attr = opId);
 
     if (opId != 0) {
diff --git a/src/mongo/scripting/mozjs/engine.h b/src/mongo/scripting/mozjs/engine.h
index c8aecdf7fb0..577248dd6d6 100644
--- a/src/mongo/scripting/mozjs/engine.h
+++ b/src/mongo/scripting/mozjs/engine.h
@@ -86,8 +86,6 @@ public:
     }
 
 private:
-    std::string printKnownOps_inlock();
-
     /**
      * This mutex protects _opToScopeMap
      */
diff --git a/src/mongo/scripting/mozjs/global.cpp b/src/mongo/scripting/mozjs/global.cpp
index 3ff4f9129ba..e8e8b57e040 100644
--- a/src/mongo/scripting/mozjs/global.cpp
+++ b/src/mongo/scripting/mozjs/global.cpp
@@ -83,10 +83,10 @@ void GlobalInfo::Functions::print::call(JSContext* cx, JS::CallArgs args) {
     args.rval().setUndefined();
 
     LOGV2_INFO_OPTIONS(
-        4615635,
+        20162,
         logv2::LogOptions(logv2::LogTag::kPlainShell, logv2::LogTruncation::Disabled),
-        "{message}",
-        "message"_attr = ss.str());
+        "{jsPrint}",
+        "jsPrint"_attr = ss.str());
 }
 
 void GlobalInfo::Functions::version::call(JSContext* cx, JS::CallArgs args) {
diff --git a/src/mongo/scripting/mozjs/implscope.cpp b/src/mongo/scripting/mozjs/implscope.cpp
index 6ed2263cf88..3834fff7629 100644
--- a/src/mongo/scripting/mozjs/implscope.cpp
+++ b/src/mongo/scripting/mozjs/implscope.cpp
@@ -239,12 +239,10 @@ void MozJSImplScope::_gcCallback(JSContext* rt, JSGCStatus status, void* data) {
     }
 
     LOGV2_INFO(22787,
-               "MozJS GC {status_JSGC_BEGIN_prologue_epilogue} heap stats -  total: "
-               "{mongo_sm_get_total_bytes} limit: {mongo_sm_get_max_bytes}",
-               "status_JSGC_BEGIN_prologue_epilogue"_attr =
-                   (status == JSGC_BEGIN ? "prologue" : "epilogue"),
-               "mongo_sm_get_total_bytes"_attr = mongo::sm::get_total_bytes(),
-               "mongo_sm_get_max_bytes"_attr = mongo::sm::get_max_bytes());
+               "MozJS GC heap stats",
+               "phase"_attr = (status == JSGC_BEGIN ? "prologue" : "epilogue"),
+               "total"_attr = mongo::sm::get_total_bytes(),
+               "limit"_attr = mongo::sm::get_max_bytes());
 }
 
 #if __has_feature(address_sanitizer)
@@ -949,10 +947,10 @@ bool MozJSImplScope::_checkErrorState(bool success, bool reportError, bool asser
 
     if (reportError)
         LOGV2_INFO_OPTIONS(
-            4635900,
+            20163,
             logv2::LogOptions(logv2::LogTag::kPlainShell, logv2::LogTruncation::Disabled),
-            "{message}",
-            "message"_attr = redact(_error));
+            "{jsError}",
+            "jsError"_attr = redact(_error));
 
     // Clear the status state
     auto status = std::move(_status);
diff --git a/src/mongo/scripting/mozjs/session.cpp b/src/mongo/scripting/mozjs/session.cpp
index c7202314799..6aa805ff425 100644
--- a/src/mongo/scripting/mozjs/session.cpp
+++ b/src/mongo/scripting/mozjs/session.cpp
@@ -153,8 +153,7 @@ void SessionInfo::finalize(js::FreeOp* fop, JSObject* obj) {
 
             try {
                 LOGV2_INFO(22791,
-                           "Failed to end session {lsid} due to {error}",
-                           "Failed to end session",
+                           "Failed to end logical session",
                            "lsid"_attr = lsid,
                            "error"_attr = status);
             } catch (...) {