|
*******************************************
|
Test : jstests/profile1.js ...
|
profile1.js BEGIN
|
{
|
"user" : "jstests_profile1_user",
|
"readOnly" : false,
|
"pwd" : "2a6e511239a4e136518316c33d5473db",
|
"_id" : ObjectId("512c06ad0fac5674fd477086")
|
}
|
m30200| Mon Feb 25 19:49:49.493 [FileAllocator] allocating new datafile /data/db/dur_passthrough/profile1.ns, filling with zeroes...
|
m30200| Mon Feb 25 19:49:49.522 [FileAllocator] done allocating datafile /data/db/dur_passthrough/profile1.ns, size: 16MB, took 0.028 secs
|
m30200| Mon Feb 25 19:49:49.522 [FileAllocator] allocating new datafile /data/db/dur_passthrough/profile1.0, filling with zeroes...
|
m30200| Mon Feb 25 19:49:49.556 [FileAllocator] done allocating datafile /data/db/dur_passthrough/profile1.0, size: 16MB, took 0.033 secs
|
m30200| Mon Feb 25 19:49:49.558 [conn1] build index profile1.system.users { _id: 1 }
|
m30200| Mon Feb 25 19:49:49.559 [conn1] build index done. scanned 0 total records. 0 secs
|
m30200| Mon Feb 25 19:49:49.559 [conn1] build index profile1.system.users { user: 1, userSource: 1 }
|
m30200| Mon Feb 25 19:49:49.560 [conn1] build index done. scanned 0 total records. 0 secs
|
m30200| Mon Feb 25 19:49:49.561 [FileAllocator] allocating new datafile /data/db/dur_passthrough/profile1.1, filling with zeroes...
|
m30200| Mon Feb 25 19:49:49.586 [conn1] authenticate db: profile1 { authenticate: 1, nonce: "df944c3145756283", user: "jstests_profile1_user", key: "1ce9e5f43468a73ee87f1b705b18cc31" }
|
m30200| Mon Feb 25 19:49:49.588 [conn1] CMD: drop profile1.system.profile
|
m30200| Mon Feb 25 19:49:49.623 [conn1] CMD: drop profile1.system.profile
|
m30200| Mon Feb 25 19:49:49.624 [FileAllocator] done allocating datafile /data/db/dur_passthrough/profile1.1, size: 32MB, took 0.062 secs
|
m30200| Mon Feb 25 19:49:49.624 [conn1] CMD: drop profile1.system.profile
|
m30200| Mon Feb 25 19:49:49.625 [conn1] profile1.system.profile exists but isn't capped
|
m30200| Mon Feb 25 19:49:49.626 [conn1] CMD: drop profile1.system.profile
|
m30200| Mon Feb 25 19:49:49.627 [conn1] creating profile collection: profile1.system.profile
|
m30200| Mon Feb 25 19:49:49.662 [conn1] CMD: drop profile1.system.profile
|
m30200| Mon Feb 25 19:49:49.663 [conn1] creating profile collection: profile1.system.profile
|
m30200| Mon Feb 25 19:49:49.813 [conn1] dbeval slow, time: 123ms profile1
|
m30200| Mon Feb 25 19:49:49.813 [conn1] command profile1.$cmd command: { $eval: "sleep(120)" } ntoreturn:1 keyUpdates:0 locks(micros) W:123663 reslen:45 123ms
|
|
sleep 2 time actual:
|
3
|
3
|
4
|
4
|
|
|
sleep 20 times actual:
|
24
|
24
|
24
|
24
|
|
|
sleep 120 times actual:
|
m30200| Mon Feb 25 19:49:50.053 [conn1] dbeval slow, time: 120ms profile1
|
m30200| Mon Feb 25 19:49:50.054 [conn1] command profile1.$cmd command: { $eval: "var x = new Date(); sleep(120); return new Date() - x;" } ntoreturn:1 keyUpdates:0 locks(micros) W:121818 reslen:53 121ms
|
121
|
m30200| Mon Feb 25 19:49:50.205 [conn1] dbeval slow, time: 121ms profile1
|
m30200| Mon Feb 25 19:49:50.205 [conn1] command profile1.$cmd command: { $eval: "var x = new Date(); sleep(120); return new Date() - x;" } ntoreturn:1 keyUpdates:0 locks(micros) W:150517 reslen:53 150ms
|
121
|
m30200| Mon Feb 25 19:49:50.333 [conn1] dbeval slow, time: 124ms profile1
|
m30200| Mon Feb 25 19:49:50.333 [conn1] command profile1.$cmd command: { $eval: "var x = new Date(); sleep(120); return new Date() - x;" } ntoreturn:1 keyUpdates:0 locks(micros) W:124270 reslen:53 124ms
|
124
|
123
|
|
m30200| Mon Feb 25 19:49:50.457 [conn1] dbeval slow, time: 123ms profile1
|
m30200| Mon Feb 25 19:49:50.457 [conn1] command profile1.$cmd command: { $eval: "var x = new Date(); sleep(120); return new Date() - x;" } ntoreturn:1 keyUpdates:0 locks(micros) W:123206 reslen:53 123ms
|
m30200| Mon Feb 25 19:49:50.460 [conn1] CMD: drop profile1.system.profile
|
m30200| Mon Feb 25 19:49:50.461 [conn1] creating profile collection: profile1.system.profile
|
m30200| Mon Feb 25 19:49:50.605 [conn1] dbeval slow, time: 123ms profile1
|
m30200| Mon Feb 25 19:49:50.605 [conn1] command profile1.$cmd command: { $eval: "sleep(120)" } ntoreturn:1 keyUpdates:0 locks(micros) W:123568 reslen:45 123ms
|
warning wanted to sleep for: 120 but took: 1556
|
m30200| Mon Feb 25 19:49:52.040 [conn1] CMD: drop profile1.system.profile
|
m30200| Mon Feb 25 19:49:52.042 [conn1] creating profile collection: profile1.system.profile
|
warning wanted to sleep for: 5 but took: 70
|
m30200| Mon Feb 25 19:49:52.236 [conn1] dbeval slow, time: 123ms profile1
|
m30200| Mon Feb 25 19:49:52.236 [conn1] command profile1.$cmd command: { $eval: "sleep(120)" } ntoreturn:1 keyUpdates:0 locks(micros) W:123599 reslen:45 123ms
|
assert: [2] != [1] are not equal : X3 :
|
{
|
"op" : "command",
|
"ns" : "profile1.$cmd",
|
"command" : {
|
"$eval" : "sleep(120)"
|
},
|
"ntoreturn" : 1,
|
"keyUpdates" : 0,
|
"numYield" : 0,
|
"lockStats" : {
|
"timeLockedMicros" : {
|
"R" : NumberLong(0),
|
"W" : NumberLong(123599)
|
},
|
"timeAcquiringMicros" : {
|
"R" : NumberLong(0),
|
"W" : NumberLong(2),
|
"r" : NumberLong(0),
|
"w" : NumberLong(6)
|
}
|
},
|
"responseLength" : 45,
|
"millis" : 123,
|
"ts" : ISODate("2013-02-26T00:49:52.236Z"),
|
"client" : "127.0.0.1",
|
"allUsers" : [
|
{
|
"user" : "super",
|
"userSource" : "admin"
|
},
|
{
|
"user" : "someone else",
|
"userSource" : "connection_status"
|
},
|
{
|
"user" : "jstests_evalb_user",
|
"userSource" : "evalb"
|
},
|
{
|
"user" : "jstests_profile1_user",
|
"userSource" : "profile1"
|
}
|
],
|
"user" : "jstests_profile1_user@profile1"
|
} ,
|
|
Error: Printing Stack Trace
|
at printStackTrace (src/mongo/shell/utils.js:37:7)
|
at doassert (src/mongo/shell/assert.js:6:1)
|
at Function.assert.eq (src/mongo/shell/assert.js:32:1)
|
at jstests/profile1.js:136:12
|
at /data/buildslaves/Linux_RHEL_64bit/mongo/jstests/dur/dur_passthrough.js:35:68
|
at Function.Date.timeFunc (src/mongo/shell/types.js:27:9)
|
at /data/buildslaves/Linux_RHEL_64bit/mongo/jstests/dur/dur_passthrough.js:35:45
|
at Array.forEach (native)
|
at doTest (/data/buildslaves/Linux_RHEL_64bit/mongo/jstests/dur/dur_passthrough.js:18:11)
|
at /data/buildslaves/Linux_RHEL_64bit/mongo/jstests/dur/dur_passthrough.js:51:9
|
Mon Feb 25 19:49:52.243 JavaScript execution failed: [2] != [1] are not equal : X3 :
|
{
|
"op" : "command",
|
"ns" : "profile1.$cmd",
|
"command" : {
|
"$eval" : "sleep(120)"
|
},
|
"ntoreturn" : 1,
|
"keyUpdates" : 0,
|
"numYield" : 0,
|
"lockStats" : {
|
"timeLockedMicros" : {
|
"R" : NumberLong(0),
|
"W" : NumberLong(123599)
|
},
|
"timeAcquiringMicros" : {
|
"R" : NumberLong(0),
|
"W" : NumberLong(2),
|
"r" : NumberLong(0),
|
"w" : NumberLong(6)
|
}
|
},
|
"responseLength" : 45,
|
"millis" : 123,
|
"ts" : ISODate("2013-02-26T00:49:52.236Z"),
|
"client" : "127.0.0.1",
|
"allUsers" : [
|
{
|
"user" : "super",
|
"userSource" : "admin"
|
},
|
{
|
"user" : "someone else",
|
"userSource" : "connection_status"
|
},
|
{
|
"user" : "jstests_evalb_user",
|
"userSource" : "evalb"
|
},
|
{
|
"user" : "jstests_profile1_user",
|
"userSource" : "profile1"
|
}
|
],
|
"user" : "jstests_profile1_user@profile1"
|
} ,
|
at src/mongo/shell/assert.js:L7
|
Mon Feb 25 19:49:52.243 JavaScript execution failed: Error: error loading js file: jstests/profile1.js at /data/buildslaves/Linux_RHEL_64bit/mongo/jstests/dur/dur_passthrough.js:L35
|
failed to load: /data/buildslaves/Linux_RHEL_64bit/mongo/jstests/dur/dur_passthrough.js
|