A slow insert of a 512-byte document is logged simply as a "query not recording (too large)" command, containing no information about what kind of write op was slow.
> db.setProfilingLevel(2,-1)
|
{ "was" : 2, "slowms" : -1, "ok" : 1 }
|
> var s512 = 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
|
> print(s512.length)
|
512
|
> db.foo.insert({foo: s512})
|
WriteResult({ "nInserted" : 1 })
|
2014-02-26T17:42:09.055-0500 [conn1] command test.$cmd command: { $msg: "query not recording (too large)" } keyUpdates:0 numYields:0 reslen:40 0ms
|
To the contrary, a slow insert of a 256-byte document is logged with the truncated document, such that it is clear that the slow operation is an insert:
> db.setProfilingLevel(2,-1)
|
{ "was" : 2, "slowms" : -1, "ok" : 1 }
|
> var s256 = 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa';
|
> print(s256.length)
|
256
|
> db.foo.insert({foo: s256})
|
WriteResult({ "nInserted" : 1 })
|
2014-02-26T17:42:02.664-0500 [conn1] command test.$cmd command: { insert: "foo", documents: [ { _id: ObjectId('530e6dbaed9a16e31683ccce'), foo: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa..." } ], ordered: true } keyUpdates:0 numYields:0 reslen:40 0ms
|