1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157
|
// This test is inherently a race between the client and the server, and the test is unreliable.
// We compare the duration of a query as seen by the server with the duration as seen by the
// client, and if the client is delayed by a few milliseconds, or, in extreme cases, by even
// 1 millisecond, it may think that there is a problem when in fact it's just a race, and the
// client lost the race.
// Windows seems to experience this more than the other platforms, so, to "fix" SERVER-5373,
// disable the test for Windows.
if (!_isWindows()) {
print("profile1.js BEGIN");
// special db so that it can be run in parallel tests
var stddb = db;
var db = db.getSisterDB("profile1");
try {
username = "jstests_profile1_user";
db.addUser( username, "password", false, 1 );
db.auth( username, "password" );
function profileCursor( query ) {
query = query || {};
Object.extend( query, { user:username + "@" + db.getName() } );
return db.system.profile.find( query );
}
function getProfileAString() {
var s = "\n";
profileCursor().forEach( function(z){
s += tojson( z ) + " ,\n" ;
} );
return s;
}
/* With pre-created system.profile (capped) */
db.runCommand({profile: 0});
db.getCollection("system.profile").drop();
assert(!db.getLastError(), "Z");
assert.eq(0, db.runCommand({profile: -1}).was, "A");
db.createCollection("system.profile", {capped: true, size: 10000});
db.runCommand({profile: 2});
assert.eq(2, db.runCommand({profile: -1}).was, "B");
assert.eq(1, db.system.profile.stats().capped, "C");
var capped_size = db.system.profile.storageSize();
assert.gt(capped_size, 9999, "D");
assert.lt(capped_size, 20000, "E");
db.foo.findOne()
assert.eq( 4 , profileCursor().count() , "E2" );
/* Make sure we can't drop if profiling is still on */
assert.throws( function(z){ db.getCollection("system.profile").drop(); } )
/* With pre-created system.profile (un-capped) */
db.runCommand({profile: 0});
db.getCollection("system.profile").drop();
assert.eq(0, db.runCommand({profile: -1}).was, "F");
db.createCollection("system.profile");
assert.eq( 0, db.runCommand({profile: 2}).ok );
assert.eq( 0, db.runCommand({profile: -1}).was, "G");
assert.eq(null, db.system.profile.stats().capped, "G1");
/* With no system.profile collection */
db.runCommand({profile: 0});
db.getCollection("system.profile").drop();
assert.eq(0, db.runCommand({profile: -1}).was, "H");
db.runCommand({profile: 2});
assert.eq(2, db.runCommand({profile: -1}).was, "I");
assert.eq(1, db.system.profile.stats().capped, "J");
var auto_size = db.system.profile.storageSize();
assert.gt(auto_size, capped_size, "K");
db.eval("sleep(1)") // pre-load system.js
function resetProfile( level , slowms ) {
db.setProfilingLevel(0);
db.system.profile.drop();
db.setProfilingLevel(level,slowms);
}
resetProfile(2);
db.eval( "sleep(25)" )
db.eval( "sleep(120)" )
assert.eq( 2 , profileCursor( { "command.$eval" : /^sleep/ } ).count() );
assert.lte( 119 , profileCursor( { "command.$eval" : "sleep(120)" } )[0].millis );
assert.lte( 24 , profileCursor( { "command.$eval" : "sleep(25)" } )[0].millis );
/* sleep() could be inaccurate on certain platforms. let's check */
print("\nsleep 2 time actual:");
for (var i = 0; i < 4; i++) {
print(db.eval("var x = new Date(); sleep(2); return new Date() - x;"));
}
print();
print("\nsleep 20 times actual:");
for (var i = 0; i < 4; i++) {
print(db.eval("var x = new Date(); sleep(20); return new Date() - x;"));
}
print();
print("\nsleep 120 times actual:");
for (var i = 0; i < 4; i++) {
print(db.eval("var x = new Date(); sleep(120); return new Date() - x;"));
}
print();
function evalSleepMoreThan(millis,max){
var start = new Date();
db.eval("sleep("+millis+")");
var end = new Date();
var actual = end.getTime() - start.getTime();
if ( actual > ( millis + 5 ) ) {
print( "warning wanted to sleep for: " + millis + " but took: " + actual );
}
return actual >= max ? 1 : 0;
}
resetProfile(1,100);
var delta = 0;
delta += evalSleepMoreThan( 15 , 100 );
delta += evalSleepMoreThan( 120 , 100 );
assert.eq( delta , profileCursor( { "command.$eval" : /^sleep/ } ).count() , "X2 : " + getProfileAString() )
resetProfile(1,20);
delta = 0;
delta += evalSleepMoreThan( 5 , 20 );
delta += evalSleepMoreThan( 120 , 20 );
assert.eq( delta , profileCursor( { "command.$eval" : /^sleep/ } ).count() , "X3 : " + getProfileAString() )
resetProfile(2);
db.profile1.drop();
var q = { _id : 5 };
var u = { $inc : { x : 1 } };
db.profile1.update( q , u );
var r = profileCursor( { ns : db.profile1.getFullName() } ).sort( { $natural : -1 } )[0]
assert.eq( q , r.query , "Y1: " + tojson(r) );
assert.eq( u , r.updateobj , "Y2" );
assert.eq( "update" , r.op , "Y3" );
assert.eq("profile1.profile1", r.ns, "Y4");
print("profile1.js SUCCESS OK");
} finally {
// disable profiling for subsequent tests
assert.commandWorked( db.runCommand( {profile:0} ) );
db = stddb;
}
} // !_isWindows()
|