I've observed what appear to be strange lock time values in my mongod log file.

I've got entries for two separate collections, col1 (no indexes apart from on _id) and col2 (index on _id plus two further indexes, one on a single key and one a compound on two keys - both ascending). For example:

2014-06-16T16:15:55.690+0000 [conn441056] insert dbname.col1 ninserted:2 keyUpdates:0 numYields:0 locks(micros) w:106859 106ms
2014-06-16T16:28:55.608+0000 [conn441056] insert dbname.col2 ninserted:1 keyUpdates:0 numYields:0 locks(micros) w:237838 119ms

The vast majority of my col1 log entries show the write lock time to be either almost identical to, or significantly less than, the query time. However, the vast majority of my col2 entries show the write lock time to be double the query execution time.

I've tried profiling these queries and can see that the time is taken up in timeLocked not timeAcquiring, for example:
{ "op" : "insert", "ns" : "dbname.col2", "ninserted" : 1, "keyUpdates" : 0, "numYield" : 0, "lockStats" : { "timeLockedMicros" :

{ "r" : NumberLong(0), "w" : NumberLong(1186366) }

, "timeAcquiringMicros" :

{ "r" : NumberLong(0), "w" : NumberLong(51) }

}, "millis" : 593, "execStats" : { }, "ts" : ISODate("2014-06-20T16:33:55.763Z"), "client" : "10.0.4.4", "allUsers" : [ ], "user" : "" }

I know from the documentation that timeLockedMicros can be larger than mills due to locks on the oplog, but it seems strange that timeLockedMicros is only double on one of the two collections.

This behaviour has been observed on MongoDB 2.6.0 (mongodb-org package) on Ubuntu 13.04 64-bit.