summaryrefslogtreecommitdiff
path: root/jstests/core/profile4.js
blob: 408af65a22512da75949a662a11d4b1915923ab7 (plain)
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
if (0) { // TODO SERVER-15614 reenable
// Check debug information recorded for a query.

// special db so that it can be run in parallel tests
var stddb = db;
var db = db.getSisterDB("profile4");

db.dropAllUsers();
t = db.profile4;
t.drop();

function profileCursor() {
    return db.system.profile.find( { user:username + "@" + db.getName() } );
}

function lastOp() {
    p = profileCursor().sort( { $natural:-1 } ).next();
//    printjson( p );
    return p;
}

function checkLastOp( spec ) {
    p = lastOp();
    for( i in spec ) {
        s = spec[ i ];
        assert.eq( s[ 1 ], p[ s[ 0 ] ], s[ 0 ] );
    }
}

try {
    username = "jstests_profile4_user";
    db.createUser({user: username, pwd: "password", roles: jsTest.basicUserRoles});
    db.auth( username, "password" );
    
    db.setProfilingLevel(0);
    
    db.system.profile.drop();
    assert.eq( 0 , profileCursor().count() )
    
    db.setProfilingLevel(2);

    t.find().itcount();
    checkLastOp( [ [ "op", "query" ],
                  [ "ns", "profile4.profile4" ],
                  [ "query", {} ],
                  [ "ntoreturn", 0 ],
                  [ "ntoskip", 0 ],
                  [ "nscanned", 0 ],
                  [ "keyUpdates", 0 ],
                  [ "nreturned", 0 ],
                  [ "responseLength", 20 ] ] );
    
    t.save( {} );

    // check write lock stats are set
    o = lastOp();
    assert.eq('insert', o.op);

    printjson( o );
    assert.eq( 0, o.lockStats.timeLockedMicros.r );
    assert.lt( 0, o.lockStats.timeLockedMicros.w );
    assert.eq( 0, o.lockStats.timeAcquiringMicros.r );
    assert.lte( 0, o.lockStats.timeAcquiringMicros.w );

    // check read lock stats are set
    t.find();
    o = lastOp();
    assert.eq('query', o.op);
    assert.lt( 0, o.lockStats.timeLockedMicros.r );
    assert.eq( 0, o.lockStats.timeLockedMicros.w );
    assert.lte( 0, o.lockStats.timeAcquiringMicros.r );
    assert.lte( 0, o.lockStats.timeAcquiringMicros.w );

    t.save( {} );
    t.save( {} );
    t.find().skip( 1 ).limit( 4 ).itcount();
    checkLastOp( [ [ "ntoreturn", 4 ],
                  [ "ntoskip", 1 ],
                  [ "nscannedObjects", 3 ],
                  [ "nreturned", 2 ] ] );

    t.find().batchSize( 2 ).next();
    o = lastOp();
    assert.lt( 0, o.cursorid );
    
    t.find( {a:1} ).itcount();
    checkLastOp( [ [ "query", {a:1} ] ] );
    
    t.find( {_id:0} ).itcount();
    checkLastOp( [ [ "idhack", true ] ] );
    
    t.find().sort( {a:1} ).itcount();
    checkLastOp( [ [ "scanAndOrder", true ] ] );
    
    t.ensureIndex( {a:1} );
    t.find( {a:1} ).itcount();
    o = lastOp();
    assert.eq( "FETCH", o.execStats.stage, tojson( o.execStats ) );
    assert.eq( "IXSCAN", o.execStats.inputStage.stage, tojson( o.execStats ) );

    // For queries with a lot of stats data, the execution stats in the profile
    // is replaced by the plan summary.
    var orClauses = 32;
    var bigOrQuery = { $or: [] };
    for ( var i = 0; i < orClauses; ++i ) {
        var indexSpec = {};
        indexSpec[ "a" + i ] = 1;
        t.ensureIndex( indexSpec );
        bigOrQuery[ "$or" ].push( indexSpec );
    }
    t.find( bigOrQuery ).itcount();
    o = lastOp();
    assert.neq( undefined, o.execStats.summary, tojson( o.execStats ) );

    db.setProfilingLevel(0);
    db.system.profile.drop();    
}
finally {
    db.setProfilingLevel(0);
    db = stddb;
}
}