Uploaded image for project: 'Java Driver'
  1. Java Driver
  2. JAVA-1622

Possible race in async server selection

XMLWordPrintableJSON

    • Type: Icon: Bug Bug
    • Resolution: Cannot Reproduce
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: None
    • Component/s: Cluster Management
    • Labels:
      None

      An async test is timing out waiting for a server to be selected, yet, the logs show that the primary is found milliseconds after the server selection first fails to find the primary.

      15:55:23.260 [Test worker] INFO  org.mongodb.driver.cluster - Cluster created with settings {hosts=[localhost:27017, localhost:27018], mode=MULTIPLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms', maxWaitQueueSize=500}
15:55:23.263 [Test worker] INFO  org.mongodb.driver.cluster - Adding discovered server localhost:27017 to client view of cluster
15:55:23.332 [Test worker] INFO  org.mongodb.driver.cluster - Adding discovered server localhost:27018 to client view of cluster
15:55:23.407 [Test worker] INFO  org.mongodb.driver.cluster - No server chosen by PrimaryServerSelector from cluster description ClusterDescription{type=UNKNOWN, connectionMode=MULTIPLE, all=[ServerDescription{address=localhost:27017, type=UNKNOWN, state=CONNECTING}, ServerDescription{address=localhost:27018, type=UNKNOWN, state=CONNECTING}]}. Waiting for 30000 ms before timing out
15:55:23.429 [cluster-ClusterId{value='54b7e2eb3de4fc41ba90c82b', description='null'}-localhost:27018] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:2, serverValue:24}] to localhost:27018
15:55:23.429 [cluster-ClusterId{value='54b7e2eb3de4fc41ba90c82b', description='null'}-localhost:27017] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:1, serverValue:43}] to localhost:27017
15:55:23.435 [cluster-ClusterId{value='54b7e2eb3de4fc41ba90c82b', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27018, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[2, 8, 0]}, minWireVersion=0, maxWireVersion=3, maxDocumentSize=16777216, roundTripTimeNanos=1880397, setName='repl0', hosts=[localhost:27017, localhost:27018, localhost:27019], passives=[], arbiters=[], primary='localhost:27017', tagSet=TagSet{[Tag{name='dc', value='BsonString{value='pa'}'}, Tag{name='ordinal', value='BsonString{value='two'}'}]}}
15:55:23.435 [cluster-ClusterId{value='54b7e2eb3de4fc41ba90c82b', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27017, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[2, 8, 0]}, minWireVersion=0, maxWireVersion=3, maxDocumentSize=16777216, roundTripTimeNanos=1614667, setName='repl0', hosts=[localhost:27017, localhost:27018, localhost:27019], passives=[], arbiters=[], primary='localhost:27017', tagSet=TagSet{[Tag{name='dc', value='BsonString{value='ny'}'}, Tag{name='ordinal', value='BsonString{value='one'}'}]}}
15:55:23.436 [cluster-ClusterId{value='54b7e2eb3de4fc41ba90c82b', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Discovered cluster type of REPLICA_SET
15:55:23.438 [cluster-ClusterId{value='54b7e2eb3de4fc41ba90c82b', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Adding discovered server localhost:27019 to client view of cluster
15:55:23.439 [cluster-ClusterId{value='54b7e2eb3de4fc41ba90c82b', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Discovered replica set primary localhost:27017
15:55:23.454 [cluster-ClusterId{value='54b7e2eb3de4fc41ba90c82b', description='null'}-localhost:27019] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:3, serverValue:23}] to localhost:27019
15:55:23.459 [cluster-ClusterId{value='54b7e2eb3de4fc41ba90c82b', description='null'}-localhost:27019] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27019, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[2, 8, 0]}, minWireVersion=0, maxWireVersion=3, maxDocumentSize=16777216, roundTripTimeNanos=2047180, setName='repl0', hosts=[localhost:27017, localhost:27018, localhost:27019], passives=[], arbiters=[], primary='localhost:27017', tagSet=TagSet{[]}}
15:55:33.477 [Thread-6] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:5, serverValue:45}] to localhost:27017

            Assignee:
            Unassigned Unassigned
            Reporter:
            jeff.yemin@mongodb.com Jeffrey Yemin
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated:
              Resolved: