Loading...

Type: Build Failure
Resolution: Fixed
Priority: Unknown
Fix Version/s: 4.11
Affects Version/s: None
Component/s: None
Labels:
None

Confidence Status:
None

Assigned Teams:

Python Drivers

Documentation Changes:
Not Needed

Aha! Reference:
None
Tracking Level:
None
Risk Status:
None
Exec Notes:
None
Goal Link:
None
Goal Name(s):
None

Name of Failure:

test.test_crud_unified.TestUnifiedAggregateWriteReadPreference.test_Aggregate_with_out_includes_read_preference_for_5_0_server
test.test_crud_unified.TestUnifiedDbAggregateWriteReadPreference.test_Database-level_aggregate_with_out_includes_read_preference_for_5_0_server

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_replica_set_patch_efe8cc38a6ed9a84536a278e21834432a6590a96_66170830e13ec10007781243_24_04_10_21_44_18?execution=2&sortBy=STATUS&sortDir=ASC

Context of when and why the failure occurred:

Started failing after ~~PYTHON-4299~~.

Stack trace:

 [2024/04/10 20:38:52.944] FAILURE: pymongo.errors.OperationFailure: PlanExecutor error during aggregation :: caused by :: indexes of target collection db0.coll1 changed during processing., full error: {'ok': 0.0, 'errmsg': 'PlanExecutor error during aggregation :: caused by :: indexes of target collection db0.coll1 changed during processing.', 'code': 125, 'codeName': 'CommandFailed', '$clusterTime': {'clusterTime': Timestamp(1712798877, 79), 'signature': {'hash': b'\xca6L\xa8\x14\xb2%\x8c\xf6V\xc0Ym\xcaQ\xc7y\xd5~h', 'keyId': 7356414332411838470}}, 'operationTime': Timestamp(1712798877, 77)} ()
 [2024/04/10 20:38:52.944] self = <test.test_crud_unified.TestUnifiedAggregateWriteReadPreference testMethod=test_Aggregate_with_$out_includes_read_preference_for_5_0+_server>
 [2024/04/10 20:38:52.944]     def test_case(self):
 [2024/04/10 20:38:52.944] >       self.run_scenario(spec)
 [2024/04/10 20:38:52.944] test/unified_format.py:1918: 
 [2024/04/10 20:38:52.944] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
 [2024/04/10 20:38:52.944] test/unified_format.py:1865: in run_scenario
 [2024/04/10 20:38:52.944]     self._run_scenario(spec, uri)
 [2024/04/10 20:38:52.944] test/unified_format.py:1895: in _run_scenario
 [2024/04/10 20:38:52.944]     self.run_operations(spec["operations"])
 [2024/04/10 20:38:52.944] test/unified_format.py:1742: in run_operations
 [2024/04/10 20:38:52.944]     self.run_entity_operation(op)
 [2024/04/10 20:38:52.944] test/unified_format.py:1484: in run_entity_operation
 [2024/04/10 20:38:52.944]     result = cmd(**dict(arguments))
 [2024/04/10 20:38:52.944] test/unified_format.py:1290: in _collectionOperation_aggregate
 [2024/04/10 20:38:52.944]     return self.__entityOperation_aggregate(target, *args, **kwargs)
 [2024/04/10 20:38:52.944] test/unified_format.py:1284: in __entityOperation_aggregate
 [2024/04/10 20:38:52.944]     return list(target.aggregate(*args, **kwargs))
 [2024/04/10 20:38:52.944] pymongo/collection.py:2697: in aggregate
 [2024/04/10 20:38:52.944]     return self._aggregate(
 [2024/04/10 20:38:52.944] pymongo/_csot.py:108: in csot_wrapper
 [2024/04/10 20:38:52.944]     return func(self, *args, **kwargs)
 [2024/04/10 20:38:52.944] pymongo/collection.py:2605: in _aggregate
 [2024/04/10 20:38:52.944]     return self.__database.client._retryable_read(
 [2024/04/10 20:38:52.944] pymongo/mongo_client.py:1529: in _retryable_read
 [2024/04/10 20:38:52.944]     return self._retry_internal(
 [2024/04/10 20:38:52.944] pymongo/_csot.py:108: in csot_wrapper
 [2024/04/10 20:38:52.944]     return func(self, *args, **kwargs)
 [2024/04/10 20:38:52.944] pymongo/mongo_client.py:1496: in _retry_internal
 [2024/04/10 20:38:52.944]     ).run()
 [2024/04/10 20:38:52.944] pymongo/mongo_client.py:2342: in run
 [2024/04/10 20:38:52.944]     return self._read() if self._is_read else self._write()
 [2024/04/10 20:38:52.944] pymongo/mongo_client.py:2480: in _read
 [2024/04/10 20:38:52.944]     return self._func(self._session, self._server, conn, read_pref)  # type: ignore
 [2024/04/10 20:38:52.944] pymongo/aggregation.py:162: in get_cursor
 [2024/04/10 20:38:52.944]     result = conn.command(
 [2024/04/10 20:38:52.944] pymongo/helpers.py:324: in inner
 [2024/04/10 20:38:52.944]     return func(*args, **kwargs)
 [2024/04/10 20:38:52.944] pymongo/pool.py:985: in command
 [2024/04/10 20:38:52.944]     return command(
 [2024/04/10 20:38:52.944] pymongo/network.py:212: in command
 [2024/04/10 20:38:52.944]     helpers._check_command_response(
 [2024/04/10 20:38:52.944] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
 [2024/04/10 20:38:52.944] response = {'$clusterTime': {'clusterTime': Timestamp(1712798877, 79), 'signature': {'hash': b'\xca6L\xa8\x14\xb2%\x8c\xf6V\xc0Ym...cutor error during aggregation :: caused by :: indexes of target collection db0.coll1 changed during processing.', ...}
 [2024/04/10 20:38:52.944] max_wire_version = 26, allowable_errors = None, parse_write_concern_error = True
 [2024/04/10 20:38:52.944]     def _check_command_response(
 [2024/04/10 20:38:52.944]         response: _DocumentOut,
 [2024/04/10 20:38:52.944]         max_wire_version: Optional[int],
 [2024/04/10 20:38:52.944]         allowable_errors: Optional[Container[Union[int, str]]] = None,
 [2024/04/10 20:38:52.944]         parse_write_concern_error: bool = False,
 [2024/04/10 20:38:52.944]     ) -> None:
 [2024/04/10 20:38:52.944]         """Check the response to a command for errors."""
 [2024/04/10 20:38:52.944]         if "ok" not in response:
 [2024/04/10 20:38:52.944]             # Server didn't recognize our message as a command.
 [2024/04/10 20:38:52.944]             raise OperationFailure(
 [2024/04/10 20:38:52.944]                 response.get("$err"),  # type: ignore[arg-type]
 [2024/04/10 20:38:52.944]                 response.get("code"),
 [2024/04/10 20:38:52.944]                 response,
 [2024/04/10 20:38:52.944]                 max_wire_version,
 [2024/04/10 20:38:52.944]             )
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         if parse_write_concern_error and "writeConcernError" in response:
 [2024/04/10 20:38:52.944]             _error = response["writeConcernError"]
 [2024/04/10 20:38:52.944]             _labels = response.get("errorLabels")
 [2024/04/10 20:38:52.944]             if _labels:
 [2024/04/10 20:38:52.944]                 _error.update({"errorLabels": _labels})
 [2024/04/10 20:38:52.944]             _raise_write_concern_error(_error)
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         if response["ok"]:
 [2024/04/10 20:38:52.944]             return
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         details = response
 [2024/04/10 20:38:52.944]         # Mongos returns the error details in a 'raw' object
 [2024/04/10 20:38:52.944]         # for some errors.
 [2024/04/10 20:38:52.944]         if "raw" in response:
 [2024/04/10 20:38:52.944]             for shard in response["raw"].values():
 [2024/04/10 20:38:52.944]                 # Grab the first non-empty raw error from a shard.
 [2024/04/10 20:38:52.944]                 if shard.get("errmsg") and not shard.get("ok"):
 [2024/04/10 20:38:52.944]                     details = shard
 [2024/04/10 20:38:52.944]                     break
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         errmsg = details["errmsg"]
 [2024/04/10 20:38:52.944]         code = details.get("code")
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         # For allowable errors, only check for error messages when the code is not
 [2024/04/10 20:38:52.944]         # included.
 [2024/04/10 20:38:52.944]         if allowable_errors:
 [2024/04/10 20:38:52.944]             if code is not None:
 [2024/04/10 20:38:52.944]                 if code in allowable_errors:
 [2024/04/10 20:38:52.944]                     return
 [2024/04/10 20:38:52.944]             elif errmsg in allowable_errors:
 [2024/04/10 20:38:52.944]                 return
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         # Server is "not primary" or "recovering"
 [2024/04/10 20:38:52.944]         if code is not None:
 [2024/04/10 20:38:52.944]             if code in _NOT_PRIMARY_CODES:
 [2024/04/10 20:38:52.944]                 raise NotPrimaryError(errmsg, response)
 [2024/04/10 20:38:52.944]         elif HelloCompat.LEGACY_ERROR in errmsg or "node is recovering" in errmsg:
 [2024/04/10 20:38:52.944]             raise NotPrimaryError(errmsg, response)
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         # Other errors
 [2024/04/10 20:38:52.944]         # findAndModify with upsert can raise duplicate key error
 [2024/04/10 20:38:52.944]         if code in (11000, 11001, 12582):
 [2024/04/10 20:38:52.944]             raise DuplicateKeyError(errmsg, code, response, max_wire_version)
 [2024/04/10 20:38:52.944]         elif code == 50:
 [2024/04/10 20:38:52.944]             raise ExecutionTimeout(errmsg, code, response, max_wire_version)
 [2024/04/10 20:38:52.944]         elif code == 43:
 [2024/04/10 20:38:52.944]             raise CursorNotFound(errmsg, code, response, max_wire_version)
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944] >       raise OperationFailure(errmsg, code, response, max_wire_version)
 [2024/04/10 20:38:52.944] E       pymongo.errors.OperationFailure: PlanExecutor error during aggregation :: caused by :: indexes of target collection db0.coll1 changed during processing., full error: {'ok': 0.0, 'errmsg': 'PlanExecutor error during aggregation :: caused by :: indexes of target collection db0.coll1 changed during processing.', 'code': 125, 'codeName': 'CommandFailed', '$clusterTime': {'clusterTime': Timestamp(1712798877, 79), 'signature': {'hash': b'\xca6L\xa8\x14\xb2%\x8c\xf6V\xc0Ym\xcaQ\xc7y\xd5~h', 'keyId': 7356414332411838470}}, 'operationTime': Timestamp(1712798877, 77)}
 [2024/04/10 20:38:52.944] pymongo/helpers.py:230: OperationFailure

 [2024/04/10 20:38:52.944] FAILURE: pymongo.errors.OperationFailure: PlanExecutor error during aggregation :: caused by :: indexes of target collection db0.coll1 changed during processing., full error: {'ok': 0.0, 'errmsg': 'PlanExecutor error during aggregation :: caused by :: indexes of target collection db0.coll1 changed during processing.', 'code': 125, 'codeName': 'CommandFailed', '$clusterTime': {'clusterTime': Timestamp(1712798877, 79), 'signature': {'hash': b'\xca6L\xa8\x14\xb2%\x8c\xf6V\xc0Ym\xcaQ\xc7y\xd5~h', 'keyId': 7356414332411838470}}, 'operationTime': Timestamp(1712798877, 77)} ()
 [2024/04/10 20:38:52.944] self = <test.test_crud_unified.TestUnifiedAggregateWriteReadPreference testMethod=test_Aggregate_with_$out_includes_read_preference_for_5_0+_server>
 [2024/04/10 20:38:52.944]     def test_case(self):
 [2024/04/10 20:38:52.944] >       self.run_scenario(spec)
 [2024/04/10 20:38:52.944] test/unified_format.py:1918: 
 [2024/04/10 20:38:52.944] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
 [2024/04/10 20:38:52.944] test/unified_format.py:1865: in run_scenario
 [2024/04/10 20:38:52.944]     self._run_scenario(spec, uri)
 [2024/04/10 20:38:52.944] test/unified_format.py:1895: in _run_scenario
 [2024/04/10 20:38:52.944]     self.run_operations(spec["operations"])
 [2024/04/10 20:38:52.944] test/unified_format.py:1742: in run_operations
 [2024/04/10 20:38:52.944]     self.run_entity_operation(op)
 [2024/04/10 20:38:52.944] test/unified_format.py:1484: in run_entity_operation
 [2024/04/10 20:38:52.944]     result = cmd(**dict(arguments))
 [2024/04/10 20:38:52.944] test/unified_format.py:1290: in _collectionOperation_aggregate
 [2024/04/10 20:38:52.944]     return self.__entityOperation_aggregate(target, *args, **kwargs)
 [2024/04/10 20:38:52.944] test/unified_format.py:1284: in __entityOperation_aggregate
 [2024/04/10 20:38:52.944]     return list(target.aggregate(*args, **kwargs))
 [2024/04/10 20:38:52.944] pymongo/collection.py:2697: in aggregate
 [2024/04/10 20:38:52.944]     return self._aggregate(
 [2024/04/10 20:38:52.944] pymongo/_csot.py:108: in csot_wrapper
 [2024/04/10 20:38:52.944]     return func(self, *args, **kwargs)
 [2024/04/10 20:38:52.944] pymongo/collection.py:2605: in _aggregate
 [2024/04/10 20:38:52.944]     return self.__database.client._retryable_read(
 [2024/04/10 20:38:52.944] pymongo/mongo_client.py:1529: in _retryable_read
 [2024/04/10 20:38:52.944]     return self._retry_internal(
 [2024/04/10 20:38:52.944] pymongo/_csot.py:108: in csot_wrapper
 [2024/04/10 20:38:52.944]     return func(self, *args, **kwargs)
 [2024/04/10 20:38:52.944] pymongo/mongo_client.py:1496: in _retry_internal
 [2024/04/10 20:38:52.944]     ).run()
 [2024/04/10 20:38:52.944] pymongo/mongo_client.py:2342: in run
 [2024/04/10 20:38:52.944]     return self._read() if self._is_read else self._write()
 [2024/04/10 20:38:52.944] pymongo/mongo_client.py:2480: in _read
 [2024/04/10 20:38:52.944]     return self._func(self._session, self._server, conn, read_pref)  # type: ignore
 [2024/04/10 20:38:52.944] pymongo/aggregation.py:162: in get_cursor
 [2024/04/10 20:38:52.944]     result = conn.command(
 [2024/04/10 20:38:52.944] pymongo/helpers.py:324: in inner
 [2024/04/10 20:38:52.944]     return func(*args, **kwargs)
 [2024/04/10 20:38:52.944] pymongo/pool.py:985: in command
 [2024/04/10 20:38:52.944]     return command(
 [2024/04/10 20:38:52.944] pymongo/network.py:212: in command
 [2024/04/10 20:38:52.944]     helpers._check_command_response(
 [2024/04/10 20:38:52.944] _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
 [2024/04/10 20:38:52.944] response = {'$clusterTime': {'clusterTime': Timestamp(1712798877, 79), 'signature': {'hash': b'\xca6L\xa8\x14\xb2%\x8c\xf6V\xc0Ym...cutor error during aggregation :: caused by :: indexes of target collection db0.coll1 changed during processing.', ...}
 [2024/04/10 20:38:52.944] max_wire_version = 26, allowable_errors = None, parse_write_concern_error = True
 [2024/04/10 20:38:52.944]     def _check_command_response(
 [2024/04/10 20:38:52.944]         response: _DocumentOut,
 [2024/04/10 20:38:52.944]         max_wire_version: Optional[int],
 [2024/04/10 20:38:52.944]         allowable_errors: Optional[Container[Union[int, str]]] = None,
 [2024/04/10 20:38:52.944]         parse_write_concern_error: bool = False,
 [2024/04/10 20:38:52.944]     ) -> None:
 [2024/04/10 20:38:52.944]         """Check the response to a command for errors."""
 [2024/04/10 20:38:52.944]         if "ok" not in response:
 [2024/04/10 20:38:52.944]             # Server didn't recognize our message as a command.
 [2024/04/10 20:38:52.944]             raise OperationFailure(
 [2024/04/10 20:38:52.944]                 response.get("$err"),  # type: ignore[arg-type]
 [2024/04/10 20:38:52.944]                 response.get("code"),
 [2024/04/10 20:38:52.944]                 response,
 [2024/04/10 20:38:52.944]                 max_wire_version,
 [2024/04/10 20:38:52.944]             )
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         if parse_write_concern_error and "writeConcernError" in response:
 [2024/04/10 20:38:52.944]             _error = response["writeConcernError"]
 [2024/04/10 20:38:52.944]             _labels = response.get("errorLabels")
 [2024/04/10 20:38:52.944]             if _labels:
 [2024/04/10 20:38:52.944]                 _error.update({"errorLabels": _labels})
 [2024/04/10 20:38:52.944]             _raise_write_concern_error(_error)
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         if response["ok"]:
 [2024/04/10 20:38:52.944]             return
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         details = response
 [2024/04/10 20:38:52.944]         # Mongos returns the error details in a 'raw' object
 [2024/04/10 20:38:52.944]         # for some errors.
 [2024/04/10 20:38:52.944]         if "raw" in response:
 [2024/04/10 20:38:52.944]             for shard in response["raw"].values():
 [2024/04/10 20:38:52.944]                 # Grab the first non-empty raw error from a shard.
 [2024/04/10 20:38:52.944]                 if shard.get("errmsg") and not shard.get("ok"):
 [2024/04/10 20:38:52.944]                     details = shard
 [2024/04/10 20:38:52.944]                     break
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         errmsg = details["errmsg"]
 [2024/04/10 20:38:52.944]         code = details.get("code")
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         # For allowable errors, only check for error messages when the code is not
 [2024/04/10 20:38:52.944]         # included.
 [2024/04/10 20:38:52.944]         if allowable_errors:
 [2024/04/10 20:38:52.944]             if code is not None:
 [2024/04/10 20:38:52.944]                 if code in allowable_errors:
 [2024/04/10 20:38:52.944]                     return
 [2024/04/10 20:38:52.944]             elif errmsg in allowable_errors:
 [2024/04/10 20:38:52.944]                 return
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         # Server is "not primary" or "recovering"
 [2024/04/10 20:38:52.944]         if code is not None:
 [2024/04/10 20:38:52.944]             if code in _NOT_PRIMARY_CODES:
 [2024/04/10 20:38:52.944]                 raise NotPrimaryError(errmsg, response)
 [2024/04/10 20:38:52.944]         elif HelloCompat.LEGACY_ERROR in errmsg or "node is recovering" in errmsg:
 [2024/04/10 20:38:52.944]             raise NotPrimaryError(errmsg, response)
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944]         # Other errors
 [2024/04/10 20:38:52.944]         # findAndModify with upsert can raise duplicate key error
 [2024/04/10 20:38:52.944]         if code in (11000, 11001, 12582):
 [2024/04/10 20:38:52.944]             raise DuplicateKeyError(errmsg, code, response, max_wire_version)
 [2024/04/10 20:38:52.944]         elif code == 50:
 [2024/04/10 20:38:52.944]             raise ExecutionTimeout(errmsg, code, response, max_wire_version)
 [2024/04/10 20:38:52.944]         elif code == 43:
 [2024/04/10 20:38:52.944]             raise CursorNotFound(errmsg, code, response, max_wire_version)
 [2024/04/10 20:38:52.944]     
 [2024/04/10 20:38:52.944] >       raise OperationFailure(errmsg, code, response, max_wire_version)
 [2024/04/10 20:38:52.944] E       pymongo.errors.OperationFailure: PlanExecutor error during aggregation :: caused by :: indexes of target collection db0.coll1 changed during processing., full error: {'ok': 0.0, 'errmsg': 'PlanExecutor error during aggregation :: caused by :: indexes of target collection db0.coll1 changed during processing.', 'code': 125, 'codeName': 'CommandFailed', '$clusterTime': {'clusterTime': Timestamp(1712798877, 79), 'signature': {'hash': b'\xca6L\xa8\x14\xb2%\x8c\xf6V\xc0Ym\xcaQ\xc7y\xd5~h', 'keyId': 7356414332411838470}}, 'operationTime': Timestamp(1712798877, 77)}
 [2024/04/10 20:38:52.944] pymongo/helpers.py:230: OperationFailure

is caused by

SERVER-90047 Aggregation with $out fails on 8.1.0, with replica-set

Closed

is duplicated by

PYTHON-4088 [Build Failure] test_Database-level_aggregate_with__out_includes_read_preference_for_5_0__server

Closed

is fixed by

DRIVERS-2914 Server 8.0+ requires tests for aggregation with $out to not pre-create output collection

Implementing

Details

Description

Name of Failure:

Link to task:

Context of when and why the failure occurred:

Stack trace:

Attachments

Issue Links

Activity

People

Dates