timeAcquiringMicros and timeLockedMicros explained
5,418 views
Skip to first unread message
FAQUser
Sep 25, 2012, 5:04:37 AM9/25/12
to mongod...@googlegroups.com
Anyone mind explaining to me these 2 fields as my performance degraded significantly these past 2 days i', suspecting it has something to do with them.
Thanks in Advance :D
FAQUser
Sep 25, 2012, 5:35:49 AM9/25/12
to mongod...@googlegroups.com
Another Example
From what I read millis is the number of milli seconds for the operation to complete which in this case is 140
while timeLockedMicros is 146 which is suppose to mean time locked how can this be?
{
"ts": ISODate("2012-09-25T09: 25: 44.724Z"),
"op": "update",
"ns": "CrawledCompanies.CompanyBucketCollection",
"query": {
"_id": ObjectId("505873199fd1870780ba566e")
},
"updateobj": {
"_id": ObjectId("505873199fd1870780ba566e"),
"DateCreated": ISODate("2012-09-18T13: 11: 53.934Z"),
"Type": "ZeepexManager.BuisnessObjects.ERModel.Bucketing.Bucket",
"Data": {
"_t": "Bucket",
"ParentBucket": ObjectId("000000000000000000000000"),
"CreatedOn": ISODate("2012-09-18T13: 11: 53.934Z"),
"Data": {
"_t": "GramSearch",
"Grams": {
"0": "Juliet"
},
"GramIdentifier": "AE02C75A75E13ED8328C91FBCAD2E4A0"
},
"Type": "ZeepexManager.BuisnessObjects.GramBucket.GramSearch",
"Buckets": {
"0": {
"_t": "ObjectReference",
"RefId": ObjectId("4fbf39b59fd18712a49ad0b1"),
"OccuranceCount": 1
},
"1": {
"_t": "ObjectReference",
"RefId": ObjectId("4fbf3f789fd18712a49c4cea"),
"OccuranceCount": 1
},
"2": {
"_t": "ObjectReference",
"RefId": ObjectId("4fbfa63f9fd18718b8fe3433"),
"OccuranceCount": 1
},
"3": {
"_t": "ObjectReference",
"RefId": ObjectId("4fbfa6559fd18718b8fe3bda"),
"OccuranceCount": 1
},
"4": {
"_t": "ObjectReference",
"RefId": ObjectId("4fbfa6b79fd18718b8fe5279"),
"OccuranceCount": 1
},
"5": {
"_t": "ObjectReference",
"RefId": ObjectId("4fbfb2ef9fd18718b800b88d"),
"OccuranceCount": 2
} ...
"99": {
"_t": "ObjectReference",
"RefId": ObjectId("000000000000000000000000"),
"OccuranceCount": 0
}
},
"BucketType": "ZeepexManager.BuisnessObjects.GramBucket.ObjectReference",
"BucketSize": 11,
"NeighbourBuckets": ObjectId("000000000000000000000000")
}
},
"idhack": true,
"nupdated": 1,
"keyUpdates": 0,
"numYield": 0,
"lockStats": {
"timeLockedMicros": {
"r": 0,
"w": 146
},
"timeAcquiringMicros": {
"r": 0,
"w": 152020
}
},
"millis": 140,
"client": "172.21.13.5",
"user": "root"
}
FAQUser
Sep 25, 2012, 9:57:47 AM9/25/12
to mongod...@googlegroups.com
Spent all day playing around with the profiler and stuff and the only reason i can think of why the locking is taking so long is that the index does not fit on ram and making index updates for inserts slow.
On Tuesday, 25 September 2012 11:04:37 UTC+2, FAQUser wrote:
On Tuesday, 25 September 2012 11:04:37 UTC+2, FAQUser wrote:
William Zola
Sep 27, 2012, 3:55:40 PM9/27/12
to mongod...@googlegroups.com
Hi FAQ!
The 'timeLockedMicros' field indicates how many microseconds this operation spent holding a particular lock.
There are two locks for each collection: the 'r' lock indicates how long this operation spent holding the read lock, and the 'w' lock indicates how long it spent holding the write lock.
The 'timeAcquiringMicros' field indicates how many microseconds this operation spent waiting for the locks.
Reference: http://docs.mongodb.org/manual/reference/current-op/#output-reference
If you're looking to diagnose general performance slowdown, I'll need additional information in order to do that.
If these systems are in MMS, then please post a link to the correct MMS group. If they're not please post the following in a gist/pastebing/pastie and post a link:
- Output of 'mongostat --all -n 20'
- Output of 'db.serverStatus()'
- Output of 'db.serverBuildInfo()'
I'll be able to use this information to move forward with my diagnosis.
Ref: http://docs.mongodb.org/manual/administration/monitoring/#diagnosing-performance-issues
Let me know if you have further questions.
-William
Reply all
Reply to author
Forward
0 new messages