Test Failure - test.test_client.TestClientPool.test_direct_client_maintains_pool_to_arbiter

XMLWordPrintableJSON

    • Type: Build Failure
    • Resolution: Unresolved
    • Priority: Unknown
    • None
    • Affects Version/s: None
    • Component/s: greenerbuild
    • None
    • None
    • Python Drivers
    • None
    • None
    • None
    • None
    • None
    • None

      Name of Failure:

      test.test_client.TestClientPool.test_direct_client_maintains_pool_to_arbiter

      Link to task:

      https://spruce.mongodb.com/task/mongo_python_driver_disable_test_commands_rhel8_python3.9_test_latest_sharded_cluster_noauth_nossl_sync_async_patch_708ce16961f077b7a03fc97e66ccfaccaa0d847a_67f027b557456500078f30f9_25_04_04_18_41_07?execution=0&sortBy=STATUS&sortDir=ASC

      Context of when and why the failure occurred:

      The arbiter's pool is being closed before the test completes, causing it to fail.

      Stack trace:

       [2025/04/04 12:10:55.011] FAILURE: AssertionError: 0 != 1 ()
 [2025/04/04 12:10:55.011] self = <test.test_client.TestClientPool testMethod=test_direct_client_maintains_pool_to_arbiter>
 [2025/04/04 12:10:55.011]     @client_context.require_connection
 [2025/04/04 12:10:55.011]     def test_direct_client_maintains_pool_to_arbiter(self):
 [2025/04/04 12:10:55.011]         listener = CMAPListener()
 [2025/04/04 12:10:55.011]         c = MockClient.get_mock_client(
 [2025/04/04 12:10:55.011]             standalones=[],
 [2025/04/04 12:10:55.011]             members=["a:1", "b:2", "c:3"],
 [2025/04/04 12:10:55.011]             mongoses=[],
 [2025/04/04 12:10:55.011]             arbiters=["c:3"],  # c:3 is an arbiter.
 [2025/04/04 12:10:55.011]             host="c:3",
 [2025/04/04 12:10:55.011]             directConnection=True,
 [2025/04/04 12:10:55.011]             minPoolSize=1,  # minPoolSize
 [2025/04/04 12:10:55.011]             event_listeners=[listener],
 [2025/04/04 12:10:55.011]         )
 [2025/04/04 12:10:55.011]         self.addCleanup(c.close)
 [2025/04/04 12:10:55.011]     
 [2025/04/04 12:10:55.011]         wait_until(lambda: len(c.nodes) == 1, "connect")
 [2025/04/04 12:10:55.011]         self.assertEqual(c.address, ("c", 3))
 [2025/04/04 12:10:55.011]         # Assert that we create 1 pooled connection.
 [2025/04/04 12:10:55.011]         listener.wait_for_event(monitoring.ConnectionReadyEvent, 1)
 [2025/04/04 12:10:55.011]         self.assertEqual(listener.event_count(monitoring.ConnectionCreatedEvent), 1)
 [2025/04/04 12:10:55.011]         arbiter = c._topology.get_server_by_address(("c", 3))
 [2025/04/04 12:10:55.011] >       self.assertEqual(len(arbiter.pool.conns), 1)
 [2025/04/04 12:10:55.011] E       AssertionError: 0 != 1
 [2025/04/04 12:10:55.011] test/test_client.py:2595: AssertionError

      Debug logs:

      [2025/04/08 09:54:01.355] DEBUG    pymongo.topology:logger.py:108 {"message": "Starting topology monitoring", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}}

[2025/04/08 09:54:01.356] DEBUG    {"message": "Topology description changed", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "previousDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Unknown, servers: []>", "newDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: Unknown, rtt: None>]>"}

[2025/04/08 09:54:01.356] DEBUG    pymongo.topology:logger.py:108 {"message": "Topology description changed", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "previousDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Unknown, servers: []>", "newDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: Unknown, rtt: None>]>"}

[2025/04/08 09:54:01.356] DEBUG    {"message": "Starting server monitoring", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "c", "serverPort": 3}

[2025/04/08 09:54:01.356] DEBUG    pymongo.topology:logger.py:108 {"message": "Starting server monitoring", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "c", "serverPort": 3}

[2025/04/08 09:54:01.356] DEBUG    {"message": "Connection pool created", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "localhost", "serverPort": 27017, "minPoolSize": 1}

[2025/04/08 09:54:01.356] DEBUG    pymongo.connection:logger.py:108 {"message": "Connection pool created", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "localhost", "serverPort": 27017, "minPoolSize": 1}

[2025/04/08 09:54:01.357] DEBUG    {"message": "Connection pool ready", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "localhost", "serverPort": 27017}

[2025/04/08 09:54:01.357] DEBUG    pymongo.connection:logger.py:108 {"message": "Connection pool ready", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "localhost", "serverPort": 27017}

[2025/04/08 09:54:01.357] DEBUG    {"message": "Topology description changed", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "previousDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: Unknown, rtt: None>]>", "newDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: RSArbiter, rtt: 0>]>"}

[2025/04/08 09:54:01.357] DEBUG    pymongo.topology:logger.py:108 {"message": "Topology description changed", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "previousDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: Unknown, rtt: None>]>", "newDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: RSArbiter, rtt: 0>]>"}

[2025/04/08 09:54:01.457] DEBUG    {"message": "Server selection started", "selector": "<function writable_server_selector at 0x7f5a290ef240>", "operation": "testOperation", "topologyDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: RSArbiter, rtt: 0>]>", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}}

[2025/04/08 09:54:01.457] DEBUG    pymongo.serverSelection:logger.py:108 {"message": "Server selection started", "selector": "<function writable_server_selector at 0x7f5a290ef240>", "operation": "testOperation", "topologyDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: RSArbiter, rtt: 0>]>", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}}

[2025/04/08 09:54:01.458] DEBUG    {"message": "Server selection succeeded", "selector": "<function writable_server_selector at 0x7f5a290ef240>", "operation": "testOperation", "topologyDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: RSArbiter, rtt: 0>]>", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "c", "serverPort": 3}

[2025/04/08 09:54:01.458] DEBUG    pymongo.serverSelection:logger.py:108 {"message": "Server selection succeeded", "selector": "<function writable_server_selector at 0x7f5a290ef240>", "operation": "testOperation", "topologyDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: RSArbiter, rtt: 0>]>", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "c", "serverPort": 3}

[2025/04/08 09:54:02.358] DEBUG    pymongo.connection:logger.py:108 {"message": "Connection created", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "localhost", "serverPort": 27017, "driverConnectionId": 1}

[2025/04/08 09:54:02.358] DEBUG    {"message": "Connection created", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "localhost", "serverPort": 27017, "driverConnectionId": 1}

[2025/04/08 09:54:02.359] DEBUG    {"message": "Connection ready", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "localhost", "serverPort": 27017, "driverConnectionId": 1, "durationMS": 0.0006445010000106777}

[2025/04/08 09:54:02.359] DEBUG    pymongo.connection:logger.py:108 {"message": "Connection ready", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "localhost", "serverPort": 27017, "driverConnectionId": 1, "durationMS": 0.0006445010000106777}

[2025/04/08 09:54:02.359] DEBUG    {"message": "Stopped server monitoring", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "c", "serverPort": 3}

[2025/04/08 09:54:02.359] DEBUG    pymongo.topology:logger.py:108 {"message": "Stopped server monitoring", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "c", "serverPort": 3}

[2025/04/08 09:54:02.360] DEBUG    {"message": "Connection closed", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "localhost", "serverPort": 27017, "driverConnectionId": 1, "reason": "Connection pool was closed", "error": "poolClosed"}

[2025/04/08 09:54:02.360] DEBUG    pymongo.connection:logger.py:108 {"message": "Connection closed", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "localhost", "serverPort": 27017, "driverConnectionId": 1, "reason": "Connection pool was closed", "error": "poolClosed"}

[2025/04/08 09:54:02.360] DEBUG    {"message": "Connection pool closed", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "localhost", "serverPort": 27017}

[2025/04/08 09:54:02.360] DEBUG    pymongo.connection:logger.py:108 {"message": "Connection pool closed", "clientId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "serverHost": "localhost", "serverPort": 27017}

[2025/04/08 09:54:02.360] DEBUG    {"message": "Topology description changed", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "previousDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: RSArbiter, rtt: 0>]>", "newDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: Unknown, rtt: None>]>"}

[2025/04/08 09:54:02.360] DEBUG    pymongo.topology:logger.py:108 {"message": "Topology description changed", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}, "previousDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: RSArbiter, rtt: 0>]>", "newDescription": "<TopologyDescription id: 67f554a9ac1f6f8e7cd5fbd2, topology_type: Single, servers: [<ServerDescription ('c', 3) server_type: Unknown, rtt: None>]>"}

[2025/04/08 09:54:02.360] DEBUG    {"message": "Stopped topology monitoring", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}}

[2025/04/08 09:54:02.360] DEBUG    pymongo.topology:logger.py:108 {"message": "Stopped topology monitoring", "topologyId": {"$oid": "67f554a9ac1f6f8e7cd5fbd2"}}

            Assignee:
            Unassigned
            Reporter:
            Noah Stapp
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated: