652985 - !rt->gcRunning assert failure with DEBUG_CC

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

[Andrew McCreight [:mccr8]]

With a fairly recent Tracemonkey tree, enabling DEBUG_CC and making no other changes causes JS_ASSERT(!rt->gcRunning) to fail in TriggerGC, when you are on http://techcrunch.com for ~30 seconds.  This seems to be caused by the cycle collector's ExplainLiveExpectedGarbage invocation of JS_DumpHeap, as commenting out the call to ExplainLiveExpectedGarbage does not cause any trouble.

From the stack trace, it looks like DumpNotify runs out of memory in the middle of the marking of the heap, which causes the GC to be invoked, which somehow causes the assertion failure.  I'm not sure how the GC is running.

Comment 1

[Andrew McCreight [:mccr8]]

I'm not sure if the problem is in the cycle collector code or the JS GC code, but it looks more like a JS problem to me, so I'm putting it there to start.

Comment 2

[Olli Pettay [:smaug]]

Knowing the regression range would be useful here.

Comment 3

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Could you post a stack trace?

Comment 4

[Andrew McCreight [:mccr8]]

Thread 0 Crashed:  Dispatch queue: com.apple.main-thread
0   XUL  0x0000000101f69722 JS_Assert + 50
1   XUL  0x0000000101dd76e8 js::TriggerGC(JSRuntime*) + 104
2   XUL  0x0000000101d73f98 JSRuntime::onTooMuchMalloc() + 40
3   XUL  0x0000000101d0c301 DumpNotify(JSTracer*, void*, unsigned int) + 593
4   XUL  0x0000000101dfb39a void js::gc::Mark<JSObject>(JSTracer*, JSObject*) + 826
5   XUL  0x0000000101dee596 js::MarkIfGCThingWord(JSTracer*, unsigned long) + 4358
6   XUL  0x0000000101ddcdbc js::MarkConservativeStackRoots(JSTracer*) + 188
7   XUL  0x0000000101ddcf57 js::MarkRuntime(JSTracer*) + 39
8   XUL  0x0000000101ddd527 js::TraceRuntime(JSTracer*) + 151
9   XUL  0x0000000101d1559b JS_DumpHeap + 859
10  XUL  0x00000001011e8104 nsXPConnect::PrintAllReferencesTo(void*) + 148 (nsXPConnect.cpp:555)
11  XUL  0x0000000101abe088 nsCycleCollector::ExplainLiveExpectedGarbage() + 3208 (nsCycleCollector.cpp:2947)
12  XUL  0x0000000101abea1c nsCycleCollector::CleanupAfterCollection() + 252 (nsCycleCollector.cpp:2523)
13  XUL  0x0000000101abf307 nsCycleCollector_collect(nsICycleCollectorListener*) + 1495 (nsCycleCollector.cpp:3374)
14  XUL  0x0000000100b6c7aa nsJSContext::CycleCollectNow(nsICycleCollectorListener*) + 106 (nsJSEnvironment.cpp:3277)
15  XUL  0x0000000101aab6bb nsTimerImpl::Fire() + 1515 (nsTimerImpl.cpp:424)
16  XUL  0x0000000101aab995 nsTimerEvent::Run() + 101 (nsTimerImpl.cpp:520)
17  XUL  0x0000000101aa3250 nsThread::ProcessNextEvent(int, int*) + 864 (nsThread.cpp:618)

Comment 5

[Gregor Wagner [:gwagner]]

I guess we should change the allocation in DumpNotify. This totally changes the behavior of the application you want to debug so it would make sense to not account for the GC trigger.

DumpNotify is only used for debugging right?

Comment 6

[Gregor Wagner [:gwagner]]

And this was fixed by bug 629655...

Comment 7

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Attachment: fix

Yeah, I think we need to change the allocation.

Also, I needed to fix a problem with make check on my system. It was finding too many files when looking for .cpp and .h files, and then it wasn't properly escaping the filenames. I don't know how to do the escaping, so I just restricted the search.

Comment 8

[Andrew McCreight [:mccr8]]

Weird, Gregor.  This was fixed at the end of January, and then at some point between then and the end of March it was removed again.  Hopefully there wasn't some good reason for that...

Comment 9

[Paul Biggar]

Comment on attachment 534086 [details] [diff] [review]
fix

Looks like I reverted the fix from bug 652985 during bug 643548. Whoops, sorry!

In light of that, I'd love a comment here as either a warning or an explanation.

Comment 10

[Carsten Book [:Tomcat]]

note, i'm running into this also in the TopSite Tests for Firefox 5 on Mac 10.6 -

Assertion failure: !rt->gcRunning, at /work/mozilla/builds/firefox5/mozilla-beta/js/src/jscntxt.cpp:1019

http://www.spele.nl: EXIT STATUS: CRASHED signal 10 SIGBUS (323.277012 seconds)

Comment 11

[Bob Clary [:bc] (inactive)]

also http://globoesporte.globo.com/ for beta on winxp though I haven't tried to reproduce it locally.

Comment 12

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

http://hg.mozilla.org/tracemonkey/rev/596dca744a37

It seems unlikely that the reports in comments 10 and 11 are related to this bug. This bug only occurs when you set DEBUG_CC, which I think is disabled by default (even in debug builds, IIUC).

Comment 13

[Andrew McCreight [:mccr8]]

Yes, DEBUG_CC has to be manually set.  Could DumpNotify being OOMing in other settings?  I don't know what exactly it is used for.

Comment 14

[Bob Clary [:bc] (inactive)]

The stacks for the two urls where I have seen this on WinXP do not involve DumpNotify. The assert fires during the destruction of a JSContext during a GC. File a new bug?

Comment 15

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Yes, please do file a new bug. A stack trace would be useful.

Comment 16

[Bob Clary [:bc] (inactive)]

I can no longer reproduce this assertion on any branch using Tomcat's or my urls. I have not seen it in automation since 5/26. I'll keep an eye out for it and will file a new bug.

Comment 17

[Olli Pettay [:smaug]]

Could we get the patch to m-c so that one could actually use DEBUG_CC

Comment 18

[Chris Leary [:cdleary] (not checking bugmail)]

http://hg.mozilla.org/mozilla-central/rev/596dca744a37