609909 - crash [@ nsNNTPProtocol::HandleAuthenticationFailure()]

Status: RESOLVED FIXED

(MailNews Core :: Networking: NNTP, defect)

Description

[Wayne Mery (:wsmwk)]

crash [@ nsNNTPProtocol::HandleAuthenticationFailure()]

bp-709d453a-0f37-4608-937b-dc32a2101103  v3.0.4
0	thunderbird.exe	nsNNTPProtocol::HandleAuthenticationFailure	mailnews/news/src/nsNNTPProtocol.cpp:3301
1	thunderbird.exe	nsNNTPProtocol::PasswordResponse	mailnews/news/src/nsNNTPProtocol.cpp:2893
2	thunderbird.exe	nsNNTPProtocol::ProcessProtocolState	mailnews/news/src/nsNNTPProtocol.cpp:4858
3	thunderbird.exe	nsMsgProtocol::OnDataAvailable	mailnews/base/util/nsMsgProtocol.cpp:359
4	thunderbird.exe	nsInputStreamPump::OnStateTransfer	netwerk/base/src/nsInputStreamPump.cpp:508
5	thunderbird.exe	nsInputStreamPump::OnInputStreamReady	netwerk/base/src/nsInputStreamPump.cpp:398
6	xpcom_core.dll	nsOutputStreamReadyEvent::Run	xpcom/io/nsStreamUtils.cpp:111
7	xpcom_core.dll	nsThread::ProcessNextEvent	xpcom/threads/nsThread.cpp:521
8	xpcom_core.dll	NS_ProcessNextEvent_P	objdir-tb/mozilla/xpcom/build/nsThreadUtils.cpp:247
9	thunderbird.exe	nsXULWindow::ShowModal	xpfe/appshell/src/nsXULWindow.cpp:415
10	thunderbird.exe	nsContentTreeOwner::ShowAsModal	xpfe/appshell/src/nsContentTreeOwner.cpp:528 

bp-9480a696-e85d-4611-8ea5-b49ee2101101 v3.1.6
0	thunderbird.exe	nsNNTPProtocol::HandleAuthenticationFailure	mailnews/news/src/nsNNTPProtocol.cpp:3306
1	thunderbird.exe	nsNNTPProtocol::PasswordResponse	mailnews/news/src/nsNNTPProtocol.cpp:2898
2	thunderbird.exe	nsNNTPProtocol::ProcessProtocolState	mailnews/news/src/nsNNTPProtocol.cpp:4865
3	thunderbird.exe	nsMsgProtocol::OnDataAvailable	mailnews/base/util/nsMsgProtocol.cpp:359
4	thunderbird.exe	nsInputStreamPump::OnStateTransfer	netwerk/base/src/nsInputStreamPump.cpp:510
5	thunderbird.exe	nsInputStreamPump::OnInputStreamReady	netwerk/base/src/nsInputStreamPump.cpp:400
6	xpcom_core.dll	nsOutputStreamReadyEvent::Run	xpcom/io/nsStreamUtils.cpp:112
7	xpcom_core.dll	nsThread::ProcessNextEvent	xpcom/threads/nsThread.cpp:527
8	xpcom_core.dll	NS_ProcessNextEvent_P	objdir-tb/mozilla/xpcom/build/nsThreadUtils.cpp:250
9	thunderbird.exe	nsXULWindow::ShowModal	xpfe/appshell/src/nsXULWindow.cpp:416
10	thunderbird.exe	nsContentTreeOwner::ShowAsModal	xpfe/appshell/src/nsContentTreeOwner.cpp:528
11	thunderbird.exe	nsWindowWatcher::OpenWindowJSInternal	embedding/components/windowwatcher/src/nsWindowWatcher.cpp:1010
12	thunderbird.exe	nsWindowWatcher::OpenWindow	embedding/components/windowwatcher/src/nsWindowWatcher.cpp:425
13	thunderbird.exe	nsPromptService::DoDialog	embedding/components/windowwatcher/src/nsPromptService.cpp:795

Comment 1

[Joshua Cranmer [:jcranmer]]

So much lower in the stack is the problem actually made fully clear:
27  	thunderbird.exe  	nsNNTPProtocol::CloseConnection

We're actually trying to close the socket right now, which sets m_nntpServer to be null to break links in the ref cycle. It appears that this is accidentally reentrant (it spins the event loop, which happens to cause incoming socket data to be processed).

There are a few options for implementation (I'm not including crash-proofing every use of m_nntpServer):
* Close the socket in such a way that we won't get any further notification callbacks (basically, force CloseSocket to not return until it is guaranteed that ProcessProtocolState will never be called again). And move the clearing of variables until after that.
* Attempt to break the refcnt cycles only after the socket is "fully closed" (i.e., we won't call ProcessProtocolState again).
* Force ProcessProtocolState to ignore all input after the socket has been told to close.

The second one seems to me the most fragile (any pointer ownership model changes would risk breakage). I'm not sure the first one could be done--I'm concerned about the edge case where we have a pending input event in the event queue when we do the magical "force close" call. I'm not even sure it exists (mInputStream->Close is about the most logical, but necko might scream). The last one is probably the easiest to implement, and could possibly fix a few other (unreported) bugs or two. On the other hand, that could put us into inconsistent states.

In any case, I'd feel more comfortable if we had some NNTP tests that tested forced connection close in odd circumstances. I think #2 is aesthetically the most pleasing: it pretty much guarantees reentrancy no matter what the case--any callback could theoretically call CloseCachedConnections, so null checks would never have to be present in theory.

Comment 2

[David :Bienvenu]

This would probably the first thing I'd try since it's pretty simple:

* Force ProcessProtocolState to ignore all input after the socket has been told
to close.

after or while the socket is closing? probably doesn't matter...

this kind of reentrancy is going to cause issues no matter what, so cutting off the reentrancy seems like the path to victory to me.

Comment 3

[Joshua Cranmer [:jcranmer]]

Attachment: Patch

This patch is basically option 2: if m_nntpServer is null, ProcessProtocolState closes the input stream and bails. The attached test crashes without the changes to ProcessProtocolState.

The only thing I'm not sure about is whether or not the mailnewsurl check should be doing the same thing.

Comment 5

[David :Bienvenu]

Comment on attachment 488609 [details] [diff] [review]
Patch

this breaks all the compose tests in debug mode on windows because we hit an assertion:

TEST-UNEXPECTED-FAIL | c:/builds/tbirdhq/objdir-tb/mozilla/_tests/xpcshell/mailn
ews/compose/test/unit/head_compose.js | EHLO test,AUTH PLAIN AHRlc3Quc210cEBmYWt
lc2VydmVyAHNtdHB0ZXN0,AUTH LOGIN == EHLO test,AUTH PLAIN AHRlc3Quc210cEBmYWtlc2V
ydmVyAHNtdHB0ZXN0,AUTH LOGIN,AUTH PLAIN AHRlc3Quc210cEBmYWtlc2VydmVyAHdyb25n,MAI
L FROM:<[e-mail]> SIZE=155,RCPT TO:<[e-mail]>,DATA - See following
 stack:
JS frame :: c:\builds\tbirdhq\mozilla\testing\xpcshell\head.js :: do_throw :: li
ne 420
JS frame :: c:\builds\tbirdhq\mozilla\testing\xpcshell\head.js :: do_check_eq ::
 line 472
JS frame :: c:/builds/tbirdhq/objdir-tb/mozilla/_tests/xpcshell/mailnews/compose
/test/unit/head_compose.js :: do_check_transaction :: line 67
JS frame :: c:/builds/tbirdhq/objdir-tb/mozilla/_tests/xpcshell/mailnews/compose
/test/unit/test_bug155172.js :: run_test :: line 92
JS frame :: c:\builds\tbirdhq\mozilla\testing\xpcshell\head.js :: _execute_test
:: line 303
JS frame :: -e :: <TOP_LEVEL> :: line 1
TEST-INFO | (xpcshell/head.js) | exiting test
TEST-UNEXPECTED-FAIL | c:/builds/tbirdhq/objdir-tb/mozilla/_tests/xpcshell/mailn
ews/compose/test/unit/test_bug155172.js | 2147500036 - See following stack:
JS frame :: c:\builds\tbirdhq\mozilla\testing\xpcshell\head.js :: do_throw :: li
ne 420
JS frame :: c:/builds/tbirdhq/objdir-tb/mozilla/_tests/xpcshell/mailnews/compose
/test/unit/test_bug155172.js :: run_test :: line 95
JS frame :: c:\builds\tbirdhq\mozilla\testing\xpcshell\head.js :: _execute_test
:: line 303
JS frame :: -e :: <TOP_LEVEL> :: line 1
TEST-INFO | (xpcshell/head.js) | exiting test
Connection Lost 2152398850
RECV: c210cHRlc3Q=
before 483328, after 479232, break 00000000
###!!! ASSERTION: unknown error, but don't alert user.: 'errorID != UNKNOWN_ERRO
R', file c:/builds/tbirdhq/mailnews/base/util/nsMsgProtocol.cpp, line 467
xul!nsSmtpProtocol::OnStopRequest+0x00000000000000AF (c:\builds\tbirdhq\mailnews
\compose\src\nssmtpprotocol.cpp, line 430)
xul!nsInputStreamPump::OnStateStop+0x00000000000000DE (c:\builds\tbirdhq\mozilla
\netwerk\base\src\nsinputstreampump.cpp, line 579)
xul!nsInputStreamPump::OnInputStreamReady+0x0000000000000090 (c:\builds\tbirdhq\
mozilla\netwerk\base\src\nsinputstreampump.cpp, line 403)
xul!nsInputStreamReadyEvent::Run+0x000000000000004A (c:\builds\tbirdhq\mozilla\x
pcom\io\nsstreamutils.cpp, line 113)
xul!nsThread::ProcessNextEvent+0x00000000000001FA (c:\builds\tbirdhq\mozilla\xpc
om\threads\nsthread.cpp, line 609)
xul!NS_ProcessNextEvent_P+0x0000000000000053 (c:\builds\tbirdhq\objdir-tb\mozill
a\xpcom\build\nsthreadutils.cpp, line 250)
xul!nsThread::Shutdown+0x0000000000000155 (c:\builds\tbirdhq\mozilla\xpcom\threa
ds\nsthread.cpp, line 491)
xul!nsSocketTransportService::Shutdown+0x00000000000000E3 (c:\builds\tbirdhq\moz
illa\netwerk\base\src\nssockettransportservice2.cpp, line 467)
xul!nsIOService::SetOffline+0x0000000000000191 (c:\builds\tbirdhq\mozilla\netwer
k\base\src\nsioservice.cpp, line 729)
xul!nsIOService::Observe+0x00000000000000B3 (c:\builds\tbirdhq\mozilla\netwerk\b
ase\src\nsioservice.cpp, line 921)
xul!nsObserverList::NotifyObservers+0x0000000000000065 (c:\builds\tbirdhq\mozill
a\xpcom\ds\nsobserverlist.cpp, line 131)
xul!nsObserverService::NotifyObservers+0x00000000000000E2 (c:\builds\tbirdhq\moz
illa\xpcom\ds\nsobserverservice.cpp, line 185)

Comment 6

[Joshua Cranmer [:jcranmer]]

Attachment: Patch, version 1.1

Okay, let's make fakeserver a little less eager to close connections, shall we? :-)

Further note to self: test compose + local too when making fakeserver changes. IMAP and NNTP isn't good enough.

Comment 7

[David :Bienvenu]

A lot fewer tests are failing this way, but these two are failing; the first with the same assertion (and probably the second one as well):

TEST-UNEXPECTED-FAIL | c:\builds\tbirdhq\objdir-tb\mozilla\_tests\xpcshell\mailn
ews\compose\test\unit\test_smtpAuthMethods.js | test failed (with xpcshell retur
n code: -2147483645), see following log:
TEST-UNEXPECTED-FAIL | c:\builds\tbirdhq\objdir-tb\mozilla\_tests\xpcshell\mailn
ews\compose\test\unit\test_smtpPasswordFailure1.js | test failed (with xpcshell
return code: -2147483645), see following log:

Comment 8

[Joshua Cranmer [:jcranmer]]

Interesting.. these seem to fail at best randomly for me.

Comment 9

[David :Bienvenu]

This test failed the first time I ran it, and hasn't failed since. I'm not sure what to do with that, unfortunately. Random failures in the unit tests need to be tracked down. I suppose we could see how bad they are on Tinderbox, if indeed they affect Tinderbox at all.

Comment 10

[Joshua Cranmer [:jcranmer]]

Various attempts at getting it to fail on tryserver have failed, although trying to get debug test builds on tryserver was difficult.

I've pushed it for now as changeset 585380321606.

Comment 11

[Joshua Cranmer [:jcranmer]]

One failure on tinderbox so far: <http://tinderbox.mozilla.org/showlog.cgi?log=SeaMonkey/1290562675.1290564227.9646.gz>, out of 6-8.

That backtrace also looks bad.

I'll keep an eye for the next few days to see if it turns up again.