[SERVER-17393] Balancer lock not released Created: 26/Feb/15  Updated: 28/Feb/15  Resolved: 27/Feb/15

Status: Closed
Project: Core Server
Component/s: Sharding
Affects Version/s: 3.0.0-rc10
Fix Version/s: None

Type: Bug Priority: Critical - P2
Reporter: Jonathan Abrahams Assignee: Randolph Tan
Resolution: Duplicate Votes: 0
Labels: 28qa, cap-ss
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File configdb.tar.gz     File mongos-balancer-lock.log.gz    
Issue Links:
Duplicate
duplicates SERVER-17398 Deadlock in MigrateStatus::startCommit Closed
Related
Backwards Compatibility: Fully Compatible
Operating System: ALL
Steps To Reproduce:

2 shard node replica set, all running wiredTiger
3 config servers
1 mongos
Heavy insert workload, 4 clients

Participants:

 Description   

The balancer is shown as running with an active lock in over 20 hours.

mongos> sh.status()
--- Sharding Status ---
  sharding version: {
	"_id" : 1,
	"minCompatibleVersion" : 5,
	"currentVersion" : 6,
	"clusterId" : ObjectId("54edd63deae8d68b1c02b2bf")
}
  shards:
	{  "_id" : "shard0",  "host" : "shard0/ip-10-102-151-133:30000,ip-10-203-175-233:30000,ip-10-63-43-228:30000" }
	{  "_id" : "shard1",  "host" : "shard1/ip-10-180-37-181:30000,ip-10-187-63-140:30000,ip-10-203-173-62:30000" }
  balancer:
	Currently enabled:  yes
	Currently running:  yes
		Balancer lock taken at Wed Feb 25 2015 19:30:06 GMT+0000 (UTC) by ip-10-123-129-75:37017:1424873021:1804289383:Balancer:1681692777
	Collections with active migrations:
		test.cap1833hashed started at Wed Feb 25 2015 19:30:07 GMT+0000 (UTC)
	Failed balancer rounds in last 5 attempts:  0
	Migration Results for the last 24 hours:
		32 : Success
		1 : Failed with error '_recvChunkCommit failed!', from shard1 to shard0
		3 : Failed with error 'chunk too big to move', from shard1 to shard0
		247 : Failed with error 'could not acquire collection lock for test.cap1833hashed to migrate chunk [{ : MinKey },{ : MaxKey }) :: caused by :: Lock for migrating chunk [{ : MinKey }, { : MaxKey }) in test.cap1833hashed is taken.', from shard1 to shard0
  databases:
	{  "_id" : "admin",  "partitioned" : false,  "primary" : "config" }
	{  "_id" : "test",  "partitioned" : true,  "primary" : "shard0" }
		test.cap1833hashed
			shard key: { "idx" : "hashed" }
			chunks:
				shard0	57324
				shard1	64971
			too many chunks to print, use verbose if you want to force print



 Comments   
Comment by Randolph Tan [ 26/Feb/15 ]

According to the changelog, the migration started at 2/25 @ 19:30. There is no entry for the end or failure so the migration is still in progress and thus why the lock is not released. I would like to see the logs from the primary of shard1 (donor) and shard0 (recipient) starting from around 19:28 to see if the the migration is stuck or is just slow.

Thanks!

Comment by Jonathan Abrahams [ 26/Feb/15 ]

I truncated the log, as it was too big to attach to the ticket. I can provide access to environment, in case you need to see why the lock has not been released.

Comment by Randolph Tan [ 26/Feb/15 ]

Based from the logs (that spanned roughly 30 minutes), the balancer lock was released 13 times. And as of the time when the log ended, it is still holding the lock since it is still moving a chunk. There has also been several attempts of moving chunks before that failed because it was not able to grab the distributed collection lock. So in the current state, it is expected that the lock should not be available.

Comment by Jonathan Abrahams [ 26/Feb/15 ]

Preload setup

sh.addShard("shard0/ip-10-102-151-133:30000")
sh.addShard("shard1/ip-10-203-173-62:30000")
db.adminCommand({ movePrimary : "test", to : "shard0" })
sh.enableSharding("test")
sh.status()
 
 
var largeValue = new Array(2048).join('Largevalue');
 
// set chunk size
db.getSiblingDB("config").settings.save({"_id" : "chunksize", "value" :2});
// shard collection with hashed key
 
sh.enableSharding("test");
var coll = db.cap1833hashed;
coll.ensureIndex({idx: "hashed"});
sh.shardCollection("test.cap1833hashed", {idx: "hashed"});
// secondary index
coll.ensureIndex({idx2: 1});
 
// Pre-load step
// Average doc size = 1KB
// Chunk size = 2MB (2000 docs)
// Total data = 1GB (500 chunks, 1000000 docs)
var numDocs = 1000000;
var startInsert = new Date();
var bulk = coll.initializeUnorderedBulkOp();
for (var i = 0; i < numDocs; i++) {
    // Random doc variance of 400 bytes (600-1000)
    var arraySize = 600 + Math.floor(Math.random()*1000)%400;
    var randomVal = Math.floor(Math.random()*numDocs);
    var doc = {idx: randomVal, idx2: randomVal, val: largeValue.slice(0, arraySize)};
    bulk.insert(doc);
}
var res = bulk.execute();
printjson(res);
var doneInsert = new Date();
print("Insert time", (doneInsert-startInsert)/1000);

Workload script (4 clients running over 20 hours)

var baseNum = 10000;
var coll = db.cap1833hashed;
var largeValue = new Array(1024).join('Largevalue');
var res;
while (true) {
    print();
    print(Date());
    try {
        var info = db.hostInfo();
        print("dbHostInfo status:", info.ok);
        var op = Math.floor(Math.random() * 10) % 10;
        var match = Math.floor(Math.random() * 1000000) % baseNum;
        switch(op) {
            case 0:
            case 1:
            case 2:
            case 3:
            case 4:
                // bulk insert baseNum docs
                print("Bulk insert", baseNum, "docs");
                var bulk = coll.initializeUnorderedBulkOp();
                    for (var i = 0; i < baseNum; i++) {
                        bulk.insert({idx:i, idx2: i, doc: largeValue});
                    }
                res = bulk.execute();
                printjson(res);
                break;
            case 5:
            case 6:
            case 7:
            case 8:
            case 9:
                // find matchings docs
                print("Find docs");
                res = coll.find({idx: {$gte: match}}).count();
                printjson(res);
                break;
        }
        res = coll.count();
        print("Docs in collection", res);
        sleep(1000);
    } catch(e) {
        print("Error encountered", tojson(e));
        sleep(10000);
    }
}

Generated at Thu Feb 08 03:44:17 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.