Uploaded image for project: 'Python Driver'
  1. Python Driver
  2. PYTHON-3027

Connecting to a replica set member in the RSGhost state leads to a "connection pool paused" error

    • Type: Icon: Bug Bug
    • Resolution: Fixed
    • Priority: Icon: Unknown Unknown
    • 4.0.1
    • Affects Version/s: 4.0
    • Component/s: Spec Comp
    • Labels:
      None
    • Hide

      DRIVERS-1999:
      Teams should resync the server selection spec tests to pull in the new test added in: https://github.com/mongodb/specifications/commit/537bb198d79d5695e735ad127ec3807689b859dd

      Note that in pymongo (PYTHON-3027) I needed to update the test runner to handle the RSGhost server type. Other drivers may need to do the same:

      diff --git a/test/utils_selection_tests.py b/test/utils_selection_tests.py
      index 0006f6f6..de10312c 100644
      --- a/test/utils_selection_tests.py
      +++ b/test/utils_selection_tests.py
      @@ -63,7 +63,7 @@ def make_server_description(server, hosts):
               return ServerDescription(clean_node(server['address']), Hello({}))
      
           hello_response = {'ok': True, 'hosts': hosts}
      -    if server_type != "Standalone" and server_type != "Mongos":
      +    if server_type not in ("Standalone", "Mongos", "RSGhost", "RSGhost"):
               hello_response['setName'] = "rs"
      
           if server_type == "RSPrimary":
      @@ -72,6 +72,8 @@ def make_server_description(server, hosts):
               hello_response['secondary'] = True
           elif server_type == "Mongos":
               hello_response['msg'] = 'isdbgrid'
      +    elif server_type == "RSGhost":
      +        hello_response['isreplicaset'] = True
      
           hello_response['lastWrite'] = {
               'lastWriteDate': make_last_write_date(server)
      
      Show
      DRIVERS-1999 : Teams should resync the server selection spec tests to pull in the new test added in: https://github.com/mongodb/specifications/commit/537bb198d79d5695e735ad127ec3807689b859dd Note that in pymongo ( PYTHON-3027 ) I needed to update the test runner to handle the RSGhost server type. Other drivers may need to do the same: diff --git a/test/utils_selection_tests.py b/test/utils_selection_tests.py index 0006f6f6..de10312c 100644 --- a/test/utils_selection_tests.py +++ b/test/utils_selection_tests.py @@ -63,7 +63,7 @@ def make_server_description(server, hosts): return ServerDescription(clean_node(server[ 'address' ]), Hello({})) hello_response = { 'ok' : True, 'hosts' : hosts} - if server_type != "Standalone" and server_type != "Mongos" : + if server_type not in ( "Standalone" , "Mongos" , "RSGhost" , "RSGhost" ): hello_response[ 'setName' ] = "rs" if server_type == "RSPrimary" : @@ -72,6 +72,8 @@ def make_server_description(server, hosts): hello_response[ 'secondary' ] = True elif server_type == "Mongos" : hello_response[ 'msg' ] = 'isdbgrid' + elif server_type == "RSGhost" : + hello_response[ 'isreplicaset' ] = True hello_response[ 'lastWrite' ] = { 'lastWriteDate' : make_last_write_date(server)

      Connecting to a replica set member in the RSGhost state without directConnection=True leads to a "connection pool paused" error. For example here are some logs from a server test failure where pymongo fails running the ping command:

      [j0:prim] Got error running ping command: localhost:20000: [Errno 111] Connection refused, Timeout: 0.5s, Topology Description: <TopologyDescription id: 61a575ef1927c1896571d906, topology_type: Unknown, servers: [<ServerDescription ('localhost', 20000) server_type: Unknown, rtt: None, error=AutoReconnect('localhost:20000: [Errno 111] Connection refused')>]>
      ERROR:j0:prim:Got error running ping command: localhost:20000: [Errno 111] Connection refused, Timeout: 0.5s, Topology Description: <TopologyDescription id: 61a575ef1927c1896571d906, topology_type: Unknown, servers: [<ServerDescription ('localhost', 20000) server_type: Unknown, rtt: None, error=AutoReconnect('localhost:20000: [Errno 111] Connection refused')>]>
      [j0:prim] Waiting to connect to mongod on port 20000.
      INFO:j0:prim:Waiting to connect to mongod on port 20000.
      INFO:root:Heartbeat sent to server ('localhost', 20000)
      [j0:prim] {"t":{"$date":"2021-11-30T00:53:03.997+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:51948","uuid":"27885a58-f675-489f-982a-0b370843109a","connectionId":1,"connectionCount":1}}
      INFO:j0:prim:{"t":{"$date":"2021-11-30T00:53:03.997+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:51948","uuid":"27885a58-f675-489f-982a-0b370843109a","connectionId":1,"connectionCount":1}}
      [j0:prim] {"t":{"$date":"2021-11-30T00:53:03.997+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn1","msg":"client metadata","attr":{"remote":"127.0.0.1:51948","client":"conn1","doc":{"driver":{"name":"PyMongo","version":"4.0"},"os":{"type":"Linux","name":"Linux","architecture":"x86_64","version":"5.4.0-1047-aws"},"platform":"CPython 3.9.2.final.0"}}}
      INFO:j0:prim:{"t":{"$date":"2021-11-30T00:53:03.997+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn1","msg":"client metadata","attr":{"remote":"127.0.0.1:51948","client":"conn1","doc":{"driver":{"name":"PyMongo","version":"4.0"},"os":{"type":"Linux","name":"Linux","architecture":"x86_64","version":"5.4.0-1047-aws"},"platform":"CPython 3.9.2.final.0"}}}
      INFO:root:Heartbeat to server ('localhost', 20000) succeeded with reply {'helloOk': True, 'topologyVersion': {'processId': ObjectId('61a575ef005532b901100275'), 'counter': 0}, 'ismaster': False, 'secondary': False, 'info': 'Does not have a valid replica set config', 'isreplicaset': True, 'maxBsonObjectSize': 16777216, 'maxMessageSizeBytes': 48000000, 'maxWriteBatchSize': 100000, 'localTime': datetime.datetime(2021, 11, 30, 0, 53, 3, 997000), 'logicalSessionTimeoutMinutes': 30, 'connectionId': 1, 'minWireVersion': 0, 'maxWireVersion': 15, 'readOnly': False, 'ok': 1.0}
      INFO:root:Heartbeat sent to server ('localhost', 20000)
      [j0:prim] {"t":{"$date":"2021-11-30T00:53:03.998+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:51950","uuid":"5cec4496-5c3a-4d13-8c53-d051c119477c","connectionId":2,"connectionCount":2}}
      INFO:j0:prim:{"t":{"$date":"2021-11-30T00:53:03.998+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:51950","uuid":"5cec4496-5c3a-4d13-8c53-d051c119477c","connectionId":2,"connectionCount":2}}
      [j0:prim] {"t":{"$date":"2021-11-30T00:53:03.998+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn2","msg":"client metadata","attr":{"remote":"127.0.0.1:51950","client":"conn2","doc":{"driver":{"name":"PyMongo","version":"4.0"},"os":{"type":"Linux","name":"Linux","architecture":"x86_64","version":"5.4.0-1047-aws"},"platform":"CPython 3.9.2.final.0"}}}
      INFO:j0:prim:{"t":{"$date":"2021-11-30T00:53:03.998+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn2","msg":"client metadata","attr":{"remote":"127.0.0.1:51950","client":"conn2","doc":{"driver":{"name":"PyMongo","version":"4.0"},"os":{"type":"Linux","name":"Linux","architecture":"x86_64","version":"5.4.0-1047-aws"},"platform":"CPython 3.9.2.final.0"}}}
      INFO:root:Topology with id 61a575f01927c1896571d907 opened
      INFO:root:[pool ('localhost', 20000)] pool created
      INFO:root:Topology description updated for topology id 61a575f01927c1896571d907
      INFO:root:Heartbeat sent to server ('localhost', 20000)
      WARNING:root:No writable servers available.
      WARNING:root:No readable servers available.
      [j0:prim] {"t":{"$date":"2021-11-30T00:53:04.099+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:51952","uuid":"fc906ba0-85c9-424f-b9a2-9df74302e83d","connectionId":3,"connectionCount":3}}
      INFO:j0:prim:{"t":{"$date":"2021-11-30T00:53:04.099+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:51952","uuid":"fc906ba0-85c9-424f-b9a2-9df74302e83d","connectionId":3,"connectionCount":3}}
      [j0:prim] {"t":{"$date":"2021-11-30T00:53:04.099+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn3","msg":"client metadata","attr":{"remote":"127.0.0.1:51952","client":"conn3","doc":{"driver":{"name":"PyMongo","version":"4.0"},"os":{"type":"Linux","name":"Linux","architecture":"x86_64","version":"5.4.0-1047-aws"},"platform":"CPython 3.9.2.final.0"}}}
      INFO:j0:prim:{"t":{"$date":"2021-11-30T00:53:04.099+00:00"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn3","msg":"client metadata","attr":{"remote":"127.0.0.1:51952","client":"conn3","doc":{"driver":{"name":"PyMongo","version":"4.0"},"os":{"type":"Linux","name":"Linux","architecture":"x86_64","version":"5.4.0-1047-aws"},"platform":"CPython 3.9.2.final.0"}}}
      INFO:root:Heartbeat to server ('localhost', 20000) succeeded with reply {'helloOk': True, 'topologyVersion': {'processId': ObjectId('61a575ef005532b901100275'), 'counter': 0}, 'ismaster': False, 'secondary': False, 'info': 'Does not have a valid replica set config', 'isreplicaset': True, 'maxBsonObjectSize': 16777216, 'maxMessageSizeBytes': 48000000, 'maxWriteBatchSize': 100000, 'localTime': datetime.datetime(2021, 11, 30, 0, 53, 4, 99000), 'logicalSessionTimeoutMinutes': 30, 'connectionId': 3, 'minWireVersion': 0, 'maxWireVersion': 15, 'readOnly': False, 'ok': 1.0}
      INFO:root:[pool ('localhost', 20000)] connection check out started
      INFO:root:[pool ('localhost', 20000)] connection check out started
      [j0:prim] Got error running ping command: localhost:20000: connection pool paused
      INFO:root:Heartbeat sent to server ('localhost', 20000)
      ERROR:j0:prim:Got error running ping command: localhost:20000: connection pool paused
      [j0:prim] Waiting to connect to mongod on port 20000.
      INFO:j0:prim:Waiting to connect to mongod on port 20000.
      Collapse
      

      AutoReconnect "connection pool paused" errors are surprising here. Instead I would expect a ServerSelectionTimeoutError.

            Assignee:
            shane.harvey@mongodb.com Shane Harvey
            Reporter:
            shane.harvey@mongodb.com Shane Harvey
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated:
              Resolved: