[SERVER-31178] Change Streams crash: "Invariant failure pin == ErrorCodes::CursorNotFound" Created: 20/Sep/17  Updated: 08/Jan/24  Resolved: 25/Sep/17

Status: Closed
Project: Core Server
Component/s: Replication
Affects Version/s: None
Fix Version/s: 3.6.0-rc0

Type: Bug Priority: Major - P3
Reporter: A. Jesse Jiryu Davis Assignee: Mira Carey
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: Text File mongod.log    
Backwards Compatibility: Fully Compatible
Operating System: ALL
Sprint: Platforms 2017-10-02
Participants:

 Description   

Seen here:

https://evergreen.mongodb.com/task/mongo_python_driver_tests_python_version_ubuntu1204_test_ssl__auth~auth_ssl~ssl_python_version~2.6_coverage~coverage_test_latest_replica_set_patch_6c7d1aa408a04e053af9d2d21581340ea17593e9_59c267f1e3c33124a8000f00_17_09_20_13_06_58

2017-09-20T14:36:56.665+0000 I COMMAND  [conn44] CMD: drop pymongo_test.test_change_stream.TestChangeStream.test_iteration
2017-09-20T14:36:56.665+0000 I STORAGE  [conn44] dropCollection: pymongo_test.test_change_stream.TestChangeStream.test_iteration - renaming to drop-pending collection: pymongo_test.system.drop.1505918216i32t2.test_change_stream.TestChangeStream.test_iteration with drop optime { ts: Timestamp 1505918216000|32, t: 2 }
2017-09-20T14:36:56.691+0000 I REPL     [replication-0] Completing collection drop for pymongo_test.system.drop.1505918216i32t2.test_change_stream.TestChangeStream.test_iteration with drop optime { ts: Timestamp 1505918216000|32, t: 2 } (notification optime: { ts: Timestamp 1505918216000|32, t: 2 })
2017-09-20T14:36:56.701+0000 I COMMAND  [conn44] CMD: drop pymongo_test.test_change_stream.TestChangeStream.test_iteration
2017-09-20T14:36:56.732+0000 F -        [conn44] Invariant failure pin == ErrorCodes::CursorNotFound src/mongo/db/cursor_manager.cpp 178
2017-09-20T14:36:56.732+0000 F -        [conn44] 
 
***aborting after invariant() failure
 
 
2017-09-20T14:36:56.741+0000 F -        [conn44] Got signal: 6 (Aborted).
 
 
 mongod(_ZN5mongo13CursorManager29eraseCursorGlobalIfAuthorizedEPNS_16OperationContextEiPKc+0x48) [0x7f7977f88c38]
 mongod(_ZN5mongo23ServiceEntryPointMongod13handleRequestEPNS_16OperationContextERKNS_7MessageE+0x1AB9) [0x7f7977a7bc19]
 mongod(_ZN5mongo19ServiceStateMachine15_processMessageERNS0_11ThreadGuardE+0xF0) [0x7f7977a83670]
 mongod(_ZN5mongo19ServiceStateMachine15_runNextInGuardERNS0_11ThreadGuardE+0x1B5) [0x7f7977a80665]

I think PyMongo is executing:

    def test_iteration(self):
        with self.coll.watch(batch_size=2) as change_stream:
            num_inserted = 10
            self.coll.insert_many([{} for _ in range(num_inserted)])
            self.coll.drop()
            received = 0
            for change in change_stream:
                received += 1

There may be a session bug in PyMongo right now that uses different lsids for the aggregate and getMore commands - this might or might not be related.

mongod.log attached



 Comments   
Comment by Githook User [ 25/Sep/17 ]

Author:

{'email': 'jcarey@argv.me', 'name': 'Jason Carey', 'username': 'hanumantmk'}

Message: SERVER-31178 Bad invariant in cursor manager

pinCursor can return unauthorized, expanding scope of invariant
Branch: master
https://github.com/mongodb/mongo/commit/829c1d6afe8177433192e6af84bf4536c330caee

Comment by A. Jesse Jiryu Davis [ 21/Sep/17 ]

You can also do this by sending legacy OP_KILLCURSORS with the change stream's cursorId, when auth is enabled. (Of course we shouldn't use OP_KILLCURSORS. Every PyMongo bug seems to also trigger a server bug.....)

 mongod(_ZN5mongo15invariantFailedEPKcS1_j+0x2E6) [0x101fe3946]
 mongod(_ZN5mongo12_GLOBAL__N_119GlobalCursorIdCache11eraseCursorEPNS_16OperationContextExb+0x535) [0x100f26165]
 mongod(_ZN5mongo13CursorManager29eraseCursorGlobalIfAuthorizedEPNS_16OperationContextEiPKc+0x4C) [0x100f25bcc]
 mongod(_ZN5mongo23ServiceEntryPointMongod13handleRequestEPNS_16OperationContextERKNS_7MessageE+0x17CD) [0x100c8e55d]

Comment by Tess Avitabile (Inactive) [ 20/Sep/17 ]

mira.carey@mongodb.com, I am investigating if there is a bug here related to change streams and collection drops.

Generated at Thu Feb 08 04:26:14 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.