160182 - Assertion at shutdown [@nsFastLoadFile.cpp line 1694] [@ nsFastLoadFileWriter::ObjectMapEnumerate]

Status: RESOLVED INCOMPLETE

(Core :: XPCOM, defect)

Description

[Nicholas Allen]

With CVS trunk debug build, when XUL Cache is disabled I get the following 
assertion on shutdown:

###!!! ASSERTION: too many strong refs in serialization: 'entry->mInfo.mStrongRe
fCnt <= rc - 2', file x:/project/mozilla/xpcom/io/nsFastLoadFile.cpp, line 1694

Blowing away fastload files, creating new profile, etc. doesn't help.

Steps to reproduce:

1) Disable XUL Cache
2) Open Mozilla
3) Close Mozilla

Comment 1

[Doug Turner (:dougt)]

ben, brendan, can you look at this?

Comment 2

[Brendan Eich [:brendan]]

This is not my bug.  It might be a XUL bug; it might be a "don't do that" (do we
support turning off the XUL cache?).  Trying ben, changing QA Contact to jrgm.

/be

Comment 3

[timeless]

<bz> and Ben no longer works on Mozilla
<bz> fyi

when i get settled, i'll look into this, it bugged me for a while (and stopped
when i lost my dev env...)

The problem i had before is that i couldn't figure out what was expected or what
was happening.

reporter: please attach a stack trace, and we can try to figure out which caller
should have known better than to touch fastload.

Comment 4

[Nicholas Allen]

Here's the stack at assertion time:

nsFastLoadFileWriter::ObjectMapEnumerate(PLDHashTable * 0x02af0c14, 
PLDHashEntryHdr * 0x01547f38, unsigned int 0, void * 0x014fb270) line 1694 + 44 
bytes
PL_DHashTableEnumerate(PLDHashTable * 0x02af0c14, int (PLDHashTable *, 
PLDHashEntryHdr *, unsigned int, void *)* 0x1005d030 
nsFastLoadFileWriter::ObjectMapEnumerate(PLDHashTable *, PLDHashEntryHdr *, 
unsigned int, void *), void * 0x014fb270) line 601 + 34 bytes
nsFastLoadFileWriter::WriteFooter() line 1783 + 21 bytes
nsFastLoadFileWriter::Close(nsFastLoadFileWriter * const 0x02af0bb8) line 1903 
+ 8 bytes
nsFastLoadService::~nsFastLoadService() line 85
nsFastLoadService::`scalar deleting destructor'(unsigned int 1) + 15 bytes
nsFastLoadService::Release(nsFastLoadService * const 0x014a9ad0) line 63 + 133 
bytes
nsXULPrototypeCache::~nsXULPrototypeCache() line 205 + 27 bytes
nsXULPrototypeCache::`scalar deleting destructor'(unsigned int 1) + 15 bytes
nsXULPrototypeCache::Release(nsXULPrototypeCache * const 0x01491270) line 210 + 
138 bytes
nsXULPrototypeScript::ReleaseGlobals() line 330 + 26 bytes
Shutdown(nsIModule * 0x00fe31a8) line 261
nsGenericModule::Shutdown() line 323 + 10 bytes
nsGenericModule::~nsGenericModule() line 234
nsGenericModule::`scalar deleting destructor'(unsigned int 1) + 15 bytes
nsGenericModule::Release(nsGenericModule * const 0x00fe31a8) line 236 + 136 
bytes
nsDll::Shutdown() line 383 + 18 bytes
nsFreeLibrary(nsDll * 0x00fad7e8, nsIServiceManager * 0x00000000, int 3) line 
309
nsFreeLibraryEnum(nsHashKey * 0x00fad988, void * 0x00fad7e8, void * 0x0012fe88) 
line 357 + 64 bytes
_hashEnumerate(PLHashEntry * 0x00fad9d0, int 47, void * 0x0012fe6c) line 199 + 
26 bytes
PL_HashTableEnumerateEntries(PLHashTable * 0x0027d460, int (PLHashEntry *, int, 
void *)* 0x1001dde0 _hashEnumerate(PLHashEntry *, int, void *), void * 
0x0012fe6c) line 429 + 15 bytes
nsHashtable::Enumerate(int (nsHashKey *, void *, void *)* 0x100720a0 
nsFreeLibraryEnum(nsHashKey *, void *, void *), void * 0x0012fe88) line 362 + 
21 bytes
nsNativeComponentLoader::UnloadAll(nsNativeComponentLoader * const 0x0027d410, 
int 3) line 949
nsComponentManagerImpl::UnloadLibraries(nsIServiceManager * 0x00000000, int 3) 
line 2960 + 22 bytes
nsComponentManagerImpl::Shutdown() line 861
NS_ShutdownXPCOM(nsIServiceManager * 0x00000000) line 661 + 11 bytes
main(int 1, char * * 0x00276d40) line 1886 + 8 bytes
mainCRTStartup() line 338 + 17 bytes
KERNEL32! 77ea847c()

Comment 5

[timeless]

ok, so we need to change nsXULPrototypeCache to honor the pref, i wonder if i
have a patch in my tree to do that.  if you'd like to investigate this people on
irc.mozilla.org #mozilla should be able to help you play w/ the pref service
(i'm making lunch now, but i'll be there)

brendan? amusingly enough, this reminds me of a topcrash - bug 157760

Comment 6

[Nicholas Allen]

Ok, poking around at this a bit, here's where things stand:

1 xul cache enabled: works
2 xul cache disabled: busted (asserts on shutdown)
3 enabling xul cache while running: busted (asserts on shutdown)
4 disabling xul cache while running: busted (asserts next time started)

#2 is easy to wallpaper over by wrapping the NS_IF_RELEASE for the fastload 
service with a check that the XUL cache is enabled.  But that's clearly not the 
right thing to do all the time.

Comment 7

[timeless]

Attachment: draft

i'm hoping the reporter or qa can test this for me (including a compile)

Comment 8

[Nicholas Allen]

The patch fixes the assertions in all of the cases I listed above.  I also 
tried general browsing with it applied for a bit and didn't notice any 
differences from my baseline build.

Now I'm going to have to figure out why AbortFastLoads works when timeless does 
it but didn't work when I tried it earlier.

Comment 9

[Jay Patel [:jay]]

Is this a dup of bug 157760?  Timeless said it remind him of that bug...should
we mark it a dup?  Perhaps the patch here might help fix that topcrash?

Comment 10

[Nicholas Allen]

I'm not sure the two are related.  This bug requires the xul cache to be
disabled which should be somewhat rare (although bug 183309 showed it was not as
rare as it should be) but constant.  However, the number of crashes in bug
157760 has gone from dozens to essentially zero in the meantime.  jrgm is going
to be resetting the xul cache disable pref soon so we might be able to see then
if that's a factor.

Comment 11

[John Morrison]

Yeah this isn't a dupe, or not in a way that I can see. This is happening 
during shutdown and this only happens if the xul cache has been disabled. The
other stack shows this occurring during normal operation (i.e., triggered by 
EndLoad of a xul document, not during shutdown). Although there may be a bit of 
a clue in what happens here. 

[And yes I do have to review this patch. Sorry. Tomorrow].

Comment 12

[John Morrison]

Actually, brendan and I realized that the 'too many strong refs in 
serialization' is bogus and it was removed in the most recent patch to 
nsFastLoadFile.cpp.

Still, we shouldn't be going back into fastload writer code after xpcom
has begun shutdown...

Comment 13

[Brendan Eich [:brendan]]

jrgm, is this the bug we should use to track the "FastLoadFileWriter stream left
open for indefinite periods" problem that you told me about the other day?  If
so, can you take this bug and dig into why FastLoad episodes are not short (only
as long as it takes to get all the concurrently-opening new XUL windows of
discrete types up and loaded)?

/be

Comment 14

[John Morrison]

I filed bug 193641 to investigate the fastload stream left open issue.
This bug has flavours of that problem, but really the fastload code
implicitly assumes that the xul cache will exist, and when you disable
one and not the other all kinds of ugliness ensues. So let's just
treat this bug on its own.

(Note: the reason that the writer code is called at shutdown is that
URL's are put in the mFastLoadURITable, but due to the lack of the xul
cache, an error gets thrown before each entry is removed. So that
means the streams don't get closed up and are instead closed by the
destructor.)

I think we should put this patch in for 1.3. I'll r= tomorrow [sorry,
I went off looking too long at what was to become bug 193641].

(Although, I'd still also like to rename the 'disable_xul_cache' pref
and remove it from the debug UI for 1.3final [bug 190358].  It was
suggested that this would be too much pain for xul developers, but
when I posted twice to n.p.m.xpfe it drew little comment.)

Comment 15

[John Morrison]

Comment on attachment 93379 [details] [diff] [review]
draft

r=jrgm

[There is one problem with the patch, although that problem already existed
before the patch.  When you enter this section, each call to
RegisterCallbacks adds another callback to the linklist of callbacks.  So,
(a) that's slightly wasteful (quasi "leak" of the size of the pref
strings), and (b) when you toggle the disable_xul_cache pref in the UI, all
of the callbacks so far registered will be triggered. However, after the
first callback executes, the rest will be effectively no-ops. And that's
only for people who fiddle with this UI (which I still want to remove for
1.3). Regular users won't see the multiple callbacks, although we need to
clean up the multiple registrations at some point. Possible patch follows.]

Comment 16

[John Morrison]

Attachment: patch; register callbacks once only (while also incorporating timeless' changes)

There may be objections to so obviously tying the fastload with the xul cache
code, but the fact is that they were already implicitly tied together (cf. this
bug). The xul fastload code doesn't really work in the absence of the xul cache

(although if you're disabling xul cache, do you really care about "fast load").

Comment 17

[Boris Zbarsky [:bzbarsky]]

Comment on attachment 114851 [details] [diff] [review]
patch; register callbacks once only (while also incorporating timeless' changes)

I don't really know this code; please ask for review from someone who does (at least if you want the review in any sort of reasonable timeframe).

Comment 18

[Brendan Eich [:brendan]]

Comment on attachment 93379 [details] [diff] [review]
draft

Timeless, is this still a needed patch?

/be

Comment 19

[Justin Wood (:Callek)]

(In reply to comment #18)
> Comment on attachment 93379 [details] [diff] [review]
> draft
> 
> Timeless, is this still a needed patch?
> 

No response since this comment...