186592 - nsXPCWrappedJS::Release - PR_Lock assertion.

Status: VERIFIED FIXED

(Core :: JavaScript Engine, defect)

Description

[Doug Turner (:dougt)]

I am running the some xpconnect js code over and over again that downloads a web
page and appends the contents into a js string (during each ODA call). 
Basically, I am using Necko to download index pages.  My nsIStreamListener
interface is implemented in js.  During the OnDataAvailable call, I read all of
the data through a nsIScriptableStream interface into a js string.  These pages
can be pretty large (<10K).  I think parse through the string, and eventually
just throw the string away (drop my references to it).  I continue this whole
process for some minutes (dozens of connnections), then I get this assertion hit.  

NTDLL! 77f767cd()
PR_Lock(PRLock * 0x00a01d38) line 235 + 40 bytes
js_RemoveRoot(JSRuntime * 0x00a6f028, void * 0x03f373dc) line 433 + 16 bytes
JS_RemoveRootRT(JSRuntime * 0x00a6f028, void * 0x03f373dc) line 1503 + 13 bytes
nsXPCWrappedJS::Release(nsXPCWrappedJS * const 0x03f373c0) line 158 + 22 bytes
XPCJSRuntime::GCCallback(JSContext * 0x02b88e88, JSGCStatus JSGC_END) line 546 +
18 bytes
DOMGCCallback(JSContext * 0x02b88e88, JSGCStatus JSGC_END) line 1641 + 23 bytes
js_GC(JSContext * 0x02b88e88, unsigned int 5) line 1399 + 12 bytes
js_AllocGCThing(JSContext * 0x02b88e88, unsigned int 1) line 523 + 11 bytes
js_NewString(JSContext * 0x02b88e88, unsigned short * 0x0409a220, unsigned int
16104, unsigned int 0) line 2442 + 16 bytes
JS_NewStringCopyZ(JSContext * 0x02b88e88, const char * 0x040962f8) line 3542 +
19 bytes
XPCConvert::NativeData2JS(XPCCallContext & {...}, long * 0x0012e2dc, const void
* 0x0012e380, const nsXPTType & {...}, const nsID * 0x0012e404, JSObject *
0x03320f10, unsigned int * 0x0012e4b8) line 362 + 14 bytes
XPCWrappedNative::CallMethod(XPCCallContext & {...}, XPCWrappedNative::CallMode
CALL_GETTER) line 2105 + 50 bytes
XPCWrappedNative::GetAttribute(XPCCallContext & {...}) line 1880 + 14 bytes
XPC_WN_GetterSetter(JSContext * 0x02b88e88, JSObject * 0x03320f10, unsigned int
0, long * 0x0403de04, long * 0x0012e670) line 1324 + 12 bytes
js_Invoke(JSContext * 0x02b88e88, unsigned int 0, unsigned int 2) line 839 + 23
bytes
js_InternalInvoke(JSContext * 0x02b88e88, JSObject * 0x03320f10, long 53612464,
unsigned int 0, unsigned int 0, long * 0x00000000, long * 0x0012f398) line 931 +
20 bytes
js_Interpret(JSContext * 0x02b88e88, long * 0x0012f550) line 2634 + 1230 bytes
js_Invoke(JSContext * 0x02b88e88, unsigned int 5, unsigned int 2) line 856 + 13
bytes
nsXPCWrappedJSClass::CallMethod(nsXPCWrappedJSClass * const 0x03e5ff70,
nsXPCWrappedJS * 0x03e5ddf0, unsigned short 5, const nsXPTMethodInfo *
0x02b79460, nsXPTCMiniVariant * 0x0012fa48) line 1200 + 21 bytes
nsXPCWrappedJS::CallMethod(nsXPCWrappedJS * const 0x03e5ddf0, unsigned short 5,
const nsXPTMethodInfo * 0x02b79460, nsXPTCMiniVariant * 0x0012fa48) line 430
PrepareAndDispatch(nsXPTCStubBase * 0x03e5ddf0, unsigned int 5, unsigned int *
0x0012faf8, unsigned int * 0x0012fae8) line 115 + 31 bytes
SharedStub() line 139
nsStreamListenerTee::OnDataAvailable(nsStreamListenerTee * const 0x03e85348,
nsIRequest * 0x03fcea00, nsISupports * 0x03fce698, nsIInputStream * 0x03fcfda8,
unsigned int 23465, unsigned int 3816) line 97 + 51 bytes
nsHttpChannel::OnDataAvailable(nsHttpChannel * const 0x03fcea04, nsIRequest *
0x03fd002c, nsISupports * 0x00000000, nsIInputStream * 0x03fcfda8, unsigned int
23465, unsigned int 3816) line 3087 + 63 bytes
nsOnDataAvailableEvent::HandleEvent() line 195 + 70 bytes
nsARequestObserverEvent::HandlePLEvent(PLEvent * 0x04021e54) line 116
PL_HandleEvent(PLEvent * 0x04021e54) line 644 + 10 bytes
PL_ProcessPendingEvents(PLEventQueue * 0x009ecc58) line 574 + 9 bytes
_md_TimerProc(HWND__ * 0x00a7025e, unsigned int 275, unsigned int 0, unsigned
long 942518810) line 930 + 9 bytes
USER32! 77d43a68()
USER32! 77d442dd()
USER32! 77d43e87()
USER32! 77d43df7()
nsAppShellService::Run(nsAppShellService * const 0x00a9b7d8) line 472
main1(int 1, char * * 0x002a4fb0, nsISupports * 0x00a7c568) line 1554 + 32 bytes
main(int 1, char * * 0x002a4fb0) line 1915 + 37 bytes
mainCRTStartup() line 338 + 17 bytes
KERNEL32! 77e814c7()

any ideas?

Comment 1

[David Bradley]

Looks like the lock was already aquired, or wasn't released. This lock is
controlled by the JS engine. I suspect there might be an error path that might
not be releasing it. js_GC looks like it should release it before the callback
is invoked.

Comment 2

[Phil Schwartau]

cc'ing JS experts -

Comment 3

[Brendan Eich [:brendan]]

Mine.

/be

Comment 4

[Brendan Eich [:brendan]]

Attachment: proposed fix

Easy to fix.  If a last-ditch GC has to give up the GC lock to invoke the GC
callback (in case that callback meddles with roots), then a racing allocator
may use up the memory just reclaimed, leaving the last-ditch GC in the last
ditch, still.  Too bad.  See bug 162779 for evidence that this can happen.

/be

Comment 5

[Mike Shaver (:shaver emeritus)]

Comment on attachment 110880 [details] [diff] [review]
proposed fix

Happy New Year!

Comment 6

[Brendan Eich [:brendan]]

Fixed.

/be

Comment 7

[Phil Schwartau]

I'll need help in verifying this.

dougt: could you mark this Verified if the problem is fixed now? Thanks -

Comment 8

[Phil Schwartau]

Doug: any luck with this? Has it been fixed now?

Comment 9

[Doug Turner (:dougt)]

i do not see this problem anymore.

Comment 10

[Phil Schwartau]

Marking Verified Fixed per Doug's findings -

Comment 11

[Phil Schwartau]

This fix may have caused a regression; see bug 190813,
"Browser hangs indefinitely on above URL"