[SERVER-26344] ExceededTimeLimit: Operation timed out Created: 26/Sep/16  Updated: 04/Oct/16  Resolved: 04/Oct/16

Status: Closed
Project: Core Server
Component/s: Sharding
Affects Version/s: 3.2.9
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Dan Jenkins Assignee: Kelsey Schubert
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Operating System: ALL
Participants:

 Description   

I am running into the same issue as SERVER-22392. The configuration is 3 replicated configdb servers and one shard wtih replicated master and two slaves. All servers can see one another, but I am getting this time out error when I do anything on mongos.

Output of mongos logs:

$ mongos --configdb configReplSet/mongoconfig01:27019,mongoconfig02:27019,mongoconfig03:27019
2016-09-26T18:51:55.057-0400 I SHARDING [mongosMain] MongoS version 3.2.9 starting: pid=3832 port=27017 64-bit host=c2me-vm6 (--help for usage)
2016-09-26T18:51:55.057-0400 I CONTROL  [mongosMain] db version v3.2.9
2016-09-26T18:51:55.057-0400 I CONTROL  [mongosMain] git version: 22ec9e93b40c85fc7cae7d56e7d6a02fd811088c
2016-09-26T18:51:55.057-0400 I CONTROL  [mongosMain] OpenSSL version: OpenSSL 1.0.2g  1 Mar 2016
2016-09-26T18:51:55.057-0400 I CONTROL  [mongosMain] allocator: tcmalloc
2016-09-26T18:51:55.057-0400 I CONTROL  [mongosMain] modules: none
2016-09-26T18:51:55.057-0400 I CONTROL  [mongosMain] build environment:
2016-09-26T18:51:55.058-0400 I CONTROL  [mongosMain]     distmod: ubuntu1604
2016-09-26T18:51:55.058-0400 I CONTROL  [mongosMain]     distarch: x86_64
2016-09-26T18:51:55.058-0400 I CONTROL  [mongosMain]     target_arch: x86_64
2016-09-26T18:51:55.058-0400 I CONTROL  [mongosMain] options: { sharding: { configDB: "configReplSet/mongoconfig01:27019,mongoconfig02:27019,mongoconfig03:27019" } }
2016-09-26T18:51:55.058-0400 I SHARDING [mongosMain] Updating config server connection string to: configReplSet/mongoconfig01:27019,mongoconfig02:27019,mongoconfig03:27019
2016-09-26T18:51:55.058-0400 I NETWORK  [mongosMain] Starting new replica set monitor for configReplSet/mongoconfig01:27019,mongoconfig02:27019,mongoconfig03:27019
2016-09-26T18:51:55.059-0400 I SHARDING [thread1] creating distributed lock ping thread for process c2me-vm6:27017:1474930315:-1052051565 (sleeping for 30000ms)
2016-09-26T18:51:55.060-0400 I NETWORK  [ReplicaSetMonitorWatcher] starting
2016-09-26T18:51:55.061-0400 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Connecting to mongoconfig03:27019
2016-09-26T18:51:55.062-0400 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Successfully connected to mongoconfig03:27019
2016-09-26T18:51:55.062-0400 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Connecting to mongoconfig02:27019
2016-09-26T18:51:55.063-0400 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Successfully connected to mongoconfig02:27019
2016-09-26T18:51:55.064-0400 I NETWORK  [mongosMain] Starting new replica set monitor for rs0/mongosh01db01:27017,mongosh01db02:27017,mongosh01db03:27017
2016-09-26T18:51:55.064-0400 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Connecting to mongoconfig03:27019
2016-09-26T18:51:55.064-0400 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Successfully connected to mongoconfig03:27019
2016-09-26T18:51:55.121-0400 W SHARDING [replSetDistLockPinger] pinging failed for distributed lock pinger :: caused by :: LockStateChangeFailed: findAndModify query predicate didn't match any lock document
2016-09-26T18:51:55.123-0400 I SHARDING [Balancer] about to contact config servers and shards
2016-09-26T18:51:55.123-0400 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Connecting to mongoconfig01:27019
2016-09-26T18:51:55.126-0400 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Successfully connected to mongoconfig01:27019
2016-09-26T18:51:55.130-0400 I NETWORK  [HostnameCanonicalizationWorker] Starting hostname canonicalization worker
2016-09-26T18:51:55.139-0400 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Connecting to mongosh01db01:27017
2016-09-26T18:51:55.146-0400 I NETWORK  [mongosMain] waiting for connections on port 27017
2016-09-26T18:52:02.042-0400 I NETWORK  [mongosMain] connection accepted from 127.0.0.1:37154 #1 (1 connection now open)
2016-09-26T18:52:13.342-0400 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Connecting to mongosh01db01:27017
2016-09-26T18:52:15.139-0400 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Failed to connect to mongosh01db01:27017 - ExceededTimeLimit: Operation timed out
2016-09-26T18:52:15.139-0400 W SHARDING [Balancer] could not initialize balancer, please check that all shards and config servers are up: Operation timed out
2016-09-26T18:52:15.142-0400 I SHARDING [Balancer] will retry to initialize balancer in one minute
2016-09-26T18:52:33.342-0400 I ASIO     [NetworkInterfaceASIO-ShardRegistry-0] Failed to connect to mongosh01db01:27017 - ExceededTimeLimit: Operation timed out



 Comments   
Comment by Kelsey Schubert [ 04/Oct/16 ]

Hi djenkins,

Thanks for your report. Please note that SERVER project is for reporting bugs or feature suggestions for the MongoDB server. For MongoDB-related support discussion please post on the mongodb-users group or Stack Overflow with the mongodb tag. A question like this involving more discussion would be best posted on the mongodb-users group.

Kind regards,
Thomas

Comment by Dan Jenkins [ 26/Sep/16 ]

results of sh.status():

$ mongo localhost
MongoDB shell version: 3.2.9
connecting to: localhost
2016-09-26T18:57:27.356-0400 I NETWORK  [mongosMain] connection accepted from 127.0.0.1:37178 #2 (2 connections now open)
mongos> sh.status()
--- Sharding Status ---
  sharding version: {
        "_id" : 1,
        "minCompatibleVersion" : 5,
        "currentVersion" : 6,
        "clusterId" : ObjectId("57e04fa883c2fe1fba34d139")
}
  shards:
        {  "_id" : "rs0",  "host" : "rs0/mongosh01db01:27017,mongosh01db02:27017,mongosh01db03:27017" }
  most recently active mongoses:
        "3.2.9" : 1
  balancer:
        Currently enabled:  yes
        Currently running:  no
        Failed balancer rounds in last 5 attempts:  5
        Last reported error:  Operation timed out
        Time of Reported error:  Mon Sep 19 2016 18:53:53 GMT-0400 (EDT)
        Migration Results for the last 24 hours:
                No recent migrations
  databases:

Generated at Thu Feb 08 04:11:49 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.