SERVER-14223: Fix collection stats for insert

Also rewrite top.js to actually test the stats

jstests/core/top.js

@@ -5,22 +5,101 @@
 var name = "toptest";
 
 var testDB = db.getSiblingDB(name);
-var testColl = testDB[name + "coll"]
+var testColl = testDB[name + "coll"];
 
-testColl.drop()
+//  Ensure an empty collection exists for first top command
+testColl.drop();
+testColl.insert({x:0});
+testColl.remove({x:0});
 
-var topResult = testDB.adminCommand("top");
-printjson(topResult.totals[testColl.getFullName()]);
-
-var inserts = 0;
-for(i=0;i<20;i++) {
-	testColl.insert({_id:i});
-	inserts++;
+// get top statistics for the test collection
+function getTop() {
+   return testDB.adminCommand("top").totals[testColl.getFullName()];
+}
+
+//  This variable is used to get differential output
+var lastTop = getTop();
+
+//  return the number of operations since the last call to diffTop for the specified key
+function diffTop(key) {
+    const thisTop = getTop();
+    difference = { time  : thisTop[key].time - lastTop[key].time,
+                   count : thisTop[key].count - lastTop[key].count }
+    lastTop[key] = thisTop[key];
+
+    assert.gte(difference.count, 0, "non-decreasing count");
+    assert.gte(difference.time, 0, "non-decreasing time");
+
+    //  Time should advance iff operations were performed
+    assert.eq(difference.count != 0, difference.time > 0,"non-zero time iff non-zero count");
+    return difference;
+}
+
+const numRecords = 100
+
+// check stats for specified key are as expected
+var checked = { }
+function checkStats(key, expected) {
+    checked[key]++
+    var actual = diffTop(key).count;
+    if (actual != expected) {
+        print("top reports wrong count for " + key + 
+              ": actual " + actual + " /= expected " + expected);
+    }
+}
+
+//  Insert
+for(i = 0; i < numRecords; i++) {
+    testColl.insert({_id:i});
+}
+checkStats("insert", numRecords);
+
+// Update
+for(i = 0; i < numRecords; i++) {
+    testColl.update({_id:i},{x:i});
+}
+checkStats("update", numRecords);
+
+// Queries
+var query = { }
+for(i = 0; i < numRecords; i++) {
+    query[i] = testColl.find({x : {$gte:i}}).batchSize(1);
+    assert.eq(query[i].next()._id, i);
+}
+checkStats("queries" ,numRecords);
+
+// Getmore
+for(i = 0; i < numRecords / 2; i++) {
+    assert.eq(query[i].next()._id, i + 1);
+    assert.eq(query[i].next()._id, i + 2);
+    assert.eq(query[i].next()._id, i + 3);
+    assert.eq(query[i].next()._id, i + 4);
+}
+checkStats("getmore", numRecords);
+
+// Remove 
+for(i = 0; i < numRecords; i++) {
+    testColl.remove({_id : 1});
+}
+checkStats("remove", numRecords);
+
+// Upsert, note that these are counted as updates, not inserts
+for(i = 0; i < numRecords; i++) {
+    testColl.update({_id:i},{x:i},{upsert:1});
+}
+checkStats("update", numRecords);
+
+
+// Commands
+diffTop("commands"); // ignore any commands before this
+for(i = 0; i < numRecords; i++) {
+    assert.eq(testDB.runCommand({count:"toptestcoll"}).n, numRecords);
+}
+checkStats("commands", numRecords);
+
+for(key in lastTop) {
+   if (!(key in checked)) {
+      printjson({key:key, stats:diffTop(key)});
+   }
 }
-var topResult = testDB.adminCommand("top");
-print("inserted " + inserts)
-printjson(topResult.totals[testColl.getFullName()]);
-//verify only 20 inserts took place
-assert(inserts, topResult.totals[testColl.getFullName()].insert.count);
 
-testColl.drop()

src/mongo/db/commands/write_commands/batch_executor.cpp

@@ -605,6 +605,14 @@ namespace mongo {
         currentOp->done();
         int executionTime = currentOp->debug().executionTime = currentOp->totalTimeMillis();
         currentOp->debug().recordStats();
+        if (currentOp->getOp() == dbInsert) {
+            // This is a wrapped operation, so make sure to count this part of the op
+            // SERVER-13339: Properly fix the handling of context in the insert path.
+            // Right now it caches client contexts in ExecInsertsState, unlike the
+            // update and remove operations.
+            currentOp->recordGlobalTime(txn->lockState()->isWriteLocked(),
+                                        currentOp->totalTimeMicros());
+        }
 
         if ( opError ) {
             currentOp->debug().exceptionInfo = ExceptionInfo( opError->getErrMessage(),