# TokuMX -  range locking and Lock not granted

**URL:** <https://forums.percona.com/t/tokumx-range-locking-and-lock-not-granted/5033>\
**Category:** Percona Server for MongoDB\
**Created:** [August 10, 2016, 5:45pm UTC](https://forums.percona.com/t/tokumx-range-locking-and-lock-not-granted/5033 "2016-08-10T17:45:01Z")\
**Posts on this page:** 1\
**Page:** 1

<div class="post-metadata">

**Author:** ![voodoo\_nostromo](https://avatars.discourse-cdn.com/v4/letter/v/f17d59/32.png) [@voodoo\_nostromo](https://forums.percona.com/u/voodoo_nostromo)\
**Post date:** [August 10, 2016, 5:45pm UTC](https://forums.percona.com/t/tokumx-range-locking-and-lock-not-granted/5033/1 "2016-08-10T17:45:01Z")

</div>

Hello,

In our application we make heavy use of transactions. Recently we started getting Lock not granted messages with multiple concurrent users. Before getting that message tokumx becomes unresponsive and afterwards can leave the data in inconsistent state.We are using Python and MongoEngine.

Below are the relevant log excerpts. I see two potential causes:

1. The bounds for locks are not set per document if the $in operator is used, but on the whole collection subrange. Can this be confirmed? What is the preferred way to update many documents in TokuMX? Would it be better to issue one update command per document in this case?

2. Very often the next operation after lock not granted is insert collection.system.indexes, which apparently requires write lock. Does this message mean that a new document is being added to the index or this means adding a new index? We are not adding any new indexes, but maybe this is related to changing type to multi key indexes?

I would appreciate any help with this.

Thanks

Maricn

Wed Aug 10 18:05:23.586 [conn10421] insert collection.changes keyUpdates:0 exception: Lock not granted. Try restarting the transaction. code:16759 lockNotGranted: { index: “collection.changes.$\_cls\_1\_contract\_1\_item\_parent\_1\_item\_1”, requestingTxnid:  
3746827, blockingTxnid: 3744908, bounds: [ { \_cls: “ContractChange”, contract: ObjectId(‘57ab65cc135ff11f57c6cc0e’), item\_parent: ObjectId(‘57ab65cd135ff11f57c6cc26’), item: ObjectId(‘57ab65cd135ff11f57c6cc24’), $primaryKey: MinKey }, { \_cls: “ContractC  
hange”, contract: ObjectId(‘57ab65cc135ff11f57c6cc0e’), item\_parent: ObjectId(‘57ab65cd135ff11f57c6cc26’), item: ObjectId(‘57ab65cd135ff11f57c6cc24’), $primaryKey: MaxKey } ], blockingOp: { opid: 2444313, active: false, op: “query”, ns: “”, query: { $msg  
: “query not recording (too large)” }, client: “172.31.42.160:36492”, desc: “conn10527”, threadId: “0x7f86f37fb700”, connectionId: 10527, rootTxnid: 3744908, locks: { ^collection: “R” }, context: “query (/mnt/workspace/percona-tokumx-2.0-debian-binary/  
label\_exp/vps-ubuntu-trusty-x64-04/tokumx-enterprise-2.0.2/src/mongo/db/ops/query.cpp:1003)”, waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } } } locks(micros) r:10000248 10000ms  
Wed Aug 10 18:05:23.586 [conn10438] insert collection.system.indexes ninserted:1 keyUpdates:0 locks(micros) r:75 w:86 3794ms

Wed Aug 10 18:03:20.345 [conn10529] update collection.changes query: { \_cls: “ContractChange”, contract: ObjectId(‘57ab6c141ff701555fb4cb8d’), cid: 15 } update: { $set: { occurrence\_counter: 1 } } nscanned:0 nupdated:0 keyUpdates:0 lockNotGranted: { in  
dex: “collection.changes.$\_cls\_1\_contract\_1\_item\_1”, requestingTxnid: 3732428, blockingTxnid: 3730785, bounds: [ { \_cls: “ContractChange”, contract: ObjectId(‘57ab6c141ff701555fb4cb8d’), item: MinKey, $primaryKey: MinKey }, { \_cls: “ContractChange”, co  
ntract: ObjectId(‘57ab6c141ff701555fb4cb8d’), item: MaxKey, $primaryKey: MaxKey } ], blockingOp: { opid: 2425666, active: true, secs\_running: 19, op: “insert”, ns: “collection.system.indexes”, insert: {}, client: “172.31.29.55:51530”, desc: “conn10424”  
, threadId: “0x7f87435fd700”, connectionId: 10424, rootTxnid: 3730785, locks: { ^: “w”, ^collection: “W” }, context: “insert (/mnt/workspace/percona-tokumx-2.0-debian-binary/label\_exp/vps-ubuntu-trusty-x64-04/tokumx-enterprise-2.0.2/src/mongo/db/instan  
ce.cpp:997)”, waitingForLock: false, lockStats: { timeLockedMicros: { r: 107, w: 0 }, timeAcquiringMicros: { r: 2, w: 19217213 } } } } locks(micros) r:20000719 20000ms

Wed Aug 10 18:02:47.491 [conn10424] update collection.changes query: { \_cls: “ContractChange”, contract: ObjectId(‘57ab6badaa44d67627da7b80’), cid: 15 } update: { $set: { occurrence\_counter: 1 } } nscanned:0 nupdated:0 keyUpdates:0 lockNotGranted: { in  
dex: “collection.changes.$\_cls\_1\_contract\_1\_item\_parent\_1\_item\_1”, requestingTxnid: 3730785, blockingTxnid: 3731261, bounds: [ { \_cls: “ContractChange”, contract: ObjectId(‘57ab6badaa44d67627da7b80’), item\_parent: MinKey, item: MinKey, $primaryKey: Min  
Key }, { \_cls: “ContractChange”, contract: ObjectId(‘57ab6badaa44d67627da7b80’), item\_parent: MaxKey, item: MaxKey, $primaryKey: MaxKey } ], blockingOp: { opid: 2420278, active: true, secs\_running: 49, op: “insert”, ns: “collection.system.indexes”, ins  
ert: {}, client: “172.31.25.197:51859”, desc: “conn10414”, threadId: “0x7f86ea2fe700”, connectionId: 10414, rootTxnid: 3731261, locks: { ^: “w”, ^collection: “W” }, context: “insert (/mnt/workspace/percona-tokumx-2.0-debian-binary/label\_exp/vps-ubuntu-  
trusty-x64-04/tokumx-enterprise-2.0.2/src/mongo/db/instance.cpp:997)”, waitingForLock: false, lockStats: { timeLockedMicros: { r: 68, w: 0 }, timeAcquiringMicros: { r: 1, w: 49172164 } } } } locks(micros) r:50001297 50001ms  
Wed Aug 10 18:02:47.491 [conn10414] insert collection.system.indexes ninserted:1 keyUpdates:0 locks(micros) r:68 w:98 49172ms

Wed Aug 10 18:01:36.733 [conn10366] query collection.tags query: { section: { $in: [ ObjectId(‘57ab56d11ff701555fb4b168’), ObjectId(‘57ab56d11ff701555fb4b15f’), ObjectId(‘57ab56d11ff701555fb4b160’), ObjectId(‘57ab56d11ff701555fb4b161’), ObjectId(‘57ab5  
6d11ff701555fb4b120’), ObjectId(‘57ab56d11ff701555fb4b121’), ObjectId(‘57ab56d11ff701555fb4b12f’), ObjectId(‘57ab56d21ff701555fb4b18c’), ObjectId(‘57ab56d21ff701555fb4b18b’), ObjectId(‘57ab56d11ff701555fb4b130’), ObjectId(‘57ab56cd1ff701555fb4b057’), Obj  
ectId(‘57ab56d11ff701555fb4b131’), ObjectId(‘57ab56d11ff701555fb4b169’), ObjectId(‘57ab56d11ff701555fb4b12d’), ObjectId(‘57ab56ce1ff701555fb4b063’), ObjectId(‘57ab56d11ff701555fb4b162’), ObjectId(‘57ab56d11ff701555fb4b124’), ObjectId(‘57ab56d11ff701555fb  
4b163’), ObjectId(‘57ab56d11ff701555fb4b132’), ObjectId(‘57ab56d11ff701555fb4b133’), ObjectId(‘57ab56d21ff701555fb4b16d’), ObjectId(‘57ab56d21ff701555fb4b172’), ObjectId(‘57ab56d21ff701555fb4b174’), ObjectId(‘57ab56d01ff701555fb4b0f9’), ObjectId(‘57ab56d  
11ff701555fb4b139’), ObjectId(‘57ab56d11ff701555fb4b164’), ObjectId(‘57ab56d11ff701555fb4b13a’), ObjectId(‘57ab56d11ff701555fb4b13b’), ObjectId(‘57ab56d11ff701555fb4b13c’), ObjectId(‘57ab56d11ff701555fb4b165’), ObjectId(‘57ab56ce1ff701555fb4b085’), Objec  
tId(‘57ab56ce1ff701555fb4b08d’), ObjectId(‘57ab56ce1ff701555fb4b08f’), ObjectId(‘57ab56ce1ff701555fb4b092’), ObjectId(‘57ab56d11ff701555fb4b127’), ObjectId(‘57ab56d11ff701555fb4b134’), ObjectId(‘57ab56d11ff701555fb4b135’), ObjectId(‘57ab56cf1ff701555fb4b0ed’), ObjectId(‘5  
7ab56cf1ff701555fb4b0c5’), ObjectId(‘57ab56cf1ff701555fb4b0c6’), ObjectId(‘57ab56cf1ff701555fb4b0c7’), ObjectId(‘57ab56d01ff701555fb4b0fc’), ObjectId(‘57ab56d01ff701555fb4b0fd’), ObjectId(‘57ab56d01ff701555fb4b0fe’), ObjectId(‘57ab56d11ff701555fb4b151’), Objec  
tId(‘57ab56d11ff701555fb4b14a’), ObjectId(‘57ab56d11ff701555fb4b14b’), ObjectId(‘57ab56d11ff701555fb4b14c’), ObjectId(‘57ab56cf1ff701555fb4b0eb’), ObjectId(‘57ab56d11ff701555fb4b14d’), ObjectId(‘57ab56d11ff701555fb4b14e’), ObjectId(‘57ab56cf1ff701555fb4b  
0ec’), ObjectId(‘57ab56d11ff701555fb4b14f’), ObjectId(‘57ab56d11ff701555fb4b150’) ] }, \_cls: { $in: [“Tag”, “Tag.ValueTag”] }, contract: ObjectId(‘57ab56c91ff701555fb4aecd’) } ntoreturn:0 keyUpdates:0 exception: Lock not granted. Try restarting the transaction. code:16759 lockNotGranted: { inde  
x: “collection.ns”, requestingTxnid: 3732456, blockingTxnid: 3730785, bounds: [{ ns: “collection.tags” }, { ns: “collection.tags” }], blockingOp: { opid: 2419580, active: false, op: “query”, ns: “”, query: { $msg: "query not recording (too large)  
" }, client: “172.31.29.55:51530”, desc: “conn10424”, threadId: “0x7f87435fd700”, connectionId: 10424, rootTxnid: 3730785, locks: { ^collection: “R” }, context: “query (/mnt/workspace/percona-tokumx-2.0-debian-binary/label\_exp/vps-ubuntu-trusty-x64-04/  
tokumx-enterprise-2.0.2/src/mongo/db/ops/query.cpp:1003)”, waitingForLock: true, lockStats: { timeLockedMicros: {}, timeAcquiringMicros: {} } } } locks(micros) r:10000290 reslen:95 10000ms  
Wed Aug 10 18:01:36.733 [conn10412] assertion 16759 Lock not granted. Try restarting the transaction. ns:collection.tags query:{ \_id: { $in: [ObjectId(‘57aabb61aa44d6450d2221a6’)] } }

Current ops view of the indexing op:

{  
“opid” : 10674100,  
“active” : true,  
“secs\_running” : 380,  
“op” : “insert”,  
“ns” : “contractroom.system.indexes”,  
“insert” : {

},  
“client” : “172.31.47.18:47304”,  
“desc” : “conn86929”,  
“threadId” : “0x7fae17af9700”,  
“connectionId” : 86929,  
“rootTxnid” : 14824514,  
“locks” : {  
“^contractroom” : “W”  
},  
“context” : “insert (/mnt/workspace/percona-tokumx-2.0-debian-binary/label\_exp/vps-ubuntu-trusty-x64-04/tokumx-enterprise-2.0.2/src/mongo/db/instance.cpp:997)”,  
“waitingForLock” : true,  
“lockStats” : {  
“timeLockedMicros” : {  
“r” : NumberLong(74),  
“w” : NumberLong(0)  
},  
“timeAcquiringMicros” : {  
“r” : NumberLong(1),  
“w” : NumberLong(0)  
}  
}  
},