Certain commands are never captured in system profiler

XMLWordPrintableJSON

    • Type: Bug
    • Resolution: Unresolved
    • Priority: Minor - P4
    • None
    • Affects Version/s: None
    • Component/s: Diagnostics
    • Query Optimization
    • ALL
    • None
    • 3
    • None
    • None
    • None
    • None
    • None
    • None
    • None

      Certain commands are never captured in the system profiler, regardless of the value of the global profiling level (as set by the --profile command line option) or the database profiling level (as set by the profile command).

      Reproduce with following script, which runs a number of commands and then scrapes system.profile to determine which were profiled. 

      // Set up test.
assert.commandWorked(db.createCollection("foo"));

// Run commands on "test" database.
assert.commandWorked(db.runCommand({createIndexes: "foo", indexes: [{key: {a: 1}, name: "foo"}]}));
assert.commandWorked(db.runCommand("dbhash"));
assert.commandWorked(db.runCommand("listCollections"));
assert.commandWorked(db.runCommand({validate: "foo"}));

// Run commands on "admin" database.
assert.commandWorked(db.adminCommand({applyOps: []}));
assert.commandWorked(db.adminCommand("buildInfo"));
assert.commandWorked(db.adminCommand("connPoolStats"));
assert.commandWorked(db.adminCommand("currentOp"));
assert.commandWorked(db.adminCommand("features"));
assert.commandWorked(db.adminCommand("fsync"));
assert.commandWorked(db.adminCommand("getLastError"));
assert.commandWorked(db.adminCommand({getLog: "global"}));
assert.commandWorked(db.adminCommand({getParameter: "*"}));
assert.commandWorked(db.adminCommand("isMaster"));
assert.commandWorked(db.adminCommand("listCommands"));
assert.commandWorked(db.adminCommand("listDatabases"));
assert.commandWorked(db.adminCommand("logout"));
assert.commandWorked(db.adminCommand("ping"));
assert.commandWorked(db.adminCommand({profile: -1}));
assert.commandWorked(db.adminCommand("serverStatus"));
assert.commandWorked(db.adminCommand("top"));
assert.commandWorked(db.adminCommand("usersInfo"));
assert.commandWorked(db.adminCommand("whatsmyuri"));

// Scrape 'test.system.profile' and 'admin.system.profile' and output list of commands that were profiled.
var profileQuery = {command: {$exists: true}};
var profileEntries = [];
profileEntries = profileEntries.concat(db.system.profile.find(profileQuery).toArray());
profileEntries =
    profileEntries.concat(db.getSiblingDB("admin").system.profile.find(profileQuery).toArray());
profiledCommands = {};
for (var i = 0; i < profileEntries.length; i++) {
    for (elt in profileEntries[i].command) {
        profiledCommands[elt] = 1;
        break;
    }
}
for (command in profiledCommands) {
    print(command);
}

      See the following shell session, which runs the above script against a 3.2.0 mongod instance started with --profile 2 (which enables profiling for all operations). No commands run by the script are profiled (with the exception of the create command used in the test setup).

      rassi@rassi:~/work/mongo$ mongo --quiet repro.js
create
rassi@rassi:~/work/mongo$

      Many commands have been affected by this issue since they were first introduced, though some have regressed over time. The following is a partial list of the regressions introduced over the past few major releases:

      • As of 2.3.1, top is no longer profiled.
      • As of 2.7.0, serverStatus, applyOps are no longer profiled.
      • As of 2.7.5, listCollections is no longer profiled.
      • As of 2.7.8, dbhash, listDatabases, getParameter are no longer profiled.
      • As of 2.8.0-rc0, createIndexes is no longer profiled.
      • As of 3.1.0, validate is no longer profiled.
      • As of 3.1.9, profile is no longer profiled.

            Assignee:
            [DO NOT USE] Backlog - Query Optimization
            Reporter:
            J Rassi (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

              Created:
              Updated: