SERVER-29304 Exclude time spent blocking for awaitData from getMore latency reporting.

This change applies to various server diagnostics which
include latency metrics: the slow query logs, the
system.profile collection, top, global operation latency
stats, and per-collection operation latency stats. The
secs_running and microsecs_running fields reported in
currentOp output, on the other hand, will include time spent
blocking for awaitData.

Furthermore, this change fixes the following:
 - getMore operations are no longer double-counted.
 - Lock acquisition times are now consistently included.
   This fixes a bug in which time spent acquiring locks was
   accidentally omitted in some cases.

1 files changed, 47 insertions, 0 deletions

diff --git a/jstests/noPassthroughWithMongod/getmore_awaitdata_opcounters.js b/jstests/noPassthroughWithMongod/getmore_awaitdata_opcounters.js
new file mode 100644
index 00000000000..f61f7ec5a22
--- /dev/null
+++ b/jstests/noPassthroughWithMongod/getmore_awaitdata_opcounters.js
@@ -0,0 +1,47 @@
+/**
+ * Test that opcounters are correct for getMore operations on awaitData cursors.
+ */
+(function() {
+    "use strict";
+
+    const coll = db.getmore_awaitdata_opcounters;
+    coll.drop();
+    assert.commandWorked(db.createCollection(coll.getName(), {capped: true, size: 1024}));
+    assert.writeOK(coll.insert({_id: 1}));
+    assert.writeOK(coll.insert({_id: 2}));
+    assert.writeOK(coll.insert({_id: 3}));
+
+    function getGlobalLatencyStats() {
+        return db.serverStatus().opLatencies.reads;
+    }
+
+    function getCollectionLatencyStats() {
+        return coll.latencyStats().next().latencyStats.reads;
+    }
+
+    function getTop() {
+        return db.adminCommand({top: 1}).totals[coll.getFullName()];
+    }
+
+    // Global latency histogram from serverStatus should record two read ops, one for find and one
+    // for getMore.
+    let oldGlobalLatency = getGlobalLatencyStats();
+    assert.eq(3, coll.find().tailable(true).itcount());
+    let newGlobalLatency = getGlobalLatencyStats();
+    assert.eq(2, newGlobalLatency.ops - oldGlobalLatency.ops);
+
+    // Per-collection latency histogram should record three read ops, one for find, one for getMore,
+    // and one for the aggregation command used to retrieve the stats themselves.
+    let oldCollLatency = getCollectionLatencyStats();
+    assert.eq(3, coll.find().tailable(true).itcount());
+    let newCollLatency = getCollectionLatencyStats();
+    assert.eq(3, newCollLatency.ops - oldCollLatency.ops);
+
+    // Top separates counters for getMore and find. We should see a delta of one getMore op and one
+    // find op.
+    let oldTop = getTop();
+    assert.eq(3, coll.find().tailable(true).itcount());
+    let newTop = getTop();
+    assert.eq(1, newTop.getmore.count - oldTop.getmore.count);
+    assert.eq(1, newTop.queries.count - oldTop.queries.count);
+}());