SERVER-7382 command counters

Closes #794

Signed-off-by: Benety Goh <benety@mongodb.com>

jstests/core/opcounters_write_cmd.js

@@ -2,7 +2,7 @@
 // Legacy write mode test also available at jstests/gle.
 
 var mongo = new Mongo(db.getMongo().host);
-mongo.forceWriteMode("commands");
+
 var newdb = mongo.getDB(db.toString());
 
 var t = newdb.opcounters;
@@ -10,8 +10,6 @@ var isMongos = ("isdbgrid" == newdb.runCommand("ismaster").msg);
 var opCounters;
 var res;
 
-assert(t.getDB().getMongo().useWriteCommands(), "test is not running with write commands")
-
 //
 // Count ops attempted in write commands in mongod and mongos
 //
@@ -40,25 +38,28 @@ res = t.insert([{_id:1},{_id:2}])
 assert.writeOK(res);
 assert.eq(opCounters.insert + 2, newdb.serverStatus().opcounters.insert);
 
-// Single insert, with error.
-opCounters = newdb.serverStatus().opcounters;
-res = t.insert({_id:0})
-assert.writeError(res);
-assert.eq(opCounters.insert + 1, newdb.serverStatus().opcounters.insert);
 
-// Bulk insert, with error, ordered.
-opCounters = newdb.serverStatus().opcounters;
-res = t.insert([{_id:3},{_id:3},{_id:4}])
-assert.writeError(res);
-assert.eq(opCounters.insert + 2, newdb.serverStatus().opcounters.insert);
+// Test is not run when in compatibility mode as errors are not counted
+if (t.getMongo().writeMode() != "compatibility"){
+    // Single insert, with error.
+    opCounters = newdb.serverStatus().opcounters;
+    res = t.insert({_id:0})
+    assert.writeError(res);
+    assert.eq(opCounters.insert + 1, newdb.serverStatus().opcounters.insert);
 
-// Bulk insert, with error, unordered.
-var continueOnErrorFlag = 1;
-opCounters = newdb.serverStatus().opcounters;
-res = t.insert([{_id:5},{_id:5},{_id:6}], continueOnErrorFlag)
-assert.writeError(res);
-assert.eq(opCounters.insert + 3, newdb.serverStatus().opcounters.insert);
+    // Bulk insert, with error, ordered.
+    opCounters = newdb.serverStatus().opcounters;
+    res = t.insert([{_id:3},{_id:3},{_id:4}])
+    assert.writeError(res);
+    assert.eq(opCounters.insert + 2, newdb.serverStatus().opcounters.insert);
 
+    // Bulk insert, with error, unordered.
+    var continueOnErrorFlag = 1;
+    opCounters = newdb.serverStatus().opcounters;
+    res = t.insert([{_id:5},{_id:5},{_id:6}], continueOnErrorFlag)
+    assert.writeError(res);
+    assert.eq(opCounters.insert + 3, newdb.serverStatus().opcounters.insert);
+}
 //
 // 2. Update.
 //
@@ -146,22 +147,38 @@ t.drop();
 t.insert({_id:0})
 
 // Command, recognized, no error.
-opCounters = newdb.serverStatus().opcounters;
+serverStatus = newdb.serverStatus();
+opCounters = serverStatus.opcounters
+metricsObj = serverStatus.metrics.commands
 assert.eq(opCounters.command + 1, newdb.serverStatus().opcounters.command); // "serverStatus" counted
+// Count this and the last run of "serverStatus"
+assert.eq(metricsObj.serverStatus.total + 2,
+    newdb.serverStatus().metrics.commands.serverStatus.total, 
+    "total ServerStatus command counter did not increment"); // "serverStatus" counted
+assert.eq(metricsObj.serverStatus.failed, 
+    newdb.serverStatus().metrics.commands.serverStatus.failed, 
+   "failed ServerStatus command counter incremented!"); // "serverStatus" counted
 
 // Command, recognized, with error.
-opCounters = newdb.serverStatus().opcounters;
-res = t.runCommand("count", {query:{$invalidOp:1}});
+countVal = { "total" : 0, "failed" : 0 };
+if (metricsObj.count != null) {
+    countVal = metricsObj.count
+}
+res = t.runCommand("count", {query:{$invalidOp:1}}); // "count command" counted
 assert.eq(0, res.ok);
-assert.eq(opCounters.command + 2,
+assert.eq(opCounters.command + 5,
           newdb.serverStatus().opcounters.command); // "serverStatus", "count" counted
 
-// Command, unrecognized.
-opCounters = newdb.serverStatus().opcounters;
-res = t.runCommand("command that doesn't exist");
-assert.eq(0, res.ok);
-//assert.eq(opCounters.command + 1, newdb.serverStatus().opcounters.command); // "serverStatus" counted
-// TODO Replace below with above when SERVER-9038 is resolved (mongos counts unrecognized commands)
-assert.eq(opCounters.command + (isMongos ? 2 : 1), newdb.serverStatus().opcounters.command);
+assert.eq(countVal.total +1, 
+    newdb.serverStatus().metrics.commands.count.total, 
+    "total count command counter did not incremented"); // "serverStatus", "count" counted
+assert.eq(countVal.failed + 1, 
+    newdb.serverStatus().metrics.commands.count.failed, 
+    "failed count command counter did not increment"); // "serverStatus", "count" counted
 
-// Command, recognized, counting suppressed (TODO implement when SERVER-9038 is resolved).
+// Command, unrecognized.
+res = t.runCommand("invalid"); // "invalid" command only counted on MongoS
+assert.eq(0, res.ok);
+assert.eq(opCounters.command + (isMongos ? 9 : 8), newdb.serverStatus().opcounters.command); // "serverStatus" counted
+assert.eq(null, newdb.serverStatus().metrics.commands.invalid);
+assert.eq(metricsObj['<UNKNOWN>'] + 1, newdb.serverStatus().metrics.commands['<UNKNOWN>']);

jstests/gle/opcounters_legacy.js

@@ -150,25 +150,44 @@ t.drop();
 t.insert({_id:0})
 
 // Command, recognized, no error.
-opCounters = db.serverStatus().opcounters;
+serverStatus = db.serverStatus();
+opCounters = serverStatus.opcounters
+metricsObj = serverStatus.metrics.commands
 assert.eq(opCounters.command + 1, db.serverStatus().opcounters.command); // "serverStatus" counted
+// Count this and the last run of "serverStatus"
+assert.eq( metricsObj.serverStatus.total + 2,   
+    db.serverStatus().metrics.commands.serverStatus.total,
+    "total ServerStatus command counter did not increment" )
+assert.eq( metricsObj.serverStatus.failed,
+    db.serverStatus().metrics.commands.serverStatus.failed,
+    "failed ServerStatus command counter incremented!" )
 
 // Command, recognized, with error.
-opCounters = db.serverStatus().opcounters;
+serverStatus = db.serverStatus();
+opCounters = serverStatus.opcounters
+metricsObj = serverStatus.metrics.commands
+var countVal = { "total" : 0, "failed" : 0 };
+if (metricsObj.count != null){
+    countVal = metricsObj.count
+}
 res = t.runCommand("count", {query:{$invalidOp:1}});
 assert.eq(0, res.ok);
 assert.eq(opCounters.command + 2,
           db.serverStatus().opcounters.command); // "serverStatus", "count" counted
 
+assert.eq( countVal.total +1,
+    db.serverStatus().metrics.commands.count.total,
+    "total count command counter did not incremented" )
+assert.eq( countVal.failed + 1,
+    db.serverStatus().metrics.commands.count.failed,
+    "failed count command counter did not increment" )
+
 // Command, unrecognized.
-opCounters = db.serverStatus().opcounters;
-res = t.runCommand("command that doesn't exist");
+serverStatus = db.serverStatus();
+opCounters = serverStatus.opcounters
+metricsObj = serverStatus.metrics.commands
+res = t.runCommand("invalid");
 assert.eq(0, res.ok);
-//assert.eq(opCounters.command + 1, db.serverStatus().opcounters.command); // "serverStatus" counted
-// TODO Replace below with above when SERVER-9038 is resolved (mongos counts unrecognized commands)
-assert.eq(opCounters.command + (isMongos ? 2 : 1), db.serverStatus().opcounters.command);
-
-// Command, recognized, counting suppressed (TODO implement when SERVER-9038 is resolved).
-
-// Restore 'db' var
-db = lastDB;
+assert.eq(opCounters.command + 1, db.serverStatus().opcounters.command); // "serverStatus" counted
+assert.eq(null, db.serverStatus().metrics.commands.invalid);
+assert.eq(metricsObj['<UNKNOWN>'] +1, db.serverStatus().metrics.commands['<UNKNOWN>']);

src/mongo/db/commands.cpp

@@ -62,6 +62,10 @@ namespace mongo {
 
     int Command::testCommandsEnabled = 0;
 
+    Counter64 Command::unknownCommands;
+    static ServerStatusMetricField<Counter64> displayUnknownCommands( "commands.<UNKNOWN>",
+        &Command::unknownCommands );
+
     namespace {
         ExportedServerParameter<int> testCommandsParameter(ServerParameterSet::getGlobal(),
                                                            "enableTestCommands",
@@ -176,7 +180,10 @@ namespace mongo {
         ss << "</tr>\n";
     }
 
-    Command::Command(StringData _name, bool web, StringData oldName) : name(_name.toString()) {
+    Command::Command(StringData _name, bool web, StringData oldName) :
+        name(_name.toString()),
+        _commandsExecutedMetric("commands."+ _name.toString()+".total", &_commandsExecuted),
+        _commandsFailedMetric("commands."+ _name.toString()+".failed", &_commandsFailed) {
         // register ourself.
         if ( _commands == 0 )
             _commands = new map<string,Command*>;

src/mongo/db/commands.h

@@ -32,10 +32,12 @@
 #include <string>
 #include <vector>
 
+#include "mongo/base/counter.h"
 #include "mongo/base/status.h"
 #include "mongo/db/auth/privilege.h"
 #include "mongo/db/auth/resource_pattern.h"
 #include "mongo/db/client_basic.h"
+#include "mongo/db/commands/server_status_metric.h"
 #include "mongo/db/jsobj.h"
 #include "mongo/db/query/explain.h"
 
@@ -217,6 +219,14 @@ namespace mutablebson {
         static std::map<std::string,Command*> * _commandsByBestName;
         static std::map<std::string,Command*> * _webCommands;
 
+        // Counters for how many times this command has been executed and failed
+        Counter64 _commandsExecuted;
+        Counter64 _commandsFailed;
+
+        // Pointers to hold the metrics tree references
+        ServerStatusMetricField<Counter64> _commandsExecutedMetric;
+        ServerStatusMetricField<Counter64> _commandsFailedMetric;
+
     public:
         // Stops all index builds required to run this command and returns index builds killed.
         virtual std::vector<BSONObj> stopIndexBuilds(OperationContext* opCtx,
@@ -225,6 +235,10 @@ namespace mutablebson {
 
         static const std::map<std::string,Command*>* commandsByBestName() { return _commandsByBestName; }
         static const std::map<std::string,Command*>* webCommands() { return _webCommands; }
+
+        // Counter for unknown commands
+        static Counter64 unknownCommands;
+
         /** @return if command was found */
         static void runAgainstRegistered(const char *ns,
                                          BSONObj& jsobj,

src/mongo/db/dbcommands.cpp

@@ -1378,8 +1378,14 @@ namespace mongo {
 
         txn->getCurOp()->ensureStarted();
 
+        c->_commandsExecuted.increment();
+
         retval = _execCommand(txn, c, dbname, cmdObj, queryOptions, errmsg, result, fromRepl);
 
+        if ( !retval ){
+            c->_commandsFailed.increment();
+        }
+
         appendCommandStatus(result, retval, errmsg);
         
         // For commands from mongos, append some info to help getLastError(w) work.
@@ -1458,6 +1464,7 @@ namespace mongo {
                                          str::stream() << "no such cmd: " << e.fieldName());
             anObjBuilder.append("code", ErrorCodes::CommandNotFound);
             anObjBuilder.append("bad cmd" , _cmdobj );
+            Command::unknownCommands.increment();
         }
 
         BSONObj x = anObjBuilder.done();

src/mongo/s/commands_public.cpp

@@ -2588,6 +2588,7 @@ namespace mongo {
                                          false,
                                          str::stream() << "no such cmd: " << commandName);
             anObjBuilder.append("code", ErrorCodes::CommandNotFound);
+            Command::unknownCommands.increment();
             return;
         }
         ClientInfo *client = ClientInfo::get();

src/mongo/s/s_only.cpp

@@ -137,6 +137,8 @@ namespace mongo {
             return;
         }
 
+        c->_commandsExecuted.increment();
+
         std::string errmsg;
         bool ok;
         try {
@@ -155,6 +157,10 @@ namespace mongo {
             result.append( "code" , code );
         }
 
+        if ( !ok ) {
+            c->_commandsFailed.increment();
+        }
+
         appendCommandStatus(result, ok, errmsg);
     }
 }