362649 - Assert on shutdown when contacting google for phish list ("ASSERTION: Profile change cancellation")

Status: RESOLVED WORKSFORME

(Core :: Security: PSM, defect)

Description

[Boris Zbarsky [:bzbarsky]]

BUILD: 2006-11-01 trunk build

STEPS TO REPRODUCE:
1)  Start the browser
2)  Go to Preferences > Security
3)  Make sure the "Tell me if the site I'm visiting is a suspected forgery"
    checkbox is checked.
4)  Select the "Check by asking ..." radio button under that.
5)  Go through the resulting dialogs saying you accept.
6)  Shut down the browser.
7)  Start the browser.
8)  Quit.

EXPECTED RESULTS:  No assert at step 8.

ACTUAL RESULTS:

###!!! ASSERTION: Profile change cancellation.: 'Error', file ../../../mozilla/toolkit/xre/nsXREDirProvider.cpp, line 704

(gdb) where
#0  Break (
    aMsg=0xbfffe8b0 "###!!! ASSERTION: Profile change cancellation.: 'Error', file ../../../mozilla/toolkit/xre/nsXREDirProvider.cpp, line 704")
    at ../../../mozilla/xpcom/base/nsDebugImpl.cpp:472
#1  0xb7d97050 in NS_DebugBreak_P (aSeverity=1, 
    aStr=0xb7fe5dde "Profile change cancellation.", aExpr=0xb7fe5dc5 "Error", 
    aFile=0xb7fe5920 "../../../mozilla/toolkit/xre/nsXREDirProvider.cpp", aLine=704)
    at ../../../mozilla/xpcom/base/nsDebugImpl.cpp:350
#2  0xb7fc442f in ProfileChangeStatusImpl::ChangeFailed (this=0x8c2dd40)
    at ../../../mozilla/toolkit/xre/nsXREDirProvider.cpp:704
#3  0xb600a7a8 in nsNSSComponent::Observe (this=0x81bc6b0, aSubject=0x8c2dd40, 
    aTopic=0xb7fe5e97 "profile-before-change", someData=0xb7fe5e00)
    at ../../../../../mozilla/security/manager/ssl/src/nsNSSComponent.cpp:1862
#4  0xb7d2843c in nsObserverList::NotifyObservers (this=0x8286a14, aSubject=0x8c2dd40, 
    aTopic=0xb7fe5e97 "profile-before-change", someData=0xb7fe5e00)
    at ../../../mozilla/xpcom/ds/nsObserverList.cpp:128

(gdb) frame 2
#2  0xb7fc442f in ProfileChangeStatusImpl::ChangeFailed (this=0x8c2dd40)
    at ../../../mozilla/toolkit/xre/nsXREDirProvider.cpp:704
704       NS_ERROR("Profile change cancellation.");
(gdb) list
701     NS_IMETHODIMP
702     ProfileChangeStatusImpl::ChangeFailed()
703     {
704       NS_ERROR("Profile change cancellation.");
705       return NS_ERROR_FAILURE;
706     }
(gdb) frame 3
#3  0xb600a7a8 in nsNSSComponent::Observe (this=0x81bc6b0, aSubject=0x8c2dd40, 
    aTopic=0xb7fe5e97 "profile-before-change", someData=0xb7fe5e00)
    at ../../../../../mozilla/security/manager/ssl/src/nsNSSComponent.cpp:1862
1862              status->ChangeFailed();
(gdb) list
1858        if (needsCleanup) {
1859          if (NS_FAILED(ShutdownNSS())) {
1860            nsCOMPtr<nsIProfileChangeStatus> status = do_QueryInterface(aSubject);
1861            if (status) {
1862              status->ChangeFailed();
1863            }

Comment 1

[Adam Guthrie]

*** Bug 350620 has been marked as a duplicate of this bug. ***

Comment 2

[Nickolay_Ponomarev]

FWIW, I started getting the same assertion (error originating in SECMOD_Shutdown()) recently nearly at each shutdown with phishing protection checkbox unchecked.

Comment 3

[Tony Chang (Google)]

Some notes from digging around:

This assert gets triggered if anything in nsNSSModule gets loaded.  Specifically, an instance of nsStreamCipher is initialized by the anti-phishing JS code whether anti-phishing is enabled or not.  However, I'm able to repro by not loading any anti-phishing code and doing a createInstance from the JS Shell on any of the XPCOM objects from nsNSSModule.

SECMOD_Shutdown() is failing to clear the "Builtin Roots" module.  Not sure why, but the module refCount never seems to go to zero.

Comment 4

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

Boris, did your patch to bug 379582 fix this?

Comment 5

[Boris Zbarsky [:bzbarsky]]

Not that I can see, no.

Comment 6

[Boris Zbarsky [:bzbarsky]]

As far as I can see, we're calling SECMOD_DestroyModule the right number of times on the right number of things.  But something is holding references to module slots, so the modules are not going away, as far as I can tell.

I tried seeing what the callers of PK11_FreeSlot are after the assert fires.  I see two calls with the stack:

#1  0xb3b6e924 in PK11_FreeSymKey (symKey=0x87ca558) at pk11skey.c:270
#2  0xb3b568eb in PK11_DestroyContext (context=0x8de89b0, freeit=1) at pk11cxt.c:97
#3  0xb3ce318c in ~nsStreamCipher (this=0x8b21d80)
    at ../../../../../mozilla/security/manager/ssl/src/nsStreamCipher.cpp:52

(released off a JS GC)

I don't know whether the JS here could try to let go of those objects earlier, but it really shouldn't have to.  Could nsNSSComponent shut down extant nsStreamCiphers before trying to shut down NSS or something?

Comment 7

[Boris Zbarsky [:bzbarsky]]

To make it clear, that JS GC comes _very_ late in shutdown.  Much later than the profile change notifications.

Comment 8

[Tony Chang (Google)]

I don't see this anymore on tinderbox.  Is this fixed?

Comment 9

[Tony Chang (Google)]

Nevermind, need to turn on remote checking.  It's still there.

Comment 11

[Kai Engert (:KaiE:)]

Does this still happen?
I have block-forgeries enabled, but I didn't see the assertion. However, I didn't see loading of the blocker-list, how I can I force that?

Comment 12

[Henrik Skupin [:whimboo][⌚️UTC+2]]

I can see this a lot recently with my mochitests for WebRTC. Any push to try shows up this assertion. See: https://tbpl.mozilla.org/php/getParsedLog.php?id=17887235&tree=Try#error0

Can I assume it is the same issue or should it be filed as a new one?

Comment 13

[Dana Keeler (she/her) (use needinfo) [:keeler]]

Profile change cancellation can't happen any more, afaik.