SERVER-14064 provide planSummary for slow count commands

2 files changed, 101 insertions, 0 deletions

diff --git a/jstests/core/count_plan_summary.js b/jstests/core/count_plan_summary.js
new file mode 100644
index 00000000000..2bf96e5e437
--- /dev/null
+++ b/jstests/core/count_plan_summary.js
@@ -0,0 +1,47 @@
+// Test that the plan summary string appears in db.currentOp() for
+// count operations. SERVER-14064.
+
+var t = db.jstests_count_plan_summary;
+t.drop();
+
+for (var i = 0; i < 1000; i++) {
+    t.insert({x: 1});
+}
+
+// Mock a long-running count operation by sleeping for each of
+// the documents in the collection.
+s = startParallelShell(
+    "db.jstests_count_plan_summary.find({x: 1, $where: 'sleep(100)'}).count()"
+);
+
+// Find the count op in db.currentOp() and check for the plan summary.
+assert.soon(function() {
+    var current = db.currentOp({ns: t.getFullName(), "query.count": t.getName()});
+
+    assert("inprog" in current);
+    if (current.inprog.length === 0) {
+        print("Did not find count op. db.currentOp() output:");
+        printjson(current);
+        return false;
+    }
+
+    // There are no indices, so the plan summary should be a collscan.
+    var countOp = current.inprog[0];
+    if (!("planSummary" in countOp)) {
+        print("count op does not yet contain planSummary:");
+        printjson(countOp);
+        return false;
+    }
+
+    // There are no indices, so the planSummary should be "COLLSCAN".
+    print("Found count op with planSummary:");
+    printjson(countOp);
+    assert.eq("COLLSCAN", countOp.planSummary, "wrong planSummary string");
+
+    // Kill the op so that the test won't run for a long time.
+    db.killOp(countOp.opid);
+
+    return true;
+});
+
+s();
diff --git a/src/mongo/db/ops/count.cpp b/src/mongo/db/ops/count.cpp
index e4ffb974625..e07b81c6811 100644
--- a/src/mongo/db/ops/count.cpp
+++ b/src/mongo/db/ops/count.cpp
@@ -34,7 +34,35 @@
 #include "mongo/db/clientcursor.h"
 #include "mongo/db/catalog/database.h"
 #include "mongo/db/catalog/collection.h"
+#include "mongo/db/curop.h"
 #include "mongo/db/query/get_runner.h"
+#include "mongo/db/query/type_explain.h"
+
+namespace {
+
+    using namespace mongo;
+
+    /**
+     * Ask 'runner' for a summary of the plan it is using to run the count command,
+     * and store this information in 'currentOp'.
+     *
+     * Returns true if the planSummary was copied to 'currentOp' and false otherwise.
+     */
+    bool setPlanSummary(Runner* runner, CurOp* currentOp) {
+        if (NULL != currentOp) {
+            PlanInfo* rawInfo;
+            Status s = runner->getInfo(NULL, &rawInfo);
+            if (s.isOK()) {
+                scoped_ptr<PlanInfo> planInfo(rawInfo);
+                currentOp->debug().planSummary = planInfo->planSummary.c_str();
+                return true;
+            }
+        }
+
+        return false;
+    }
+
+} // namespace
 
 namespace mongo {
 
@@ -94,6 +122,19 @@ namespace mongo {
         uassertStatusOK(getRunnerCount(collection, query, hintObj, &rawRunner));
         auto_ptr<Runner> runner(rawRunner);
 
+        // Get a pointer to the current operation. We will try to copy the planSummary
+        // there so that it appears in db.currentOp() and the slow query log.
+        Client& client = cc();
+        CurOp* currentOp = client.curop();
+
+        // Have we copied the planSummary to 'currentOp' yet?
+        bool gotPlanSummary = false;
+
+        // Try to copy the plan summary to the 'currentOp'.
+        if (!gotPlanSummary) {
+            gotPlanSummary = setPlanSummary(runner.get(), currentOp);
+        }
+
         try {
             const ScopedRunnerRegistration safety(runner.get());
             runner->setYieldPolicy(Runner::YIELD_AUTO);
@@ -101,6 +142,13 @@ namespace mongo {
             long long count = 0;
             Runner::RunnerState state;
             while (Runner::RUNNER_ADVANCED == (state = runner->getNext(NULL, NULL))) {
+                // Try to copy the plan summary to the 'currentOp'. We need to try again
+                // here because we might not have chosen a plan until after the first
+                // call to getNext(...).
+                if (!gotPlanSummary) {
+                    gotPlanSummary = setPlanSummary(runner.get(), currentOp);
+                }
+
                 if (skip > 0) {
                     --skip;
                 }
@@ -114,6 +162,12 @@ namespace mongo {
                 }
             }
 
+            // Try to copy the plan summary to the 'currentOp', if we haven't already. This
+            // could happen if, for example, the count is 0.
+            if (!gotPlanSummary) {
+                gotPlanSummary = setPlanSummary(runner.get(), currentOp);
+            }
+
             // Emulate old behavior and return the count even if the runner was killed.  This
             // happens when the underlying collection is dropped.
             return count;