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

[Build Failure] test_unpin_after_TransientTransactionError_error_on_abort

    • Type: Icon: Build Failure Build Failure
    • Resolution: Unresolved
    • Priority: Icon: Unknown Unknown
    • 4.8
    • 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.9_coverage~coverage_test_latest_sharded_cluster_b185e50e4170c02dabb0bb61a456f2250edb508e_24_01_31_19_57_43?execution=0&sortBy=STATUS&sortDir=ASC

      Context of when and why the failure occurred:

      Introduced in SERVER-82353, see DRIVERS-2816.

      Stack trace:

       [2024/01/31 14:19:42.606] FAILURE: pymongo.errors.OperationFailure: Transaction ba8bad65-336d-41b3-9a0b-bfd56476da76 - Il1bctjvfYRA0JpLUY4Xle2E6bw+KM1YpMr4x52qGgE= -  - :1 was aborted on statement 0 due to: a non-retryable snapshot error :: caused by :: Encountered error from localhost:27219 during a transaction :: caused by :: Database mongos-unpin-db has undergone a catalog change operation at time Timestamp(1706732263, 20) and no longer satisfies the requirements for the current transaction which requires Timestamp(1706732263, 19). Transaction will be aborted., full error: {'ok': 0.0, 'errmsg': 'Transaction ba8bad65-336d-41b3-9a0b-bfd56476da76 - Il1bctjvfYRA0JpLUY4Xle2E6bw+KM1YpMr4x52qGgE= -  - :1 was aborted on statement 0 due to: a non-retryable snapshot error :: caused by :: Encountered error from localhost:27219 during a transaction :: caused by :: Database mongos-unpin-db has undergone a catalog change operation at time Timestamp(1706732263, 20) and no longer satisfies the requirements for the current transaction which requires Timestamp(1706732263, 19). Transaction will be aborted.', 'code': 272, 'codeName': 'MigrationConflict', '$clusterTime': {'clusterTime': Timestamp(1706732264, 3), 'signature': {'hash': b'\xac\xda\xe2\xfd|\x7f\xfc\x9fW\xb9\xa5\xf9\xe0\x81\xe5\xf1\xb2\xd0!\xf5', 'keyId': 7330355163804205080}}, 'operationTime': Timestamp(1706732264, 3), 'errorLabels': ['TransientTransactionError']} ()
       [2024/01/31 14:19:42.606] self = <test.test_transactions_unified.TestUnifiedMongosUnpin testMethod=test_unpin_after_TransientTransactionError_error_on_abort>
       [2024/01/31 14:19:42.606]     def test_case(self):
       [2024/01/31 14:19:42.606] >       self.run_scenario(spec)
       [2024/01/31 14:19:42.606] test/unified_format.py:1770:
       [2024/01/31 14:19:42.606] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
       [2024/01/31 14:19:42.606] test/unified_format.py:1722: in run_scenario
       [2024/01/31 14:19:42.606]     self._run_scenario(spec, uri)
       [2024/01/31 14:19:42.606] test/unified_format.py:1747: in _run_scenario
       [2024/01/31 14:19:42.606]     self.run_operations(spec["operations"])
       [2024/01/31 14:19:42.606] test/unified_format.py:1656: in run_operations
       [2024/01/31 14:19:42.606]     self.run_entity_operation(op)
       [2024/01/31 14:19:42.606] test/unified_format.py:1398: in run_entity_operation
       [2024/01/31 14:19:42.606]     result = cmd(**dict(arguments))
       [2024/01/31 14:19:42.606] pymongo/collection.py:659: in insert_one
       [2024/01/31 14:19:42.606]     self._insert_one(
       [2024/01/31 14:19:42.606] pymongo/collection.py:601: in _insert_one
       [2024/01/31 14:19:42.606]     self.__database.client._retryable_write(acknowledged, _insert_command, session)
       [2024/01/31 14:19:42.606] pymongo/mongo_client.py:1515: in _retryable_write
       [2024/01/31 14:19:42.606]     return self._retry_with_session(retryable, func, s, bulk)
       [2024/01/31 14:19:42.606] pymongo/mongo_client.py:1416: in _retry_with_session
       [2024/01/31 14:19:42.606]     return self._retry_internal(
       [2024/01/31 14:19:42.606] pymongo/_csot.py:107: in csot_wrapper
       [2024/01/31 14:19:42.606]     return func(self, *args, **kwargs)
       [2024/01/31 14:19:42.606] pymongo/mongo_client.py:1446: in _retry_internal
       [2024/01/31 14:19:42.606]     return _ClientConnectionRetryable(
       [2024/01/31 14:19:42.606] pymongo/mongo_client.py:2295: in run
       [2024/01/31 14:19:42.606]     return self._read() if self._is_read else self._write()
       [2024/01/31 14:19:42.606] pymongo/mongo_client.py:2406: in _write
       [2024/01/31 14:19:42.606]     return self._func(self._session, conn, self._retryable)  # type: ignore
       [2024/01/31 14:19:42.606] pymongo/collection.py:589: in _insert_command
       [2024/01/31 14:19:42.606]     result = conn.command(
       [2024/01/31 14:19:42.606] pymongo/helpers.py:322: in inner
       [2024/01/31 14:19:42.606]     return func(*args, **kwargs)
       [2024/01/31 14:19:42.606] pymongo/pool.py:973: in command
       [2024/01/31 14:19:42.606]     return command(
       [2024/01/31 14:19:42.606] pymongo/network.py:196: in command
       [2024/01/31 14:19:42.606]     helpers._check_command_response(
       [2024/01/31 14:19:42.606] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
       [2024/01/31 14:19:42.606] response = {'$clusterTime': {'clusterTime': Timestamp(1706732264, 3), 'signature': {'hash': b'\xac\xda\xe2\xfd|\x7f\xfc\x9fW\xb9\... requirements for the current transaction which requires Timestamp(1706732263, 19). Transaction will be aborted.', ...}
       [2024/01/31 14:19:42.606] max_wire_version = 25, allowable_errors = None
       [2024/01/31 14:19:42.606] parse_write_concern_error = False
       [2024/01/31 14:19:42.606]     def _check_command_response(
       [2024/01/31 14:19:42.606]         response: _DocumentOut,
       [2024/01/31 14:19:42.606]         max_wire_version: Optional[int],
       [2024/01/31 14:19:42.606]         allowable_errors: Optional[Container[Union[int, str]]] = None,
       [2024/01/31 14:19:42.606]         parse_write_concern_error: bool = False,
       [2024/01/31 14:19:42.606]     ) -> None:
       [2024/01/31 14:19:42.606]         """Check the response to a command for errors."""
       [2024/01/31 14:19:42.606]         if "ok" not in response:
       [2024/01/31 14:19:42.606]             # Server didn't recognize our message as a command.
       [2024/01/31 14:19:42.606]             raise OperationFailure(
       [2024/01/31 14:19:42.606]                 response.get("$err"),  # type: ignore[arg-type]
       [2024/01/31 14:19:42.606]                 response.get("code"),
       [2024/01/31 14:19:42.606]                 response,
       [2024/01/31 14:19:42.606]                 max_wire_version,
       [2024/01/31 14:19:42.606]             )
       [2024/01/31 14:19:42.606] 
       [2024/01/31 14:19:42.606]         if parse_write_concern_error and "writeConcernError" in response:
       [2024/01/31 14:19:42.606]             _error = response["writeConcernError"]
       [2024/01/31 14:19:42.606]             _labels = response.get("errorLabels")
       [2024/01/31 14:19:42.606]             if _labels:
       [2024/01/31 14:19:42.606]                 _error.update({"errorLabels": _labels})
       [2024/01/31 14:19:42.606]             _raise_write_concern_error(_error)
       [2024/01/31 14:19:42.606] 
       [2024/01/31 14:19:42.606]         if response["ok"]:
       [2024/01/31 14:19:42.606]             return
       [2024/01/31 14:19:42.606] 
       [2024/01/31 14:19:42.606]         details = response
       [2024/01/31 14:19:42.606]         # Mongos returns the error details in a 'raw' object
       [2024/01/31 14:19:42.606]         # for some errors.
       [2024/01/31 14:19:42.606]         if "raw" in response:
       [2024/01/31 14:19:42.606]             for shard in response["raw"].values():
       [2024/01/31 14:19:42.606]                 # Grab the first non-empty raw error from a shard.
       [2024/01/31 14:19:42.606]                 if shard.get("errmsg") and not shard.get("ok"):
       [2024/01/31 14:19:42.606]                     details = shard
       [2024/01/31 14:19:42.606]                     break
       [2024/01/31 14:19:42.606] 
       [2024/01/31 14:19:42.606]         errmsg = details["errmsg"]
       [2024/01/31 14:19:42.606]         code = details.get("code")
       [2024/01/31 14:19:42.606] 
       [2024/01/31 14:19:42.606]         # For allowable errors, only check for error messages when the code is not
       [2024/01/31 14:19:42.606]         # included.
       [2024/01/31 14:19:42.606]         if allowable_errors:
       [2024/01/31 14:19:42.606]             if code is not None:
       [2024/01/31 14:19:42.606]                 if code in allowable_errors:
       [2024/01/31 14:19:42.606]                     return
       [2024/01/31 14:19:42.606]             elif errmsg in allowable_errors:
       [2024/01/31 14:19:42.606]                 return
       [2024/01/31 14:19:42.606] 
       [2024/01/31 14:19:42.606]         # Server is "not primary" or "recovering"
       [2024/01/31 14:19:42.606]         if code is not None:
       [2024/01/31 14:19:42.606]             if code in _NOT_PRIMARY_CODES:
       [2024/01/31 14:19:42.606]                 raise NotPrimaryError(errmsg, response)
       [2024/01/31 14:19:42.606]         elif HelloCompat.LEGACY_ERROR in errmsg or "node is recovering" in errmsg:
       [2024/01/31 14:19:42.606]             raise NotPrimaryError(errmsg, response)
       [2024/01/31 14:19:42.606] 
       [2024/01/31 14:19:42.606]         # Other errors
       [2024/01/31 14:19:42.606]         # findAndModify with upsert can raise duplicate key error
       [2024/01/31 14:19:42.606]         if code in (11000, 11001, 12582):
       [2024/01/31 14:19:42.606]             raise DuplicateKeyError(errmsg, code, response, max_wire_version)
       [2024/01/31 14:19:42.606]         elif code == 50:
       [2024/01/31 14:19:42.606]             raise ExecutionTimeout(errmsg, code, response, max_wire_version)
       [2024/01/31 14:19:42.606]         elif code == 43:
       [2024/01/31 14:19:42.606]             raise CursorNotFound(errmsg, code, response, max_wire_version)
       [2024/01/31 14:19:42.606] 
       [2024/01/31 14:19:42.606] >       raise OperationFailure(errmsg, code, response, max_wire_version)
       [2024/01/31 14:19:42.606] E       pymongo.errors.OperationFailure: Transaction ba8bad65-336d-41b3-9a0b-bfd56476da76 - Il1bctjvfYRA0JpLUY4Xle2E6bw+KM1YpMr4x52qGgE= -  - :1 was aborted on statement 0 due to: a non-retryable snapshot error :: caused by :: Encountered error from localhost:27219 during a transaction :: caused by :: Database mongos-unpin-db has undergone a catalog change operation at time Timestamp(1706732263, 20) and no longer satisfies the requirements for the current transaction which requires Timestamp(1706732263, 19). Transaction will be aborted., full error: {'ok': 0.0, 'errmsg': 'Transaction ba8bad65-336d-41b3-9a0b-bfd56476da76 - Il1bctjvfYRA0JpLUY4Xle2E6bw+KM1YpMr4x52qGgE= -  - :1 was aborted on statement 0 due to: a non-retryable snapshot error :: caused by :: Encountered error from localhost:27219 during a transaction :: caused by :: Database mongos-unpin-db has undergone a catalog change operation at time Timestamp(1706732263, 20) and no longer satisfies the requirements for the current transaction which requires Timestamp(1706732263, 19). Transaction will be aborted.', 'code': 272, 'codeName': 'MigrationConflict', '$clusterTime': {'clusterTime': Timestamp(1706732264, 3), 'signature': {'hash': b'\xac\xda\xe2\xfd|\x7f\xfc\x9fW\xb9\xa5\xf9\xe0\x81\xe5\xf1\xb2\xd0!\xf5', 'keyId': 7330355163804205080}}, 'operationTime': Timestamp(1706732264, 3), 'errorLabels': ['TransientTransactionError']}
       [2024/01/31 14:19:42.606] pymongo/helpers.py:230: OperationFailure
      

            Assignee:
            Unassigned Unassigned
            Reporter:
            steve.silvester@mongodb.com Steve Silvester
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated: