Loading...

Type: Bug
Resolution: Done
Priority: Major - P3
Fix Version/s: None
Affects Version/s: 3.2.1
Component/s: Sharding
Labels:
None

Operating System:
ALL
Steps To Reproduce:

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")`
Sprint:
Sharding 10 (02/19/16), Sharding 11 (03/11/16)
Linked BF Score:
0
CAR Domain/s:
None

Aha! Reference:
None
Tracking Level:
None
Risk Status:
None
Exec Notes:
None
Goal Name(s):
None
Goal Link:
None

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.

- - Sort By Name
  - Sort By Date
  - Ascending
  - Descending
  - Thumbnails
  - List
  - Download All

mongod-config-server-logs.tar.gz
220 kB
Feb 01 2016 11:30:11 AM UTC

is related to

SERVER-22427 Add additional diagnostics to "Operation timed out" errors returned from NetworkInterfaceASIO

Closed

SERVER-22428 Log read-after-optime timeouts

Closed

Details

Description

Attachments

Attachments

Issue Links

Activity

People

Dates