Closed
Bug 463988
Opened 16 years ago
Closed 16 years ago
Gloda: mozStorageConnection holds lock while calling outside its module leading to PR_ASSERT(lock->owner != me) on shutting down while indexing is active
Categories
(Toolkit :: Storage, defect, P2)
Toolkit
Storage
Tracking
()
RESOLVED
FIXED
mozilla1.9.2a1
People
(Reporter: rain1, Assigned: asuth)
References
Details
(Keywords: fixed1.9.1)
Attachments
(1 file)
Another crash on shutdown, this time in nsAutoLock. Stack at the time of the crash: > ntdll.dll!_DbgBreakPoint@0() nspr4.dll!PR_Assert(const char * s=0x10041014, const char * file=0x10040f40, int ln=238) Line 550 C nspr4.dll!PR_Lock(PRLock * lock=0x04d4bfb8) Line 238 + 0x21 bytes C xpcom_core.dll!nsAutoLock::nsAutoLock(PRLock * aLock=0x04d4bfb8) Line 219 + 0xd bytes C++ strgcmps.dll!mozStorageConnection::getAsyncExecutionTarget() Line 941 C++ strgcmps.dll!NS_executeAsync(nsTArray<sqlite3_stmt *> & aStatements={...}, mozStorageConnection * aConnection=0x04ce91b8, mozIStorageStatementCallback * aCallback=0x07c51290, mozIStoragePendingStatement * * _stmt=0x0016bc6c) Line 639 + 0xc bytes C++ strgcmps.dll!mozStorageConnection::ExecuteAsync(mozIStorageStatement * * aStatements=0x0016bab8, unsigned int aNumStatements=1, mozIStorageStatementCallback * aCallback=0x07c51290, mozIStoragePendingStatement * * _stmt=0x0016bc6c) Line 410 + 0x15 bytes C++ strgcmps.dll!mozStorageStatement::ExecuteAsync(mozIStorageStatementCallback * aCallback=0x07c51290, mozIStoragePendingStatement * * _stmt=0x0016bc6c) Line 582 C++ xpcom_core.dll!NS_InvokeByIndex_P(nsISupports * that=0x00000022, unsigned int methodIndex=2, unsigned int paramCount=1490012, nsXPTCVariant * params=0x0512d600) Line 102 C++ xpc3250.dll!XPCWrappedNative::CallMethod(XPCCallContext & ccx={...}, XPCWrappedNative::CallMode mode=CALL_METHOD) Line 2405 + 0x21 bytes C++ xpc3250.dll!XPC_WN_CallMethod(JSContext * cx=0x00d36b88, JSObject * obj=0x04902200, unsigned int argc=1, long * argv=0x04be9078, long * vp=0x0016bf28) Line 1477 + 0xe bytes C++ js3250.dll!js_Invoke(JSContext * cx=0x00d36b88, unsigned int argc=1, long * vp=0x04be9070, unsigned int flags=2) Line 1306 + 0x1a bytes C++ js3250.dll!js_Interpret(JSContext * cx=0x00d36b88) Line 5147 + 0x16 bytes C++ js3250.dll!SendToGenerator(JSContext * cx=0x00d36b88, JSGeneratorOp op=JSGENOP_SEND, JSObject * obj=0x04913200, JSGenerator * gen=0x08294578, long arg=76627776) Line 874 + 0x9 bytes C++ js3250.dll!generator_op(JSContext * cx=0x00d36b88, JSGeneratorOp op=JSGENOP_SEND, long * vp=0x0849b704, unsigned int argc=1) Line 987 + 0x19 bytes C++ js3250.dll!generator_send(JSContext * cx=0x00d36b88, unsigned int argc=1, long * vp=0x0849b704) Line 996 + 0x13 bytes C++ js3250.dll!js_Interpret(JSContext * cx=0x00d36b88) Line 5130 + 0x17 bytes C++ js3250.dll!SendToGenerator(JSContext * cx=0x00d36b88, JSGeneratorOp op=JSGENOP_SEND, JSObject * obj=0x071a3140, JSGenerator * gen=0x0849b678, long arg=76627776) Line 874 + 0x9 bytes C++ js3250.dll!generator_op(JSContext * cx=0x00d36b88, JSGeneratorOp op=JSGENOP_SEND, long * vp=0x04be9300, unsigned int argc=1) Line 987 + 0x19 bytes C++ js3250.dll!generator_send(JSContext * cx=0x00d36b88, unsigned int argc=1, long * vp=0x04be9300) Line 996 + 0x13 bytes C++ js3250.dll!js_Interpret(JSContext * cx=0x00d36b88) Line 5130 + 0x17 bytes C++ js3250.dll!js_Invoke(JSContext * cx=0x00d36b88, unsigned int argc=3, long * vp=0x04be9454, unsigned int flags=0) Line 1324 + 0x9 bytes C++ xpc3250.dll!nsXPCWrappedJSClass::CallMethod(nsXPCWrappedJS * wrapper=0x0807bda8, unsigned short methodIndex=4, const XPTMethodDescriptor * info=0x03bdaef8, nsXPTCMiniVariant * nativeParams=0x0016ddcc) Line 1549 + 0x1b bytes C++ xpc3250.dll!nsXPCWrappedJS::CallMethod(unsigned short methodIndex=4, const XPTMethodDescriptor * info=0x03bdaef8, nsXPTCMiniVariant * params=0x0016ddcc) Line 564 C++ xpcom_core.dll!PrepareAndDispatch(nsXPTCStubBase * self=0x07c4f2a0, unsigned int methodIndex=4, unsigned int * args=0x0016de8c, unsigned int * stackBytesToPop=0x0016de7c) Line 114 + 0x21 bytes C++ xpcom_core.dll!SharedStub() Line 142 C++ mime.dll!nsStreamConverter::OnStopRequest(nsIRequest * request=0x06255538, nsISupports * ctxt=0x02b99d64, unsigned int status=0) Line 1078 C++ msgimap.dll!nsImapCacheStreamListener::OnStopRequest(nsIRequest * request=0x060cdad8, nsISupports * aCtxt=0x02b99d64, unsigned int aStatus=0) Line 8003 + 0x30 bytes C++ necko.dll!nsInputStreamPump::OnStateStop() Line 577 C++ necko.dll!nsInputStreamPump::OnInputStreamReady(nsIAsyncInputStream * stream=0x0849bdd8) Line 401 + 0xb bytes C++ xpcom_core.dll!nsInputStreamReadyEvent::Run() Line 112 C++ xpcom_core.dll!nsThread::ProcessNextEvent(int mayWait=1, int * result=0x0016dfb4) Line 511 C++ xpcom_core.dll!NS_ProcessNextEvent_P(nsIThread * thread=0x00c7ab00, int mayWait=1) Line 227 + 0x16 bytes C++ xpcom_core.dll!nsThread::Shutdown() Line 465 + 0xb bytes C++ strgcmps.dll!mozStorageConnection::Close() Line 237 C++ xpcom_core.dll!NS_InvokeByIndex_P(nsISupports * that=0x00000003, unsigned int methodIndex=0, unsigned int paramCount=1499692, nsXPTCVariant * params=0x727209ef) Line 102 C++ xpc3250.dll!XPCWrappedNative::CallMethod(XPCCallContext & ccx={...}, XPCWrappedNative::CallMode mode=CALL_METHOD) Line 2405 + 0x21 bytes C++ xpc3250.dll!XPC_WN_CallMethod(JSContext * cx=0x00d36b88, JSObject * obj=0x03fd29a0, unsigned int argc=0, long * argv=0x04be9448, long * vp=0x0016e4f8) Line 1477 + 0xe bytes C++ js3250.dll!js_Invoke(JSContext * cx=0x00d36b88, unsigned int argc=0, long * vp=0x04be9440, unsigned int flags=2) Line 1306 + 0x1a bytes C++ js3250.dll!js_Interpret(JSContext * cx=0x00d36b88) Line 5147 + 0x16 bytes C++ js3250.dll!js_Invoke(JSContext * cx=0x00d36b88, unsigned int argc=1, long * vp=0x02a6da40, unsigned int flags=0) Line 1324 + 0x9 bytes C++ xpc3250.dll!nsXPCWrappedJSClass::CallMethod(nsXPCWrappedJS * wrapper=0x0808cd70, unsigned short methodIndex=5, const XPTMethodDescriptor * info=0x04c125f8, nsXPTCMiniVariant * nativeParams=0x0016f1dc) Line 1549 + 0x1b bytes C++ xpc3250.dll!nsXPCWrappedJS::CallMethod(unsigned short methodIndex=5, const XPTMethodDescriptor * info=0x04c125f8, nsXPTCMiniVariant * params=0x0016f1dc) Line 564 C++ ... JS stack at the time of the crash: 0 [native frame] 1 gloda_ds__queryFromSQLString(aMasterCollection = undefined, aExistingCollectio n = undefined, aListenerData = undefined, [object Object], [object Object]) ["fi le:///D:/mozilla-build/msys/comm-central/obj-i686-pc-mingw32/mozilla/dist/bin/mo dules/datastore.js":2702] collection = [object Object] statement = [object mozStorageStatementJSHelper @ 0x8092188 (native @ 0x51de b18)] this = [object Object] 2 gloda_ds_getMessagesByMessageID(010201c91c69$dcfe31c0$1e021fac@pgcseiitk, [fun ction], [object Object]) ["file:///D:/mozilla-build/msys/comm-central/obj-i686-p c-mingw32/mozilla/dist/bin/modules/datastore.js":2012] query = [object Object] listener = [object Object] nounDef = [object Object] sqlString = "SELECT * FROM messages WHERE headerMessageID IN ('010201c91c69$ dcfe31c0$1e021fac@pgcseiitk')" quotedIDs = '010201c91c69$dcfe31c0$1e021fac@pgcseiitk' this = [object Object] 3 gloda_indexMessage([xpconnect wrapped nsIMsgDBHdr @ 0x807d5a0 (native @ 0x8889 a60)], [object Object]) ["file:///D:/mozilla-build/msys/comm-central/obj-i686-pc -mingw32/mozilla/dist/bin/modules/indexer.js":2045] isNew = undefined attachmentNames = undefined curMsg = undefined conversation = undefined conversationID = undefined this = [object Object] 4 gloda_index_workBatch() ["file:///D:/mozilla-build/msys/comm-central/obj-i686- pc-mingw32/mozilla/dist/bin/modules/indexer.js":1059] commitTokens = 1 this = [object Object] 5 gloda_index_callbackDriver([xpconnect wrapped nsIMsgDBHdr @ 0x807d5a0 (native @ 0x8889a60)], [object Object]) ["file:///D:/mozilla-build/msys/comm-central/obj -i686-pc-mingw32/mozilla/dist/bin/modules/indexer.js":939] this = [object Object] 6 anonymous(aStatusCode = 0, aContext = [xpconnect wrapped nsIURI @ 0x8083858 (n ative @ 0x2b99d64)], aRequest = [xpconnect wrapped nsIRequest @ 0x808d660 (nativ e @ 0x6255538)]) ["file:///D:/mozilla-build/msys/comm-central/obj-i686-pc-mingw3 2/mozilla/dist/bin/modules/mimemsg.js":92] message = [object Object] this = [object Object] Gloda log just before the crash: 2008-11-10 13:11:11 gloda.indexer INFO Shutting Down 2008-11-10 13:11:11 gloda.indexer INFO Event-Driven Indexing is now fal se 2008-11-10 13:11:11 gloda.datastore INFO Closing pending transaction out for shutdown. --WEBSHELL 00CDABB8 == 2 2008-11-10 13:11:11 gloda.NS DEBUG found identity for '' (all@cse. iitk.ac.in) 2008-11-10 13:11:11 gloda.NS DEBUG found identity for 'ACA' (aca@c se.iitk.ac.in) 2008-11-10 13:11:11 gloda.NS INFO * provider: gloda.explattr 2008-11-10 13:11:11 gloda.NS INFO * optimizer: gloda.fundattr 2008-11-10 13:11:11 gloda.NS INFO ** done with providers. 2008-11-10 13:11:11 gloda.NS DEBUG %% no old, want to add Identity: email:aca@cse.iitk.ac.in which map to 6,906 2008-11-10 13:11:11 gloda.NS DEBUG %% no old, want to add Identity: email:all@cse.iitk.ac.in which map to 7,8 2008-11-10 13:11:11 gloda.NS DEBUG %% no old, want to add which ma p to 2008-11-10 13:11:11 gloda.NS DEBUG %% no old, want to add false whi ch map to 18,0 2008-11-10 13:11:11 gloda.NS DEBUG %% no old, want to add false whi ch map to 19,0 2008-11-10 13:11:11 gloda.NS DEBUG %% no old, want to add which ma p to 2008-11-10 13:11:11 gloda.NS DEBUG %% no old, want to add Identity: email:aca@cse.iitk.ac.in,Identity:email:all@cse.iitk.ac.in which map to 11,906,1 1,8 2008-11-10 13:11:11 gloda.NS DEBUG json text: {"6":906,"7":[8],"8 ":[],"18":false,"19":false,"17":[],"11":[906,8]} 2008-11-10 13:11:11 gloda.NS DEBUG inserting item 2008-11-10 13:11:11 gloda.NS DEBUG adjusting attributes, add: 6,90 6,7,8,18,0,19,0,11,906,11,8 rem: 2008-11-10 13:11:11 gloda.NS DEBUG done grokking. 2008-11-10 13:11:11 gloda.indexer DEBUG <<< _indexMessage 2008-11-10 13:11:11 gloda.indexer DEBUG >>> _indexMessage 2008-11-10 13:11:11 gloda.indexer DEBUG *** Indexing message: 120 : Stat e of Art Seminar: Authentication System ..... 2008-11-10 13:11:12 gloda.datastore INFO Closing db connection 2008-11-10 13:11:12 gloda.indexer DEBUG * Got Mime Message!
Reporter | ||
Comment 1•16 years ago
|
||
Since nsAutoLock comes in here, I'd just like to mention that this is a debug build.
http://mxr.mozilla.org/comm-central/source/mozilla/xpcom/glue/nsAutoLock.h?mark=211-212,217-219#203 211 nsAutoLock(PRLock* aLock) 212 : nsAutoLockBase(aLock, eAutoLock), 217 // This will assert deep in the bowels of NSPR if you attempt 218 // to re-enter the lock. 219 PR_Lock(mLock); http://mxr.mozilla.org/comm-central/source/mozilla/storage/src/mozStorageConnection.cpp?mark=218-219,234-236,937-939#212 strgcmps.dll!mozStorageConnection::Close() Line 237 C++ 218 mozStorageConnection::Close() 234 nsAutoLock mutex(mAsyncExecutionMutex); 235 if (mAsyncExecutionThread) { 236 mAsyncExecutionThread->Shutdown(); xpcom_core.dll!nsThread::Shutdown() Line 465 + 0xb bytes C++
Component: Backend → Storage
Product: MailNews Core → Toolkit
QA Contact: backend → storage
Summary: Gloda: Assertion in nspr4!PR_Lock on shutting down while indexing is active → Gloda: mozStorageConnection holds lock while calling outside its module leading to PR_ASSERT(lock->owner != me) on shutting down while indexing is active
Comment 3•16 years ago
|
||
So, we could get around this by adding a new variable to tell when we can use the connection (instead of using mDBConn). We'd set that once close was called (atomically!) so we do not need to use the lock in close?
Blocks: 460635
Updated•16 years ago
|
Whiteboard: tb3needs
Updated•16 years ago
|
Whiteboard: tb3needs → [tb3needs]
Comment 4•16 years ago
|
||
Holding a lock while calling outside our module is very bad, so I'm requesting blocking.
Flags: blocking1.9.1?
Assignee | ||
Comment 5•16 years ago
|
||
I'll get on this promptly; I had been punting while the trees were frozen, and then got busy. Clear tb3needs since gloda code no longer does dubious things in terms of storage after closing a connection.
Assignee: nobody → bugmail
Status: NEW → ASSIGNED
Whiteboard: [tb3needs]
Assignee | ||
Comment 6•16 years ago
|
||
No matter what we do, we need an extra variable (or allow for mAsyncExecutionThread to take on a non-null sentinel value) in order to capture the fact that we are shutting down. We must do this because mDBConn has to stay valid until the async execution thread is shut down (so that all pending events can successfully run to completion), and simply nulling out mAsyncExecution thread is insufficient; a new execution thread could end up being created. It would be more 'useful' to have a variable that captures the notion that we are shutting down the connection, but the async execution thread has specific/unique needs (pending async statements should succeed), so I am giving it its own variable. I don't think I can write a unit test for this change that would be deterministic unless we have some means of stalling the async execution thread until Shutdown is called on it. Brief investigation suggests this is difficult when MOZILLA_INTERNAL_API is defined, as is the case for storage. I would want to wrap the nsIThread, which would require wrapping the nsIThreadManager, which I presume is only feasible when do_GetService enters the picture. We could change to create its new thread that way, I suppose...
Attachment #352494 -
Flags: review?(sdwilsh)
Comment 7•16 years ago
|
||
Comment on attachment 352494 [details] [diff] [review] v1 add flag that indicates async thread is shutting down, don't call nsIThread::Shutdown with a lock held. (against 1.9.1) r=sdwilsh Looks good. Testing this would be darn near impossible unless we used a whole bunch of mock-objects.
Attachment #352494 -
Flags: review?(sdwilsh) → review+
Updated•16 years ago
|
Priority: -- → P2
Whiteboard: [has patch][has review][can land]
Assignee | ||
Comment 8•16 years ago
|
||
Landed on trunk: http://hg.mozilla.org/mozilla-central/rev/54601bbd453c This was done after a successful (if forever-taking) try build.
Whiteboard: [has patch][has review][can land] → [has patch][has review][baking on trunk]
Updated•16 years ago
|
Attachment #352494 -
Flags: approval1.9.1?
Comment 9•16 years ago
|
||
Policy is to close bugs once they land on trunk.
Status: ASSIGNED → RESOLVED
Closed: 16 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla1.9.2a1
Updated•16 years ago
|
Flags: blocking1.9.1? → blocking1.9.1+
Comment 10•16 years ago
|
||
Comment on attachment 352494 [details] [diff] [review] v1 add flag that indicates async thread is shutting down, don't call nsIThread::Shutdown with a lock held. (against 1.9.1) (this is now blocking, so doesn't need explicit approval)
Attachment #352494 -
Flags: approval1.9.1?
Comment 11•16 years ago
|
||
http://hg.mozilla.org/releases/mozilla-1.9.1/rev/3d5b39441bda
Keywords: fixed1.9.1
Whiteboard: [has patch][has review][baking on trunk]
You need to log in
before you can comment on or make changes to this bug.
Description
•