[SERVER-1721] cursor error on concurrent requests Created: 02/Sep/10  Updated: 12/Jul/16  Resolved: 08/Nov/10

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: 1.7.3

Type: Bug Priority: Major - P3
Reporter: Kristina Chodorow (Inactive) Assignee: Eliot Horowitz (Inactive)
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

db version v1.7.0-pre-, pdfile version 4.5
Thu Sep 2 16:35:31 git version: b6321840dd39f96febef4e82de70dc2bb71075e5


Attachments: File sample.php    
Operating System: ALL
Participants:

 Description   

I'm running the attached PHP script (drop collection, add 1000 elements, findOne) through ab with:

$ ab -c 5 -n 1000 http://localhost/sample.php

It causes a lot of errors that look like this in the db log:

Thu Sep 2 16:30:24 [conn546] CMD: drop testDB.testColl
Thu Sep 2 16:30:24 [conn536] CMD: drop testDB.testColl
Thu Sep 2 16:30:24 [conn546] building new index on

{ _id: 1 }

for testDB.testColl
Thu Sep 2 16:30:24 [conn546] done for 0 records 0secs
Thu Sep 2 16:30:24 [conn548] CMD: drop testDB.testColl
Thu Sep 2 16:30:24 [conn536] Assertion: 13338:cursor dropped during query
0x8153a5a 0x821084d 0x830f838 0x830fecd 0x8314973 0x831a7ea 0x831b203 0x831b97d 0x81fe5e7 0x82e0677 0x83ddade 0x81a1ef8 0x42ec1d 0x2e696e 0x6c6a4e
./mongod(_ZN5mongo11msgassertedEiPKc+0x20a) [0x8153a5a]
./mongod(_ZN5mongo11UserQueryOp16recoverFromYieldEv+0xdd) [0x821084d]
./mongod(_ZN5mongo12QueryPlanSet6Runner16recoverFromYieldERNS_7QueryOpE+0x38) [0x830f838]
./mongod(_ZN5mongo12QueryPlanSet6Runner8mayYieldERKSt6vectorIN5boost10shared_ptrINS_7QueryOpEEESaIS6_EE+0xcd) [0x830fecd]
./mongod(_ZN5mongo12QueryPlanSet6Runner3runEv+0x8a3) [0x8314973]
./mongod(_ZN5mongo12QueryPlanSet5runOpERNS_7QueryOpE+0x21a) [0x831a7ea]
./mongod(_ZN5mongo16MultiPlanScanner9runOpOnceERNS_7QueryOpE+0x6b3) [0x831b203]
./mongod(_ZN5mongo16MultiPlanScanner5runOpERNS_7QueryOpE+0x2d) [0x831b97d]
./mongod(ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1+0xa17) [0x81fe5e7]
./mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_8SockAddrE+0x1447) [0x82e0677]
./mongod(_ZN5mongo10connThreadEPNS_13MessagingPortE+0x2ee) [0x83ddade]
./mongod(_ZN5boost6detail11thread_dataINS_3_bi6bind_tIvPFvPN5mongo13MessagingPortEENS2_5list1INS2_5valueIS6_EEEEEEE3runEv+0x18) [0x81a1ef8]
/usr/lib/libboost_thread-mt.so.1.38.0(thread_proxy+0x5d) [0x42ec1d]
/lib/tls/i686/cmov/libpthread.so.0(+0x596e) [0x2e696e]
/lib/tls/i686/cmov/libc.so.6(clone+0x5e) [0x6c6a4e]
Thu Sep 2 16:30:24 [conn536] assertion 13338 cursor dropped during query ns:testDB.testColl query:

{ a: 500 }

Thu Sep 2 16:30:24 [conn536] ntoskip:0 ntoreturn:-1
Thu Sep 2 16:30:24 [conn548] building new index on

{ _id: 1 }

for testDB.testColl
Thu Sep 2 16:30:24 [conn548] done for 0 records 0secs

The query is a findOne, so it seems weird that the cursor would be dropped during it.



 Comments   
Comment by Kristina Chodorow (Inactive) [ 09/Nov/10 ]

Nevermind, totally fixed. My bad.

Comment by Kristina Chodorow (Inactive) [ 09/Nov/10 ]

It's not really "fixed", it's just back to the original error...

Comment by auto [ 08/Nov/10 ]

Author:

{'login': 'erh', 'name': 'Eliot Horowitz', 'email': 'eliot@10gen.com'}

Message: fix cursor usage when possible deleted
SERVER-1721 SERVER-2075
/mongodb/mongo/commit/9bfffc98e6a13954a1699ea0ab58b7feefb9939f

Comment by Kristina Chodorow (Inactive) [ 04/Nov/10 ]

This is now crashing the server:

Thu Nov 4 11:00:34 [conn435] end connection 127.0.0.1:54540
Thu Nov 4 11:00:34 [conn433] end connection 127.0.0.1:54538
Thu Nov 4 11:00:34 [initandlisten] connection accepted from 127.0.0.1:54545 #441
Thu Nov 4 11:00:34 [conn441] CMD: drop testDB.testColl
mongod: /usr/include/boost/shared_ptr.hpp:419: T* boost::shared_ptr< <template-parameter-1-1> >::operator->() const [with T = mongo::Cursor]: Assertion `px != 0' failed.
Thu Nov 4 11:00:34 Got signal: 6 (Aborted).

Thu Nov 4 11:00:34 Backtrace:
0x83f9cd0 0xd8c400 0xd8c422 0x27c651 0x27fa82 0x275718 0x821b568 0x821b6ee 0x83215a8 0x8327df2 0x832ab8a 0x832b429 0x832ba0d 0x8209ebf 0x82f3a15 0x83fadf5 0x81a8d48 0x78cc1d 0xe7b96e 0x31fa4e
./mongod(_ZN5mongo10abruptQuitEi+0x400) [0x83f9cd0]
[0xd8c400]
[0xd8c422]
/lib/tls/i686/cmov/libc.so.6(gsignal+0x51) [0x27c651]
/lib/tls/i686/cmov/libc.so.6(abort+0x182) [0x27fa82]
/lib/tls/i686/cmov/libc.so.6(__assert_fail+0xf8) [0x275718]
./mongod() [0x821b568]
./mongod(_ZN5mongo11UserQueryOp4nextEv+0x17e) [0x821b6ee]
./mongod(_ZN5mongo12QueryPlanSet6Runner6nextOpERNS_7QueryOpE+0x38) [0x83215a8]
./mongod(_ZN5mongo12QueryPlanSet6Runner3runEv+0xa32) [0x8327df2]
./mongod(_ZN5mongo12QueryPlanSet5runOpERNS_7QueryOpE+0x21a) [0x832ab8a]
./mongod(_ZN5mongo16MultiPlanScanner9runOpOnceERNS_7QueryOpE+0x499) [0x832b429]
./mongod(_ZN5mongo16MultiPlanScanner5runOpERNS_7QueryOpE+0x2d) [0x832ba0d]
./mongod(ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1+0xa0f) [0x8209ebf]
./mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_8SockAddrE+0x1425) [0x82f3a15]
./mongod(_ZN5mongo10connThreadEPNS_13MessagingPortE+0x2c5) [0x83fadf5]
./mongod(_ZN5boost6detail11thread_dataINS_3_bi6bind_tIvPFvPN5mongo13MessagingPortEENS2_5list1INS2_5valueIS6_EEEEEEE3runEv+0x18) [0x81a8d48]
/usr/lib/libboost_thread-mt.so.1.38.0(thread_proxy+0x5d) [0x78cc1d]
/lib/tls/i686/cmov/libpthread.so.0(+0x596e) [0xe7b96e]
/lib/tls/i686/cmov/libc.so.6(clone+0x5e) [0x31fa4e]

Thu Nov 4 11:00:34 dbexit:
Thu Nov 4 11:00:34 [conn436] shutdown: going to close listening sockets...
Thu Nov 4 11:00:34 [conn436] closing listening socket: 5
Thu Nov 4 11:00:34 [conn436] closing listening socket: 6
Thu Nov 4 11:00:34 [conn436] closing listening socket: 7
Thu Nov 4 11:00:34 [conn436] closing listening socket: 8
Thu Nov 4 11:00:34 [conn436] removing socket file: /tmp/mongodb-27017.sock
Thu Nov 4 11:00:34 [conn436] removing socket file: /tmp/mongodb-28017.sock
Thu Nov 4 11:00:34 [conn436] shutdown: going to flush oplog...
Thu Nov 4 11:00:34 [conn436] shutdown: going to close sockets...
Thu Nov 4 11:00:34 [conn436] shutdown: waiting for fs preallocator...
Thu Nov 4 11:00:34 [conn436] shutdown: closing all files...
Thu Nov 4 11:00:34 [conn441] got request after shutdown()
Thu Nov 4 11:00:34 closeAllFiles() finished
Thu Nov 4 11:00:34 [conn436] shutdown: removing fs lock...
Thu Nov 4 11:00:34 dbexit: really exiting now
Thu Nov 4 11:00:34 ERROR: Client::~Client _context should be null but is not; client:conn

Comment by Eliot Horowitz (Inactive) [ 03/Sep/10 ]

Its happening because even though its a findOne, we yield every X objects scanned. So since there isn't an index, we have to do a table scan.

Not sure if there is much we can do here....

Maybe make the error nicer?

Generated at Thu Feb 08 02:57:50 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.