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

::test_unpin_after_TransientTransactionError_error_on_abort failure

    • Type: Icon: Build Failure Build Failure
    • Resolution: Duplicate
    • Priority: Icon: Unknown Unknown
    • None
    • Affects Version/s: None
    • Component/s: None
    • Labels:
      None
    • Python Drivers

      Name of Failure:

      test.test_transactions_unified.TestUnifiedMongosUnpin.test_unpin_after_TransientTransactionError_error_on_abort

      Link to task:

      https://spruce.mongodb.com/task/mongo_python_driver_tests_python_version_rhel8_test_ssl__platform~rhel8_auth_ssl~auth_ssl_python_version~3.10_coverage~coverage_test_latest_sharded_cluster_patch_0f7e1b011024b19b5ec755cc3302032bc5a36008_65c0e80a30661505c769d14c_24_02_05_13_52_11/tests?execution=1&sortBy=STATUS&sortDir=ASC

      Context of when and why the failure occurred:

      Not quite sure. Looks like the report is about database unpinning?

      Stack trace:

       

       [2024/02/05 11:17:49.104] FAILURE: pymongo.errors.OperationFailure: Transaction 878ed51f-68d4-4d85-8aaa-bc6595b39d72 - Il1bctjvfYRA0JpLUY4Xle2E6bw+KM1YpMr4x52qGgE= -  - :1 was aborted on statement 0 due to: a non-retryable snapshot error :: caused by :: Encountered error from localhost:27217 during a transaction :: caused by :: Database mongos-unpin-db has undergone a catalog change operation at time Timestamp(1707149740, 28) and no longer satisfies the requirements for the current transaction which requires Timestamp(1707149740, 27). Transaction will be aborted., full error: {'ok': 0.0, 'errmsg': 'Transaction 878ed51f-68d4-4d85-8aaa-bc6595b39d72 - Il1bctjvfYRA0JpLUY4Xle2E6bw+KM1YpMr4x52qGgE= -  - :1 was aborted on statement 0 due to: a non-retryable snapshot error :: caused by :: Encountered error from localhost:27217 during a transaction :: caused by :: Database mongos-unpin-db has undergone a catalog change operation at time Timestamp(1707149740, 28) and no longer satisfies the requirements for the current transaction which requires Timestamp(1707149740, 27). Transaction will be aborted.', 'code': 272, 'codeName': 'MigrationConflict', '$clusterTime': {'clusterTime': Timestamp(1707149741, 1), 'signature': {'hash': b'\xda\xca:\xd2\x8c=\xd8\xbe0\xd7\xd4h\xe3_\x0cm\x88\x80\xcdk', 'keyId': 7332148407139565592}}, 'operationTime': Timestamp(1707149741, 1), 'errorLabels': ['TransientTransactionError']} ()
       [2024/02/05 11:17:49.104] self = <test.test_transactions_unified.TestUnifiedMongosUnpin testMethod=test_unpin_after_TransientTransactionError_error_on_abort>
       [2024/02/05 11:17:49.104]     def test_case(self):
       [2024/02/05 11:17:49.104] >       self.run_scenario(spec)
       [2024/02/05 11:17:49.104] test/unified_format.py:1781:
       [2024/02/05 11:17:49.104] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
       [2024/02/05 11:17:49.104] test/unified_format.py:1733: in run_scenario
       [2024/02/05 11:17:49.104]     self._run_scenario(spec, uri)
       [2024/02/05 11:17:49.104] test/unified_format.py:1758: in _run_scenario
       [2024/02/05 11:17:49.104]     self.run_operations(spec["operations"])
       [2024/02/05 11:17:49.104] test/unified_format.py:1667: in run_operations
       [2024/02/05 11:17:49.104]     self.run_entity_operation(op)
       [2024/02/05 11:17:49.104] test/unified_format.py:1409: in run_entity_operation
       [2024/02/05 11:17:49.104]     result = cmd(**dict(arguments))
       [2024/02/05 11:17:49.104] pymongo/collection.py:659: in insert_one
       [2024/02/05 11:17:49.104]     self._insert_one(
       [2024/02/05 11:17:49.104] pymongo/collection.py:601: in _insert_one
       [2024/02/05 11:17:49.104]     self.__database.client._retryable_write(acknowledged, _insert_command, session)
       [2024/02/05 11:17:49.104] pymongo/mongo_client.py:1515: in _retryable_write
       [2024/02/05 11:17:49.104]     return self._retry_with_session(retryable, func, s, bulk)
       [2024/02/05 11:17:49.104] pymongo/mongo_client.py:1416: in _retry_with_session
       [2024/02/05 11:17:49.104]     return self._retry_internal(
       [2024/02/05 11:17:49.104] pymongo/_csot.py:107: in csot_wrapper
       [2024/02/05 11:17:49.104]     return func(self, *args, **kwargs)
       [2024/02/05 11:17:49.104] pymongo/mongo_client.py:1455: in _retry_internal
       [2024/02/05 11:17:49.104]     ).run()
       [2024/02/05 11:17:49.104] pymongo/mongo_client.py:2295: in run
       [2024/02/05 11:17:49.104]     return self._read() if self._is_read else self._write()
       [2024/02/05 11:17:49.104] pymongo/mongo_client.py:2406: in _write
       [2024/02/05 11:17:49.104]     return self._func(self._session, conn, self._retryable)  # type: ignore
       [2024/02/05 11:17:49.104] pymongo/collection.py:589: in _insert_command
       [2024/02/05 11:17:49.104]     result = conn.command(
       [2024/02/05 11:17:49.104] pymongo/helpers.py:322: in inner
       [2024/02/05 11:17:49.104]     return func(*args, **kwargs)
       [2024/02/05 11:17:49.104] pymongo/pool.py:973: in command
       [2024/02/05 11:17:49.104]     return command(
       [2024/02/05 11:17:49.104] pymongo/network.py:196: in command
       [2024/02/05 11:17:49.104]     helpers._check_command_response(
       [2024/02/05 11:17:49.104] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
       [2024/02/05 11:17:49.104] response = {'$clusterTime': {'clusterTime': Timestamp(1707149741, 1), 'signature': {'hash': b'\xda\xca:\xd2\x8c=\xd8\xbe0\xd7\xd4... requirements for the current transaction which requires Timestamp(1707149740, 27). Transaction will be aborted.', ...}
       [2024/02/05 11:17:49.104] max_wire_version = 25, allowable_errors = None
       [2024/02/05 11:17:49.104] parse_write_concern_error = False
       [2024/02/05 11:17:49.104]     def _check_command_response(
       [2024/02/05 11:17:49.104]         response: _DocumentOut,
       [2024/02/05 11:17:49.104]         max_wire_version: Optional[int],
       [2024/02/05 11:17:49.104]         allowable_errors: Optional[Container[Union[int, str]]] = None,
       [2024/02/05 11:17:49.104]         parse_write_concern_error: bool = False,
       [2024/02/05 11:17:49.104]     ) -> None:
       [2024/02/05 11:17:49.104]         """Check the response to a command for errors."""
       [2024/02/05 11:17:49.104]         if "ok" not in response:
       [2024/02/05 11:17:49.104]             # Server didn't recognize our message as a command.
       [2024/02/05 11:17:49.104]             raise OperationFailure(
       [2024/02/05 11:17:49.104]                 response.get("$err"),  # type: ignore[arg-type]
       [2024/02/05 11:17:49.104]                 response.get("code"),
       [2024/02/05 11:17:49.104]                 response,
       [2024/02/05 11:17:49.104]                 max_wire_version,
       [2024/02/05 11:17:49.104]             )
       [2024/02/05 11:17:49.104] 
       [2024/02/05 11:17:49.104]         if parse_write_concern_error and "writeConcernError" in response:
       [2024/02/05 11:17:49.104]             _error = response["writeConcernError"]
       [2024/02/05 11:17:49.104]             _labels = response.get("errorLabels")
       [2024/02/05 11:17:49.104]             if _labels:
       [2024/02/05 11:17:49.104]                 _error.update({"errorLabels": _labels})
       [2024/02/05 11:17:49.104]             _raise_write_concern_error(_error)
       [2024/02/05 11:17:49.104] 
       [2024/02/05 11:17:49.104]         if response["ok"]:
       [2024/02/05 11:17:49.104]             return
       [2024/02/05 11:17:49.104] 
       [2024/02/05 11:17:49.104]         details = response
       [2024/02/05 11:17:49.104]         # Mongos returns the error details in a 'raw' object
       [2024/02/05 11:17:49.104]         # for some errors.
       [2024/02/05 11:17:49.104]         if "raw" in response:
       [2024/02/05 11:17:49.104]             for shard in response["raw"].values():
       [2024/02/05 11:17:49.104]                 # Grab the first non-empty raw error from a shard.
       [2024/02/05 11:17:49.104]                 if shard.get("errmsg") and not shard.get("ok"):
       [2024/02/05 11:17:49.104]                     details = shard
       [2024/02/05 11:17:49.104]                     break
       [2024/02/05 11:17:49.104] 
       [2024/02/05 11:17:49.104]         errmsg = details["errmsg"]
       [2024/02/05 11:17:49.104]         code = details.get("code")
       [2024/02/05 11:17:49.104] 
       [2024/02/05 11:17:49.104]         # For allowable errors, only check for error messages when the code is not
       [2024/02/05 11:17:49.104]         # included.
       [2024/02/05 11:17:49.104]         if allowable_errors:
       [2024/02/05 11:17:49.104]             if code is not None:
       [2024/02/05 11:17:49.104]                 if code in allowable_errors:
       [2024/02/05 11:17:49.104]                     return
       [2024/02/05 11:17:49.104]             elif errmsg in allowable_errors:
       [2024/02/05 11:17:49.104]                 return
       [2024/02/05 11:17:49.104] 
       [2024/02/05 11:17:49.104]         # Server is "not primary" or "recovering"
       [2024/02/05 11:17:49.104]         if code is not None:
       [2024/02/05 11:17:49.104]             if code in _NOT_PRIMARY_CODES:
       [2024/02/05 11:17:49.104]                 raise NotPrimaryError(errmsg, response)
       [2024/02/05 11:17:49.104]         elif HelloCompat.LEGACY_ERROR in errmsg or "node is recovering" in errmsg:
       [2024/02/05 11:17:49.104]             raise NotPrimaryError(errmsg, response)
       [2024/02/05 11:17:49.104] 
       [2024/02/05 11:17:49.104]         # Other errors
       [2024/02/05 11:17:49.104]         # findAndModify with upsert can raise duplicate key error
       [2024/02/05 11:17:49.104]         if code in (11000, 11001, 12582):
       [2024/02/05 11:17:49.104]             raise DuplicateKeyError(errmsg, code, response, max_wire_version)
       [2024/02/05 11:17:49.104]         elif code == 50:
       [2024/02/05 11:17:49.104]             raise ExecutionTimeout(errmsg, code, response, max_wire_version)
       [2024/02/05 11:17:49.104]         elif code == 43:
       [2024/02/05 11:17:49.104]             raise CursorNotFound(errmsg, code, response, max_wire_version)
       [2024/02/05 11:17:49.104] 
       [2024/02/05 11:17:49.104] >       raise OperationFailure(errmsg, code, response, max_wire_version)
       [2024/02/05 11:17:49.104] E       pymongo.errors.OperationFailure: Transaction 878ed51f-68d4-4d85-8aaa-bc6595b39d72 - Il1bctjvfYRA0JpLUY4Xle2E6bw+KM1YpMr4x52qGgE= -  - :1 was aborted on statement 0 due to: a non-retryable snapshot error :: caused by :: Encountered error from localhost:27217 during a transaction :: caused by :: Database mongos-unpin-db has undergone a catalog change operation at time Timestamp(1707149740, 28) and no longer satisfies the requirements for the current transaction which requires Timestamp(1707149740, 27). Transaction will be aborted., full error: {'ok': 0.0, 'errmsg': 'Transaction 878ed51f-68d4-4d85-8aaa-bc6595b39d72 - Il1bctjvfYRA0JpLUY4Xle2E6bw+KM1YpMr4x52qGgE= -  - :1 was aborted on statement 0 due to: a non-retryable snapshot error :: caused by :: Encountered error from localhost:27217 during a transaction :: caused by :: Database mongos-unpin-db has undergone a catalog change operation at time Timestamp(1707149740, 28) and no longer satisfies the requirements for the current transaction which requires Timestamp(1707149740, 27). Transaction will be aborted.', 'code': 272, 'codeName': 'MigrationConflict', '$clusterTime': {'clusterTime': Timestamp(1707149741, 1), 'signature': {'hash': b'\xda\xca:\xd2\x8c=\xd8\xbe0\xd7\xd4h\xe3_\x0cm\x88\x80\xcdk', 'keyId': 7332148407139565592}}, 'operationTime': Timestamp(1707149741, 1), 'errorLabels': ['TransientTransactionError']}
       [2024/02/05 11:17:49.104] pymongo/helpers.py:230: OperationFailure
      
           

       

       

            Assignee:
            Unassigned Unassigned
            Reporter:
            jib.adegunloye@mongodb.com Jib Adegunloye
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated:
              Resolved: