summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
Diffstat
-rw-r--r--buildscripts/resmokeconfig/suites/read_concern_linearizable_passthrough.yml7
-rw-r--r--buildscripts/resmokeconfig/suites/read_concern_majority_passthrough.yml7
-rw-r--r--jstests/auth/lib/commands_lib.js20
-rw-r--r--jstests/core/profile_sampling.js51
-rw-r--r--jstests/libs/parallelTester.js1
-rw-r--r--src/mongo/bson/util/bson_extract.cpp12
-rw-r--r--src/mongo/bson/util/bson_extract.h15
-rw-r--r--src/mongo/db/assemble_response.cpp8
-rw-r--r--src/mongo/db/commands/dbcommands.cpp13
-rw-r--r--src/mongo/db/mongod_options.cpp11
-rw-r--r--src/mongo/db/ops/write_ops_exec.cpp8
-rw-r--r--src/mongo/db/server_options.h1
-rw-r--r--src/mongo/shell/db.js38
13 files changed, 165 insertions, 27 deletions
diff --git a/buildscripts/resmokeconfig/suites/read_concern_linearizable_passthrough.yml b/buildscripts/resmokeconfig/suites/read_concern_linearizable_passthrough.yml
index c62a50a6d01..075ee977257 100644
--- a/buildscripts/resmokeconfig/suites/read_concern_linearizable_passthrough.yml
+++ b/buildscripts/resmokeconfig/suites/read_concern_linearizable_passthrough.yml
@@ -41,6 +41,9 @@ selector:
- jstests/core/mr_outreduce2.js # mr temp tables aren't replicated
- jstests/core/opcounters_active.js # off by n problem with opcounters
- jstests/core/opcounters_write_cmd.js # off by n problem with opcounters
+ - jstests/core/profile1.js # system.profile not replicated
+ - jstests/core/profile2.js # system.profile not replicated
+ - jstests/core/profile3.js # system.profile not replicated
- jstests/core/profile_agg.js # system.profile not replicated
- jstests/core/profile_count.js # system.profile not replicated
- jstests/core/profile_delete.js # system.profile not replicated
@@ -52,10 +55,8 @@ selector:
- jstests/core/profile_group.js # system.profile not replicated
- jstests/core/profile_insert.js # system.profile not replicated
- jstests/core/profile_mapreduce.js # system.profile not replicated
+ - jstests/core/profile_sampling.js # system.profile not replicated
- jstests/core/profile_update.js # system.profile not replicated
- - jstests/core/profile1.js # system.profile not replicated
- - jstests/core/profile2.js # system.profile not replicated
- - jstests/core/profile3.js # system.profile not replicated
- jstests/core/read_after_optime.js # verifies read after optime fails on standalone
- jstests/core/remove8.js # db.eval() used
- jstests/core/rename4.js # db.eval() used
diff --git a/buildscripts/resmokeconfig/suites/read_concern_majority_passthrough.yml b/buildscripts/resmokeconfig/suites/read_concern_majority_passthrough.yml
index f9950016db7..4012e322e8f 100644
--- a/buildscripts/resmokeconfig/suites/read_concern_majority_passthrough.yml
+++ b/buildscripts/resmokeconfig/suites/read_concern_majority_passthrough.yml
@@ -38,6 +38,9 @@ selector:
- jstests/core/mr_outreduce2.js # mr temp tables aren't replicated
- jstests/core/opcounters_active.js # off by n problem with opcounters
- jstests/core/opcounters_write_cmd.js # off by n problem with opcounters
+ - jstests/core/profile1.js # system.profile not replicated
+ - jstests/core/profile2.js # system.profile not replicated
+ - jstests/core/profile3.js # system.profile not replicated
- jstests/core/profile_agg.js # system.profile not replicated
- jstests/core/profile_count.js # system.profile not replicated
- jstests/core/profile_delete.js # system.profile not replicated
@@ -49,10 +52,8 @@ selector:
- jstests/core/profile_group.js # system.profile not replicated
- jstests/core/profile_insert.js # system.profile not replicated
- jstests/core/profile_mapreduce.js # system.profile not replicated
+ - jstests/core/profile_sampling.js # system.profile not replicated
- jstests/core/profile_update.js # system.profile not replicated
- - jstests/core/profile1.js # system.profile not replicated
- - jstests/core/profile2.js # system.profile not replicated
- - jstests/core/profile3.js # system.profile not replicated
- jstests/core/read_after_optime.js # verifies read after optime fails on standalone
- jstests/core/remove8.js # db.eval() used
- jstests/core/rename4.js # db.eval() used
diff --git a/jstests/auth/lib/commands_lib.js b/jstests/auth/lib/commands_lib.js
index 3cbf3dfcc9b..29b6eb4a669 100644
--- a/jstests/auth/lib/commands_lib.js
+++ b/jstests/auth/lib/commands_lib.js
@@ -3586,6 +3586,26 @@ var authCommandsLib = {
]
},
{
+ testname: "profileSetSampleRate",
+ command: {profile: -1, sampleRate: 0.5},
+ skipSharded: true,
+ testcases: [
+ {
+ runOnDb: firstDbName,
+ roles: roles_dbAdmin,
+ privileges:
+ [{resource: {db: firstDbName, collection: ""}, actions: ["enableProfiler"]}]
+ },
+ {
+ runOnDb: secondDbName,
+ roles: roles_dbAdminAny,
+ privileges: [
+ {resource: {db: secondDbName, collection: ""}, actions: ["enableProfiler"]}
+ ]
+ }
+ ]
+ },
+ {
testname: "renameCollection_sameDb",
command: {renameCollection: firstDbName + ".x", to: firstDbName + ".y", dropTarget: true},
setup: function(db) {
diff --git a/jstests/core/profile_sampling.js b/jstests/core/profile_sampling.js
new file mode 100644
index 00000000000..6ad60060845
--- /dev/null
+++ b/jstests/core/profile_sampling.js
@@ -0,0 +1,51 @@
+// Confirms that the number of profiled operations is consistent with the sampleRate, if set.
+(function() {
+ "use strict";
+
+ // Use a special db to support running other tests in parallel.
+ var profileDB = db.getSisterDB("profile_sampling");
+ var coll = profileDB.profile_sampling;
+
+ profileDB.dropDatabase();
+
+ var originalProfilingSettings;
+ try {
+ originalProfilingSettings = assert.commandWorked(profileDB.setProfilingLevel(0));
+ profileDB.system.profile.drop();
+ assert.eq(0, profileDB.system.profile.count());
+
+ profileDB.createCollection(coll.getName());
+ assert.writeOK(coll.insert({x: 1}));
+
+ assert.commandWorked(profileDB.setProfilingLevel(2, {sampleRate: 0}));
+
+ assert.neq(null, coll.findOne({x: 1}));
+ assert.eq(1, coll.find({x: 1}).count());
+ assert.writeOK(coll.update({x: 1}, {$inc: {a: 1}}));
+
+ profileDB.setProfilingLevel(0);
+
+ profileDB.system.profile.find().forEach(printjson);
+ assert.eq(0, profileDB.system.profile.count());
+
+ profileDB.system.profile.drop();
+ assert.commandWorked(profileDB.setProfilingLevel(2, {sampleRate: 0.5}));
+
+ // This should generate about 500 profile log entries.
+ for (var i = 0; i < 500; i++) {
+ assert.neq(null, coll.findOne({x: 1}));
+ assert.writeOK(coll.update({x: 1}, {$inc: {a: 1}}));
+ }
+
+ profileDB.setProfilingLevel(0);
+
+ assert.between(10, profileDB.system.profile.count(), 990);
+ } finally {
+ let profileCmd = {};
+ profileCmd.profile = originalProfilingSettings.was;
+ profileCmd = Object.extend(profileCmd, originalProfilingSettings);
+ delete profileCmd.was;
+ delete profileCmd.ok;
+ assert.commandWorked(profileDB.runCommand(profileCmd));
+ }
+}());
diff --git a/jstests/libs/parallelTester.js b/jstests/libs/parallelTester.js
index 21d44b3f813..418b06b5d12 100644
--- a/jstests/libs/parallelTester.js
+++ b/jstests/libs/parallelTester.js
@@ -247,6 +247,7 @@ if (typeof _threadInject != "undefined") {
parallelFilesDir + "/profile_insert.js",
parallelFilesDir + "/profile_mapreduce.js",
parallelFilesDir + "/profile_no_such_db.js",
+ parallelFilesDir + "/profile_sampling.js",
parallelFilesDir + "/profile_update.js"
];
var serialTests = makeKeys(serialTestsArr);
diff --git a/src/mongo/bson/util/bson_extract.cpp b/src/mongo/bson/util/bson_extract.cpp
index 84c9cc92de6..8a453c02472 100644
--- a/src/mongo/bson/util/bson_extract.cpp
+++ b/src/mongo/bson/util/bson_extract.cpp
@@ -185,6 +185,18 @@ Status bsonExtractDoubleField(const BSONObj& object, StringData fieldName, doubl
return Status::OK();
}
+Status bsonExtractDoubleFieldWithDefault(const BSONObj& object,
+ StringData fieldName,
+ double defaultValue,
+ double* out) {
+ Status status = bsonExtractDoubleField(object, fieldName, out);
+ if (status == ErrorCodes::NoSuchKey) {
+ *out = defaultValue;
+ status = Status::OK();
+ }
+ return status;
+}
+
Status bsonExtractIntegerFieldWithDefault(const BSONObj& object,
StringData fieldName,
long long defaultValue,
diff --git a/src/mongo/bson/util/bson_extract.h b/src/mongo/bson/util/bson_extract.h
index cedc84cd01f..a4e2b90d82d 100644
--- a/src/mongo/bson/util/bson_extract.h
+++ b/src/mongo/bson/util/bson_extract.h
@@ -158,6 +158,21 @@ Status bsonExtractIntegerFieldWithDefault(const BSONObj& object,
long long* out);
/**
+ * Finds a double-precision floating point element named "fieldName" in "object".
+ *
+ * If a field named "fieldName" is present, and is a double, stores the value of the field into
+ * "*out". If no field named fieldName is present, sets "*out" to "defaultValue". In these cases,
+ * returns Status::OK().
+ *
+ * If "fieldName" is present more than once, behavior is undefined. If the found field is not a
+ * double, returns ErrorCodes::TypeMismatch.
+ */
+Status bsonExtractDoubleFieldWithDefault(const BSONObj& object,
+ StringData fieldName,
+ double defaultValue,
+ double* out);
+
+/**
* Finds a std::string element named "fieldName" in "object".
*
* If a field named "fieldName" is present, and is a string, stores the value of the field into
diff --git a/src/mongo/db/assemble_response.cpp b/src/mongo/db/assemble_response.cpp
index c2da985db30..6e14055aeed 100644
--- a/src/mongo/db/assemble_response.cpp
+++ b/src/mongo/db/assemble_response.cpp
@@ -628,13 +628,17 @@ void assembleResponse(OperationContext* txn,
.incrementGlobalLatencyStats(
txn, currentOp.totalTimeMicros(), currentOp.getReadWriteType());
- if (shouldLogOpDebug || debug.executionTimeMicros > logThresholdMs * 1000LL) {
+ const bool shouldSample = serverGlobalParams.sampleRate == 1.0
+ ? true
+ : c.getPrng().nextCanonicalDouble() < serverGlobalParams.sampleRate;
+
+ if (shouldLogOpDebug || (shouldSample && debug.executionTimeMicros > logThresholdMs * 1000LL)) {
Locker::LockerInfo lockerInfo;
txn->lockState()->getLockerInfo(&lockerInfo);
log() << debug.report(&c, currentOp, lockerInfo.stats);
}
- if (currentOp.shouldDBProfile()) {
+ if (shouldSample && currentOp.shouldDBProfile()) {
// Performance profiling is on
if (txn->lockState()->isReadLocked()) {
LOG(1) << "note: not profiling because recursive read lock";
diff --git a/src/mongo/db/commands/dbcommands.cpp b/src/mongo/db/commands/dbcommands.cpp
index 7b5714b95e0..b9e0fd07669 100644
--- a/src/mongo/db/commands/dbcommands.cpp
+++ b/src/mongo/db/commands/dbcommands.cpp
@@ -38,6 +38,7 @@
#include "mongo/base/status.h"
#include "mongo/base/status_with.h"
#include "mongo/bson/simple_bsonobj_comparator.h"
+#include "mongo/bson/util/bson_extract.h"
#include "mongo/bson/util/builder.h"
#include "mongo/db/audit.h"
#include "mongo/db/auth/action_set.h"
@@ -349,7 +350,8 @@ public:
const BSONObj& cmdObj) {
AuthorizationSession* authzSession = AuthorizationSession::get(client);
- if (cmdObj.firstElement().numberInt() == -1 && !cmdObj.hasField("slowms")) {
+ if (cmdObj.firstElement().numberInt() == -1 && !cmdObj.hasField("slowms") &&
+ !cmdObj.hasField("sampleRate")) {
// If you just want to get the current profiling level you can do so with just
// read access to system.profile, even if you can't change the profiling level.
if (authzSession->isAuthorizedForActionsOnResource(
@@ -393,6 +395,7 @@ public:
result.append("was", db ? db->getProfilingLevel() : serverGlobalParams.defaultProfile);
result.append("slowms", serverGlobalParams.slowMS);
+ result.append("sampleRate", serverGlobalParams.sampleRate);
if (!readOnly) {
if (!db) {
@@ -408,6 +411,14 @@ public:
serverGlobalParams.slowMS = slow.numberInt();
}
+ double newSampleRate;
+ uassertStatusOK(bsonExtractDoubleFieldWithDefault(
+ cmdObj, "sampleRate"_sd, serverGlobalParams.sampleRate, &newSampleRate));
+ uassert(ErrorCodes::BadValue,
+ "sampleRate must be between 0.0 and 1.0 inclusive",
+ newSampleRate >= 0.0 && newSampleRate <= 1.0);
+ serverGlobalParams.sampleRate = newSampleRate;
+
if (!status.isOK()) {
errmsg = status.reason();
}
diff --git a/src/mongo/db/mongod_options.cpp b/src/mongo/db/mongod_options.cpp
index 921de16e082..3824340a934 100644
--- a/src/mongo/db/mongod_options.cpp
+++ b/src/mongo/db/mongod_options.cpp
@@ -146,6 +146,13 @@ Status addMongodOptions(moe::OptionSection* options) {
"value of slow for profile and console log")
.setDefault(moe::Value(100));
+ general_options
+ .addOptionChaining("operationProfiling.slowOpSampleRate",
+ "slowOpSampleRate",
+ moe::Double,
+ "fraction of slow ops to include in the profile and console log")
+ .setDefault(moe::Value(1.0));
+
general_options.addOptionChaining("profile", "profile", moe::Int, "0=off 1=slow, 2=all")
.setSources(moe::SourceAllLegacy);
@@ -1044,6 +1051,10 @@ Status storeMongodOptions(const moe::Environment& params) {
serverGlobalParams.slowMS = params["operationProfiling.slowOpThresholdMs"].as<int>();
}
+ if (params.count("operationProfiling.slowOpSampleRate")) {
+ serverGlobalParams.sampleRate = params["operationProfiling.slowOpSampleRate"].as<double>();
+ }
+
if (params.count("storage.syncPeriodSecs")) {
storageGlobalParams.syncdelay = params["storage.syncPeriodSecs"].as<double>();
if (storageGlobalParams.syncdelay < 0 ||
diff --git a/src/mongo/db/ops/write_ops_exec.cpp b/src/mongo/db/ops/write_ops_exec.cpp
index 347d8d1d486..c3e36232801 100644
--- a/src/mongo/db/ops/write_ops_exec.cpp
+++ b/src/mongo/db/ops/write_ops_exec.cpp
@@ -109,13 +109,17 @@ void finishCurOp(OperationContext* txn, CurOp* curOp) {
const bool logSlow = executionTimeMicros >
(serverGlobalParams.slowMS + curOp->getExpectedLatencyMs()) * 1000LL;
- if (logAll || logSlow) {
+ const bool shouldSample = serverGlobalParams.sampleRate == 1.0
+ ? true
+ : txn->getClient()->getPrng().nextCanonicalDouble() < serverGlobalParams.sampleRate;
+
+ if (logAll || (shouldSample && logSlow)) {
Locker::LockerInfo lockerInfo;
txn->lockState()->getLockerInfo(&lockerInfo);
log() << curOp->debug().report(txn->getClient(), *curOp, lockerInfo.stats);
}
- if (curOp->shouldDBProfile()) {
+ if (shouldSample && curOp->shouldDBProfile()) {
profile(txn, CurOp::get(txn)->getNetworkOp());
}
} catch (const DBException& ex) {
diff --git a/src/mongo/db/server_options.h b/src/mongo/db/server_options.h
index 13dc2705150..95bd873740c 100644
--- a/src/mongo/db/server_options.h
+++ b/src/mongo/db/server_options.h
@@ -65,6 +65,7 @@ struct ServerGlobalParams {
int defaultProfile = 0; // --profile
int slowMS = 100; // --time in ms that is "slow"
+ double sampleRate = 1.0; // --samplerate rate at which to sample slow queries
int defaultLocalThresholdMillis = 15; // --localThreshold in ms to consider a node local
bool moveParanoia = false; // for move chunk paranoia
diff --git a/src/mongo/shell/db.js b/src/mongo/shell/db.js
index be8c7321bf2..583ef4d33e9 100644
--- a/src/mongo/shell/db.js
+++ b/src/mongo/shell/db.js
@@ -509,7 +509,7 @@ var DB;
"\tdb.runCommand(cmdObj) run a database command. if cmdObj is a string, turns it into { cmdObj : 1 }");
print("\tdb.serverStatus()");
print("\tdb.setLogLevel(level,<component>)");
- print("\tdb.setProfilingLevel(level,<slowms>) 0=off 1=slow 2=all");
+ print("\tdb.setProfilingLevel(level,slowms) 0=off 1=slow 2=all");
print(
"\tdb.setWriteConcern( <write concern doc> ) - sets the write concern for writes to the db");
print(
@@ -546,22 +546,25 @@ var DB;
};
/**
- * <p> Set profiling level for your db. Profiling gathers stats on query performance. </p>
+ * Configures settings for capturing operations inside the system.profile collection and in the
+ * slow query log.
*
- * <p>Default is off, and resets to off on a database restart -- so if you want it on,
- * turn it on periodically. </p>
+ * The 'level' can be 0, 1, or 2:
+ * - 0 means that profiling is off and nothing will be written to system.profile.
+ * - 1 means that profiling is on for operations slower than the currently configured 'slowms'
+ * threshold (more on 'slowms' below).
+ * - 2 means that profiling is on for all operations, regardless of whether or not they are
+ * slower than 'slowms'.
*
- * <p>Levels :</p>
- * <ul>
- * <li>0=off</li>
- * <li>1=log very slow operations; optional argument slowms specifies slowness threshold</li>
- * <li>2=log all</li>
- * @param {String} level Desired level of profiling
- * @param {String} slowms For slow logging, query duration that counts as slow (default 100ms)
- * @return SOMETHING_FIXME or null on error
+ * The 'options' parameter, if a number, is interpreted as the 'slowms' value to send to the
+ * server. 'slowms' determines the threshold, in milliseconds, above which slow operations get
+ * profiled at profiling level 1 or logged at logLevel 0.
+ *
+ * If 'options' is not a number, it is expected to be an object containing additional parameters
+ * to get passed to the server. For example, db.setProfilingLevel(2, {foo: "bar"}) will issue
+ * the command {profile: 2, foo: "bar"} to the server.
*/
- DB.prototype.setProfilingLevel = function(level, slowms) {
-
+ DB.prototype.setProfilingLevel = function(level, options) {
if (level < 0 || level > 2) {
var errorText = "input level " + level + " is out of range [0..2]";
var errorObject = new Error(errorText);
@@ -570,8 +573,11 @@ var DB;
}
var cmd = {profile: level};
- if (isNumber(slowms))
- cmd["slowms"] = slowms;
+ if (isNumber(options)) {
+ cmd.slowms = options;
+ } else {
+ cmd = Object.extend(cmd, options);
+ }
return assert.commandWorked(this._dbCommand(cmd));
};
View Lorry Controller Status