410116 - DEBUG_CC spews over a megabyte of "was not collected" (etc) on every shutdown

Status: RESOLVED FIXED

(Core :: XPCOM, defect, P3)

Description

[Jesse Ruderman]

Steps to reproduce:
1. Build with DEBUG_CC.  (You may need the patch in bug 410036.)
2. Run Firefox from the command line.
3. Quit Firefox with Cmd+Q.

Result: DEBUG_CC spews a whole bunch of stuff, but trace-refcnt says nothing leaked all the way through shutdown.

<Jesse> dbaron: previously, was cycle collector silent when there were no leaks?
<dbaron> I think so, but I'm not sure.

I showed dbaron the output:

<dbaron> I'd say that may be a real bug, although the bug may just be the relative ordering of cycle collector shutdown and JS component loader shutdown.
<dbaron> there could be a real issue that cycle collector is shutting down too early to help cleanup global objects in JS components
<dbaron> or something else
<dbaron> it could also be a DEBUG_CC issue
<dbaron> but probably worth filing

Comment 1

[Jesse Ruderman]

Attachment: console output when starting and quitting with DEBUG_CC

Comment 2

[Jesse Ruderman]

I can also get a bunch of spew when I close a browser window, even if I'm not shutting down the browser.:
1. Build with DEBUG_CC.
2. Run Firefox from the command line.
3. Cmd+N to open a second browser window.
4. Close the new window by clicking the red 'x'.
5. Wait about 10 seconds

I think this makes it pretty hard to debug large leaks using DEBUG_CC, unless you figure out the address of an nsGlobalWindow that leaks through shutdown using another method (e.g. trace-refcnt logging or leak-gauge).

Comment 3

[Mike Schroepfer]

Moving to blocking so we can figure out if this is a real bug

Comment 4

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

I think I found a mistake in the DEBUG_CC changes in bug 401687 (suspectCurrentCount is now always 0; we should really just make it expectedGarbageCount instead).  If my theory is right, hopefully patch coming soon...

Comment 5

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

Attachment: patch

Comment 6

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

But even with that things are still way too noisy because anything that's GCMarked gets treated as though it has external references, even though that really just means it or something that can reach it has external references.

Comment 7

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

...er, except it looks like we should handle that already with nsXPConnect::mJSRoots.

Comment 8

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

er, never mind.  It is broken, since mJSRoots has the whole runtime.

Comment 9

[Peter Van der Beken [:peterv]]

I'll have to go back and look closely but iirc mJSRoots should only contain the "real" JS roots, objects that are held alive by the JS engine itself or through traditional JS rooting. From the pov of the cycle collector those do have an unknown edge.

Comment 10

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

I thought it was everything since NoteJSRoot calls JS_TraceChildren.  I think the cycle collector would work OK either way, but I suspect you wanted to match the non-ExplainLiveExpectedGarbage case which uses JS_IsAboutToBeFinalized.  Though it might actually work fine (i.e., be fast enough) to trace from the runtime without tracing children even in the normal case (if we want to keep the two cases matching).  Though maybe the best option is to just make the ExplainLiveExpectedGarbage case different...

Comment 11

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

Oh, oops -- I missed that the JS_TraceChildren call was in an else (and what the condition there was).

Comment 12

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

So, I guess I can believe that the above patch is sufficient, and the current noise I'm seeing on shutdown has to do with the timing of the shutdown cycle collection being earlier than I'd want it to be combined with bug 398219 not really being fixed.

Comment 13

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

Aha.  I think I did find a real problem to explain a bit of the noise -- we need to find a place to call UnsetContextGlobals and RestoreContextGlobals for the ExplainLiveExpectedGarbage case...

Comment 14

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

Attachment: also unset and restore context globals

Comment 15

[Peter Van der Beken [:peterv]]

Comment on attachment 296556 [details] [diff] [review]
also unset and restore context globals

Good catch, sorry about that.

Comment 16

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

Both patches checked in.  I think the remaining noise is actually representing stuff that should have been collected at that point but wasn't, although perhaps I should comment out the nsGenericElement shouldBeFreed and wasFreed calls, since they tend to cause more noise than they're worth.

Comment 17

[Mike Beltzner [:beltzner, not reading bugmail]]

Fixed?

Comment 18

[Ben Turner (not reading bugmail, use the needinfo flag!)]

The bug as described in comment 0 is certainly fixed, we have a clean shutdown with no CC output follwing those steps to reproduce.

Comment 19

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

OK, fixed.