Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-22392

"Operation timed out" when enableSharding on new cluster

    XMLWordPrintableJSON

Details

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Major - P3 Major - P3
    • None
    • 3.2.1
    • Sharding
    • None
    • ALL
    • Hide

      1. Create 6 replication sets with 3 nodes each
      2. Set clusterRole to configsvr on one shard to make it config RS
      3. Set clusterRole on others to shardsvr
      3. Run rs.initiate() on 'first' node of each shard
      4. Run db.CreateUser to create admin user (role: "root") on 'first' node of each shard
      5. Run mongos pointing to config servers
      6. Connect to mongos, add shards
      7. Try to enable sharding `sh.enableSharding("my-db")`

      Show
      1. Create 6 replication sets with 3 nodes each 2. Set clusterRole to configsvr on one shard to make it config RS 3. Set clusterRole on others to shardsvr 3. Run rs.initiate() on 'first' node of each shard 4. Run db.CreateUser to create admin user (role: "root") on 'first' node of each shard 5. Run mongos pointing to config servers 6. Connect to mongos, add shards 7. Try to enable sharding `sh.enableSharding("my-db")`
    • Sharding 10 (02/19/16), Sharding 11 (03/11/16)
    • 0

    Description

      Given a mongodb 3.2.1 cluster with multiple shards, enabling sharding for a database yields "Operation timed out":

      mongos>   sh.enableSharding("my-db")
      { "ok" : 0, "errmsg" : "Operation timed out", "code" : 50 }
      

      Adding shards worked just fine but sh.status() also shows timeout issues:

      mongos> sh.status(true)
      --- Sharding Status --- 
        sharding version: {
      	"_id" : 1,
      	"minCompatibleVersion" : 5,
      	"currentVersion" : 6,
      	"clusterId" : ObjectId("56af2c8c9a517ed41619c719")
      }
        shards:
      	{  "_id" : "replA",  "host" : "replA/replA-0.mongodb-shardsvr.service.q:27017,replA-1.mongodb-shardsvr.service.q:27017,replA-2.mongodb-shardsvr.service.q:27017" }
      	{  "_id" : "replB",  "host" : "replB/replB-0.mongodb-shardsvr.service.q:27017,replB-1.mongodb-shardsvr.service.q:27017,replB-2.mongodb-shardsvr.service.q:27017" }
      	{  "_id" : "replC",  "host" : "replC/replC-0.mongodb-shardsvr.service.q:27017,replC-1.mongodb-shardsvr.service.q:27017,replC-2.mongodb-shardsvr.service.q:27017" }
      	{  "_id" : "replD",  "host" : "replD/replD-0.mongodb-shardsvr.service.q:27017,replD-1.mongodb-shardsvr.service.q:27017,replD-2.mongodb-shardsvr.service.q:27017" }
      	{  "_id" : "replE",  "host" : "replE/replE-0.mongodb-shardsvr.service.q:27017,replE-1.mongodb-shardsvr.service.q:27017,replE-2.mongodb-shardsvr.service.q:27017" }
        active mongoses:
      	{  "_id" : "ip-10-1-45-192:27018",  "ping" : ISODate("2016-02-01T11:12:25.013Z"),  "up" : NumberLong(4363),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-45-220:27018",  "ping" : ISODate("2016-02-01T11:12:24.552Z"),  "up" : NumberLong(4363),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-47-28:27018",  "ping" : ISODate("2016-02-01T11:12:24.434Z"),  "up" : NumberLong(4362),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-40-26:27018",  "ping" : ISODate("2016-02-01T11:12:24.251Z"),  "up" : NumberLong(4363),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-24-168:27018",  "ping" : ISODate("2016-02-01T11:12:24.050Z"),  "up" : NumberLong(4362),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-29-10:27017",  "ping" : ISODate("2016-02-01T11:12:24.047Z"),  "up" : NumberLong(4362),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-24-208:27018",  "ping" : ISODate("2016-02-01T11:12:24.044Z"),  "up" : NumberLong(4362),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-11-238:27017",  "ping" : ISODate("2016-02-01T11:12:23.750Z"),  "up" : NumberLong(4361),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-46-222:27018",  "ping" : ISODate("2016-02-01T11:12:23.686Z"),  "up" : NumberLong(4362),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-27-15:27018",  "ping" : ISODate("2016-02-01T11:12:23.559Z"),  "up" : NumberLong(4361),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-45-146:27018",  "ping" : ISODate("2016-02-01T11:12:23.529Z"),  "up" : NumberLong(4362),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-26-190:27018",  "ping" : ISODate("2016-02-01T11:12:23.325Z"),  "up" : NumberLong(4361),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-28-139:27018",  "ping" : ISODate("2016-02-01T11:12:23.253Z"),  "up" : NumberLong(4362),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-8-127:27018",  "ping" : ISODate("2016-02-01T11:12:23.206Z"),  "up" : NumberLong(4362),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-25-107:27018",  "ping" : ISODate("2016-02-01T11:12:23.206Z"),  "up" : NumberLong(4362),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-8-239:27018",  "ping" : ISODate("2016-02-01T11:12:22.988Z"),  "up" : NumberLong(4360),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-11-26:27018",  "ping" : ISODate("2016-02-01T11:12:22.986Z"),  "up" : NumberLong(4361),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-10-142:27018",  "ping" : ISODate("2016-02-01T11:12:22.970Z"),  "up" : NumberLong(4361),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-10-41:27018",  "ping" : ISODate("2016-02-01T11:12:22.131Z"),  "up" : NumberLong(4360),  "waiting" : false,  "mongoVersion" : "3.2.1" }
      	{  "_id" : "ip-10-1-11-229:27018",  "ping" : ISODate("2016-02-01T11:12:16.815Z"),  "up" : NumberLong(3640),  "waiting" : false,  "mongoVersion" : "3.2.1" }
        balancer:
      	Currently enabled:  yes
      	Currently running:  no
      	Failed balancer rounds in last 5 attempts:  5
      	Last reported error:  could not get updated shard list from config server due to ExceededTimeLimit Operation timed out
      	Time of Reported error:  Mon Feb 01 2016 11:12:14 GMT+0000 (UTC)
      	Migration Results for the last 24 hours: 
      		No recent migrations
        databases:
      

      On the config server RS, rs.status() looks good:

      configReplSet:PRIMARY> rs.status()
      {
      	"set" : "configReplSet",
      	"date" : ISODate("2016-02-01T11:15:52.962Z"),
      	"myState" : 1,
      	"term" : NumberLong(1),
      	"configsvr" : true,
      	"heartbeatIntervalMillis" : NumberLong(2000),
      	"members" : [
      		{
      			"_id" : 0,
      			"name" : "configReplSet-0.mongodb-configsvr.service.q:27017",
      			"health" : 1,
      			"state" : 1,
      			"stateStr" : "PRIMARY",
      			"uptime" : 4588,
      			"optime" : {
      				"ts" : Timestamp(1454325351, 1),
      				"t" : NumberLong(1)
      			},
      			"optimeDate" : ISODate("2016-02-01T11:15:51Z"),
      			"electionTime" : Timestamp(1454320777, 1),
      			"electionDate" : ISODate("2016-02-01T09:59:37Z"),
      			"configVersion" : 1,
      			"self" : true
      		},
      		{
      			"_id" : 1,
      			"name" : "configReplSet-1.mongodb-configsvr.service.q:27017",
      			"health" : 1,
      			"state" : 2,
      			"stateStr" : "SECONDARY",
      			"uptime" : 4586,
      			"optime" : {
      				"ts" : Timestamp(1454325348, 1),
      				"t" : NumberLong(1)
      			},
      			"optimeDate" : ISODate("2016-02-01T11:15:48Z"),
      			"lastHeartbeat" : ISODate("2016-02-01T11:15:51.718Z"),
      			"lastHeartbeatRecv" : ISODate("2016-02-01T11:15:51.271Z"),
      			"pingMs" : NumberLong(0),
      			"syncingTo" : "configReplSet-0.mongodb-configsvr.service.q:27017",
      			"configVersion" : 1
      		},
      		{
      			"_id" : 2,
      			"name" : "configReplSet-2.mongodb-configsvr.service.q:27017",
      			"health" : 1,
      			"state" : 2,
      			"stateStr" : "SECONDARY",
      			"uptime" : 4586,
      			"optime" : {
      				"ts" : Timestamp(1454325351, 1),
      				"t" : NumberLong(1)
      			},
      			"optimeDate" : ISODate("2016-02-01T11:15:51Z"),
      			"lastHeartbeat" : ISODate("2016-02-01T11:15:51.883Z"),
      			"lastHeartbeatRecv" : ISODate("2016-02-01T11:15:51.774Z"),
      			"pingMs" : NumberLong(0),
      			"syncingTo" : "configReplSet-0.mongodb-configsvr.service.q:27017",
      			"configVersion" : 1
      		}
      	],
      	"ok" : 1
      }
      

      All this was working when I did the same on 3.2.0 without authentication. So it's either related to the authentication or a regression in 3.2.1. I'll try to reproduce this with 3.2.1 now.

      Attachments

        Activity

          People

            spencer@mongodb.com Spencer Brody (Inactive)
            fish Johannes Ziemke
            Votes:
            0 Vote for this issue
            Watchers:
            10 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: