SERVER-72815: Track document count and duration for updateMany and deleteMany calls (v6.0)

3 files changed, 198 insertions, 58 deletions

diff --git a/jstests/sharding/update_delete_many_metrics.js b/jstests/sharding/update_delete_many_metrics.js
index af7daf59d20..3987f9ab156 100644
--- a/jstests/sharding/update_delete_many_metrics.js
+++ b/jstests/sharding/update_delete_many_metrics.js
@@ -14,48 +14,68 @@
     st.rs1.nodes.forEach(node => mongodConns.push(node));
 
     const testDB = st.s.getDB("test");
-    const testColl = testDB.coll;
-    const unshardedColl = testDB.unsharded;
+    const shardedColl = testDB.shardedColl;
+    const unshardedColl = testDB.unshardedColl;
 
     assert.commandWorked(st.s0.adminCommand({enableSharding: testDB.getName()}));
     st.ensurePrimaryShard(testDB.getName(), st.shard0.shardName);
 
-    // Shard testColl on {x:1}, split it at {x:0}, and move chunk {x:1} to shard1.
-    st.shardColl(testColl, {x: 1}, {x: 0}, {x: 1});
+    // Shard shardedColl on {x:1}, split it at {x:0}, and move chunk {x:1} to shard1.
+    st.shardColl(shardedColl, {x: 1}, {x: 0}, {x: 1});
 
     // Insert one document on each shard.
-    assert.commandWorked(testColl.insert({x: 1, _id: 1}));
-    assert.commandWorked(testColl.insert({x: -1, _id: 0}));
+    assert.commandWorked(shardedColl.insert({x: 1, _id: 1}));
+    assert.commandWorked(shardedColl.insert({x: 2, _id: 2}));
+    assert.commandWorked(shardedColl.insert({x: -1, _id: -1}));
+    assert.commandWorked(shardedColl.insert({x: -2, _id: -2}));
+    assert.eq(4, shardedColl.find().itcount());
 
-    assert.eq(2, testColl.countDocuments({}));
     assert.commandWorked(unshardedColl.insert({x: 1, _id: 1}));
-    assert.eq(1, unshardedColl.countDocuments({}));
+    assert.commandWorked(unshardedColl.insert({x: -11, _id: 0}));
+    assert.eq(2, unshardedColl.find().itcount());
 
     let mongosServerStatus = testDB.adminCommand({serverStatus: 1});
 
-    // Verification for 'updateManyCount' metric.
+    // Verification for initial values.
     assert.eq(0, mongosServerStatus.metrics.query.updateManyCount);
-    // Verification for 'deleteManyCount' metric.
     assert.eq(0, mongosServerStatus.metrics.query.deleteManyCount);
 
     assert.commandWorked(unshardedColl.update({_id: 1}, {$set: {a: 2}}, {multi: false}));
-    assert.commandWorked(testColl.update({_id: 1}, {$set: {a: 2}}, {multi: false}));
+    assert.eq(1, unshardedColl.find({a: 2}).count());
+
+    assert.commandWorked(shardedColl.update({_id: 1}, {$set: {a: 2}}, {multi: false}));
+    assert.eq(1, shardedColl.find({a: 2}).count());
+
     // 3 update with multi:true calls.
-    assert.commandWorked(unshardedColl.update({_id: 1}, {$set: {a: 2}}, {multi: true}));
-    assert.commandWorked(testColl.update({}, {$set: {a: 3}}, {multi: true}));
-    assert.commandWorked(testColl.update({_id: 1}, {$set: {a: 2}}, {multi: true}));
+    assert.commandWorked(unshardedColl.update({}, {$set: {a: 3}}, {multi: true}));
+    assert.eq(2, unshardedColl.find({a: 3}).count());
+    assert.commandWorked(shardedColl.update({}, {$set: {a: 3}}, {multi: true}));
+    assert.eq(0, shardedColl.find({a: 2}).count());
+    assert.eq(4, shardedColl.find({a: 3}).count());
+    assert.commandWorked(shardedColl.update({}, {$set: {a: 4}}, {multi: true}));
+    assert.eq(4, shardedColl.find({a: 4}).count());
 
     // 2 updateMany calls.
-    assert.commandWorked(testColl.updateMany({}, {$set: {array: 'string', doc: 'string'}}));
+    assert.commandWorked(shardedColl.updateMany({}, {$set: {array: 'string', doc: 'string'}}));
     assert.commandWorked(unshardedColl.updateMany({}, {$set: {array: 'string', doc: 'string'}}));
 
+    // batch update: 2 more, so 7 updates in total
+    var request = {
+        update: shardedColl.getName(),
+        updates: [{q: {}, u: {$set: {c: 3}}, multi: true}, {q: {}, u: {$set: {a: 5}}, multi: true}],
+        writeConcern: {w: 1},
+        ordered: false
+    };
+    shardedColl.runCommand(request);
+    assert.eq(4, shardedColl.find({a: 5}).count());
+
     // Use deleteMany to delete one of the documents.
-    const result = testColl.deleteMany({_id: 1});
+    const result = shardedColl.deleteMany({_id: 1});
     assert.commandWorked(result);
     assert.eq(1, result.deletedCount);
-    assert.eq(1, testColl.countDocuments({}));
+    assert.eq(3, shardedColl.find().itcount());
     // Next call will not increase count.
-    assert.commandWorked(testColl.deleteOne({_id: 1}));
+    assert.commandWorked(shardedColl.deleteOne({_id: 1}));
 
     // Use deleteMany to delete one document in the unsharded collection.
     assert.commandWorked(unshardedColl.deleteMany({_id: 1}));
@@ -63,10 +83,8 @@
     assert.commandWorked(unshardedColl.deleteOne({_id: 1}));
 
     mongosServerStatus = testDB.adminCommand({serverStatus: 1});
-
-    // Verification for 'updateManyCount' metric.
-    assert.eq(5, mongosServerStatus.metrics.query.updateManyCount);
-    // Verification for 'deleteManyCount' metric.
+    // Verification for metrics.
+    assert.eq(7, mongosServerStatus.metrics.query.updateManyCount);
     assert.eq(2, mongosServerStatus.metrics.query.deleteManyCount);
 
     st.stop();
@@ -80,42 +98,65 @@
     const primary = rst.getPrimary();
     const testDB = primary.getDB("test");
     const testColl = testDB.coll;
-    const unshardedColl = testDB.unsharded;
 
-    // Insert one document on each shard.
+    // Insert documents
     assert.commandWorked(testColl.insert({x: 1, _id: 1}));
-    assert.commandWorked(testColl.insert({x: -1, _id: 0}));
-    assert.eq(2, testColl.countDocuments({}));
+    assert.commandWorked(testColl.insert({x: 2, _id: 2}));
+    assert.commandWorked(testColl.insert({x: -1, _id: -1}));
+    assert.commandWorked(testColl.insert({x: -2, _id: -2}));
+    assert.eq(4, testColl.find().itcount());
 
     let mongosServerStatus = testDB.adminCommand({serverStatus: 1});
 
-    // Verification for 'updateManyCount' metric.
+    // Verification for initial values.
     assert.eq(0, mongosServerStatus.metrics.query.updateManyCount);
-    // Verification for 'deleteManyCount' metric.
     assert.eq(0, mongosServerStatus.metrics.query.deleteManyCount);
+    assert.eq(0, mongosServerStatus.metrics.query.updateDeleteManyDocumentsMaxCount);
+    assert.eq(0, mongosServerStatus.metrics.query.updateDeleteManyDurationMaxMs);
+    assert.eq(0, mongosServerStatus.metrics.query.updateDeleteManyDocumentsTotalCount);
+    assert.eq(0, mongosServerStatus.metrics.query.updateDeleteManyDurationTotalMs);
 
     assert.commandWorked(testColl.update({_id: 1}, {$set: {a: 2}}, {multi: false}));
-    // 3 update with multi:true calls.
+    assert.eq(1, testColl.find({a: 2}).count());
+    // 2 update with multi:true calls.
     assert.commandWorked(testColl.update({}, {$set: {a: 3}}, {multi: true}));
-    assert.commandWorked(testColl.update({_id: 1}, {$set: {a: 2}}, {multi: true}));
+    assert.eq(0, testColl.find({a: 2}).count());
+    assert.eq(4, testColl.find({a: 3}).count());
+    assert.commandWorked(testColl.update({}, {$set: {a: 4}}, {multi: true}));
+    assert.eq(4, testColl.find({a: 4}).count());
 
-    // 2 updateMany call.
+    // 1 updateMany call.
     assert.commandWorked(testColl.updateMany({}, {$set: {array: 'string', doc: 'string'}}));
 
-    // Use deleteMany to delete one of the documents.
-    const result = testColl.deleteMany({_id: 1});
+    // batch update: 2 more, so 5 updates in total
+    var request = {
+        update: testColl.getName(),
+        updates: [{q: {}, u: {$set: {c: 3}}, multi: true}, {q: {}, u: {$set: {a: 5}}, multi: true}],
+        writeConcern: {w: 1},
+        ordered: false
+    };
+    testColl.runCommand(request);
+    assert.eq(4, testColl.find({a: 5}).count());
+
+    // Use deleteMany to delete two of the documents.
+    const result = testColl.deleteMany({_id: {$lt: 0}});
     assert.commandWorked(result);
-    assert.eq(1, result.deletedCount);
-    assert.eq(1, testColl.countDocuments({}));
+    assert.eq(2, result.deletedCount);
+    assert.eq(2, testColl.find().itcount());
     // Next call will not increase count.
     assert.commandWorked(testColl.deleteOne({_id: 1}));
 
     mongosServerStatus = testDB.adminCommand({serverStatus: 1});
 
-    // Verification for 'updateManyCount' metric.
-    assert.eq(3, mongosServerStatus.metrics.query.updateManyCount);
-    // Verification for 'deleteManyCount' metric.
+    // Verification for final metric values.
+    assert.eq(5, mongosServerStatus.metrics.query.updateManyCount);
     assert.eq(1, mongosServerStatus.metrics.query.deleteManyCount);
+    assert.eq(4, mongosServerStatus.metrics.query.updateDeleteManyDocumentsMaxCount);
+    assert(mongosServerStatus.metrics.query.hasOwnProperty("updateDeleteManyDurationMaxMs"));
+    assert.lte(0, mongosServerStatus.metrics.query.updateDeleteManyDurationMaxMs);
+    assert.eq(22, mongosServerStatus.metrics.query.updateDeleteManyDocumentsTotalCount);
+    assert(mongosServerStatus.metrics.query.hasOwnProperty("updateDeleteManyDurationTotalMs"));
+    assert.lte(0, mongosServerStatus.metrics.query.updateDeleteManyDurationTotalMs);
 
     rst.stopSet();
 }
diff --git a/src/mongo/db/commands/write_commands.cpp b/src/mongo/db/commands/write_commands.cpp
index ccbfec7d9cc..495644a9aa3 100644
--- a/src/mongo/db/commands/write_commands.cpp
+++ b/src/mongo/db/commands/write_commands.cpp
@@ -1524,9 +1524,6 @@ public:
                 if (update.getArrayFilters()) {
                     CmdUpdate::updateMetrics.incrementExecutedWithArrayFilters();
                 }
-                if (update.getMulti()) {
-                    updateManyCount.increment(1);
-                }
             }
 
             return updateReply;
@@ -1673,13 +1670,6 @@ public:
                           std::move(reply),
                           &deleteReply);
 
-            // Collect metrics.
-            for (auto&& deletes : request().getDeletes()) {
-                if (deletes.getMulti()) {
-                    deleteManyCount.increment(1);
-                }
-            }
-
             return deleteReply;
         } catch (const DBException& ex) {
             NotPrimaryErrorTracker::get(opCtx->getClient()).recordError(ex.code());
diff --git a/src/mongo/db/ops/write_ops_exec.cpp b/src/mongo/db/ops/write_ops_exec.cpp
index 258bccbbd4e..14f373d69fd 100644
--- a/src/mongo/db/ops/write_ops_exec.cpp
+++ b/src/mongo/db/ops/write_ops_exec.cpp
@@ -96,6 +96,46 @@
 #include "mongo/util/scopeguard.h"
 
 namespace mongo::write_ops_exec {
+class Atomic64Metric;
+}  // namespace mongo::write_ops_exec
+
+namespace mongo {
+template <>
+struct BSONObjAppendFormat<write_ops_exec::Atomic64Metric> : FormatKind<NumberLong> {};
+}  // namespace mongo
+
+
+namespace mongo::write_ops_exec {
+
+/**
+ * Atomic wrapper for long long type for Metrics.
+ */
+class Atomic64Metric {
+public:
+    /** Set _value to the max of the current or newMax. */
+    void setIfMax(long long newMax) {
+        /*  Note: compareAndSwap will load into val most recent value. */
+        for (long long val = _value.load(); val < newMax && !_value.compareAndSwap(&val, newMax);) {
+        }
+    }
+
+    /** store val into value. */
+    void set(long long val) {
+        _value.store(val);
+    }
+
+    /** Return the current value. */
+    long long get() const {
+        return _value.load();
+    }
+
+    operator long long() const {
+        return get();
+    }
+
+private:
+    mongo::AtomicWord<long long> _value;
+};
 
 // Convention in this file: generic helpers go in the anonymous namespace. Helpers that are for a
 // single type of operation are static functions defined above their caller.
@@ -119,6 +159,51 @@ MONGO_FAIL_POINT_DEFINE(hangWithLockDuringBatchUpdate);
 MONGO_FAIL_POINT_DEFINE(hangWithLockDuringBatchRemove);
 MONGO_FAIL_POINT_DEFINE(failAtomicTimeseriesWrites);
 
+
+/**
+ * Metrics group for the `updateMany` and `deleteMany` operations. For each
+ * operation, the `duration` and `numDocs` will contribute to aggregated total
+ * and max metrics.
+ */
+class MultiUpdateDeleteMetrics {
+public:
+    void operator()(Microseconds duration, size_t numDocs) {
+        _durationTotalMicroseconds.increment(durationCount<Microseconds>(duration));
+        _durationTotalMs.set(
+            durationCount<Milliseconds>(Microseconds{_durationTotalMicroseconds.get()}));
+        _durationMaxMs.setIfMax(durationCount<Milliseconds>(duration));
+
+        _numDocsTotal.increment(numDocs);
+        _numDocsMax.setIfMax(numDocs);
+    }
+
+private:
+    /**
+     * To avoid rapid accumulation of roundoff error in the duration total, it
+     * is maintained precisely, and we arrange for the corresponding
+     * Millisecond metric to hold an exported low-res image of it.
+     */
+    Counter64 _durationTotalMicroseconds;
+
+    Atomic64Metric _durationTotalMs;
+    ServerStatusMetricField<Atomic64Metric> _displayDurationTotalMs{
+        "query.updateDeleteManyDurationTotalMs", &_durationTotalMs};
+    Atomic64Metric _durationMaxMs;
+    ServerStatusMetricField<Atomic64Metric> _displayDurationMaxMs{
+        "query.updateDeleteManyDurationMaxMs", &_durationMaxMs};
+
+    Counter64 _numDocsTotal;
+    ServerStatusMetricField<Counter64> displayNumDocsTotal{
+        "query.updateDeleteManyDocumentsTotalCount", &_numDocsTotal};
+
+    Atomic64Metric _numDocsMax;
+    ServerStatusMetricField<Atomic64Metric> _displayNumDocsMax{
+        "query.updateDeleteManyDocumentsMaxCount", &_numDocsMax};
+};
+
+MultiUpdateDeleteMetrics collectMultiUpdateDeleteMetrics;
+
+
 void updateRetryStats(OperationContext* opCtx, bool containsRetry) {
     if (containsRetry) {
         RetryableWritesStats::get(opCtx)->incrementRetriedCommandsCount();
@@ -1090,7 +1175,12 @@ WriteResult performUpdates(OperationContext* opCtx,
                 ? *wholeOp.getStmtIds()
                 : std::vector<StmtId>{stmtId};
 
-            out.results.emplace_back(
+            boost::optional<Timer> timer;
+            if (singleOp.getMulti()) {
+                timer.emplace();
+            }
+
+            const SingleWriteResult&& reply =
                 performSingleUpdateOpWithDupKeyRetry(opCtx,
                                                      ns,
                                                      wholeOp.getCollectionUUID(),
@@ -1099,9 +1189,15 @@ WriteResult performUpdates(OperationContext* opCtx,
                                                      runtimeConstants,
                                                      wholeOp.getLet(),
                                                      source,
-                                                     forgoOpCounterIncrements));
+                                                     forgoOpCounterIncrements);
+            out.results.emplace_back(reply);
             forgoOpCounterIncrements = true;
             lastOpFixer.finishedOpSuccessfully();
+
+            if (singleOp.getMulti()) {
+                updateManyCount.increment(1);
+                collectMultiUpdateDeleteMetrics(timer->elapsed(), reply.getNModified());
+            }
         } catch (const DBException& ex) {
             out.canContinue = handleError(
                 opCtx, ex, ns, wholeOp.getWriteCommandRequestBase(), singleOp.getMulti(), &out);
@@ -1317,15 +1413,28 @@ WriteResult performDeletes(OperationContext* opCtx,
         });
         try {
             lastOpFixer.startingOp();
-            out.results.push_back(performSingleDeleteOp(opCtx,
-                                                        ns,
-                                                        wholeOp.getCollectionUUID(),
-                                                        stmtId,
-                                                        singleOp,
-                                                        runtimeConstants,
-                                                        wholeOp.getLet(),
-                                                        source));
+
+            boost::optional<Timer> timer;
+            if (singleOp.getMulti()) {
+                timer.emplace();
+            }
+
+            const SingleWriteResult&& reply = performSingleDeleteOp(opCtx,
+                                                                    ns,
+                                                                    wholeOp.getCollectionUUID(),
+                                                                    stmtId,
+                                                                    singleOp,
+                                                                    runtimeConstants,
+                                                                    wholeOp.getLet(),
+                                                                    source);
+            out.results.push_back(reply);
             lastOpFixer.finishedOpSuccessfully();
+
+            // Collect metrics.
+            if (singleOp.getMulti()) {
+                deleteManyCount.increment(1);
+                collectMultiUpdateDeleteMetrics(timer->elapsed(), reply.getN());
+            }
         } catch (const DBException& ex) {
             out.canContinue = handleError(
                 opCtx, ex, ns, wholeOp.getWriteCommandRequestBase(), false /* multiUpdate */, &out);