Last Comment Bug 589759 - Wait 5 minutes without entering password, Thunderbird stops responding/hangs if pop connection was closed while the password prompt was up. [pop]
: Wait 5 minutes without entering password, Thunderbird stops responding/hangs ...
Status: VERIFIED FIXED
[gs][gssolved]
: hang
Product: MailNews Core
Classification: Components
Component: Networking: POP (show other bugs)
: Trunk
: All All
: -- critical with 2 votes (vote)
: Thunderbird 13.0
Assigned To: :aceman
:
Mentors:
http://getsatisfaction.com/mozilla_me...
: 603064 623924 691494 715805 729433 (view as bug list)
Depends on:
Blocks: 691494 699186 729433
  Show dependency treegraph
 
Reported: 2010-08-23 03:15 PDT by Kim Burton
Modified: 2012-06-07 05:53 PDT (History)
20 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---


Attachments
Wireshark Capture -Thunderbird Crash (1.21 KB, application/octet-stream)
2010-08-29 09:30 PDT, Kim Burton
no flags Details
Debug log file (60.95 KB, text/plain)
2010-09-14 13:42 PDT, Kim Burton
no flags Details
Debug file (64.30 KB, text/plain)
2010-09-19 02:38 PDT, Kim Burton
no flags Details
patch (748 bytes, patch)
2011-02-15 08:43 PST, arno renevier
mozilla: feedback+
Details | Diff | Splinter Review
patch v2 (981 bytes, patch)
2012-02-24 13:46 PST, :aceman
mozilla: feedback+
Details | Diff | Splinter Review
patch v3 (1.60 KB, patch)
2012-03-06 10:48 PST, :aceman
mozilla: review+
Details | Diff | Splinter Review

Description Kim Burton 2010-08-23 03:15:19 PDT
User-Agent:       Opera/9.80 (Windows NT 5.1; U; en) Presto/2.6.30 Version/10.61
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-GB; rv:1.9.2.8) Gecko/20100802 Thunderbird/3.1.2

After opening Thunderbird the password dialog is displayed. If nothing is entered for approx 5 minutes, Thunderbird will hang.

Reproducible: Always

Steps to Reproduce:
1. Start Thunderbird (password dialog is displayed.
2. Wait 5 minutes without entering a password.
3. Thunderbird stops responding. 
Actual Results:  
Stops responding

Expected Results:  
Should be able to wait indefinitely for the password to be entered.
Comment 1 Wayne Mery (:wsmwk, NI for questions) 2010-08-23 05:09:12 PDT
I cannot reproduce. Does it reproduce in safe mode ? https://support.mozillamessaging.com/en-US/kb/Safe+Mode
Comment 2 Ludovic Hirlimann [:Usul] 2010-08-23 06:18:57 PDT
What kind of password dialog is showing up - master password - imp/pop password - ldap password ?
Comment 3 Kim Burton 2010-08-23 11:08:01 PDT
Yes this bug still happens in safe mode.

The dialog is the Master Password for the software security device which gets displayed at Thunderbird startup.

I've noticed the following:

After approx 1 min 15 sec "connected to pop.XXXXX.net.." appears in the status bar. This is the second of two POP mail accounts I have Thunderbird set to check. Both pop mail accounts are set for check messages at startup.

On one occasion the caret in the password edit box disappeared. I didn't note the time.

On my next try the caret stopped flashing at about 2 min 10 sec and Thunderbird was unresponsive. Clicking the dialog adds "(Not Responding)" to the dialog title.
Comment 4 Kim Burton 2010-08-27 11:09:52 PDT
Using the same settings this bug does not happen on my Vista Laptop, so maybe something specific to XP or my XP computer.
Comment 5 Michael A. Pasek 2010-08-28 12:15:02 PDT
(In reply to comment #3)
> After approx 1 min 15 sec "connected to pop.XXXXX.net.." appears in the status
> bar. This is the second of two POP mail accounts I have Thunderbird set to
> check. Both pop mail accounts are set for check messages at startup.

This is likely a "bogus connection" ala Bug 533083, but probably unrelated to the "unresponsiveness".

(In reply to comment #4)
> Using the same settings this bug does not happen on my Vista Laptop, so maybe
> something specific to XP or my XP computer.

Just in case it IS related to Bug 533083, are the "Check for new messages at startup" and "Automatically download new messages" settings the same on XP/Vista ?
Comment 6 Kim Burton 2010-08-29 04:09:25 PDT
I have rechecked the settings on both computers. "Check new messages at startup" was not set the same on both computers. I have done a bit more checking and it is only my second email account that causes the problem and I can now replicate this problem on both my XP and Vista computers.

I have set both computers not to automatically check or download messages. By Starting Thunderbird and just clicking get mail from my Freeserve account, I can crash Thunderbird by doing nothing at the Master Password entry and waiting a couple of minutes. 

Since it may be important to understand this bug, the actual pop server I am connecting to is pop.freeserve.net.  So it appears to be caused by something that pop.freeserve.net does whilst waiting for a password.

I don't understand all aspects of Bug 533083 but I think it is likely that is is related in some way. I can't see why there's a need to contact the mail server before the master password has been entered.
Comment 7 Michael A. Pasek 2010-08-29 06:01:34 PDT
(In reply to comment #6)
> I don't understand all aspects of Bug 533083 but I think it is likely that is
> is related in some way. I can't see why there's a need to contact the mail
> server before the master password has been entered.

There isn't -- that's why Bug 533083 was submitted.  The scenario in your case is slightly different, in that the saved passwords are available -- IF you enter the Master Password.  There may be a slightly different set of circumstances that occurs when you don't respond to the password prompt; I'd suspect the server is closing the connection after waiting 3-4 minutes for the "PASS" command.

Can you get a POP3 log of such an occurrence ?  Use "POP3:5":
http://kb.mozillazine.org/Session_logging_for_mail/news
https://wiki.mozilla.org/MailNews:Logging

Have you ever used Wireshark (www.wireshark.org) ?  If you can manage it, a packet capture ("raw", or ".pcap" format) would also be very helpful.

Attach, don't "paste" the log (and the packet capture if possible).
Comment 8 Kim Burton 2010-08-29 07:22:40 PDT
(In reply to comment #7)
> (In reply to comment #6)
> > I don't understand all aspects of Bug 533083 but I think it is likely that is
> > is related in some way. I can't see why there's a need to contact the mail
> > server before the master password has been entered.
> 
> There isn't -- that's why Bug 533083 was submitted.  The scenario in your case
> is slightly different, in that the saved passwords are available -- IF you
> enter the Master Password.  There may be a slightly different set of
> circumstances that occurs when you don't respond to the password prompt; I'd
> suspect the server is closing the connection after waiting 3-4 minutes for the
> "PASS" command.
> 
> Can you get a POP3 log of such an occurrence ?  Use "POP3:5":
> http://kb.mozillazine.org/Session_logging_for_mail/news
> https://wiki.mozilla.org/MailNews:Logging
> 
> Have you ever used Wireshark (www.wireshark.org) ?  If you can manage it, a
> packet capture ("raw", or ".pcap" format) would also be very helpful.
> 
> Attach, don't "paste" the log (and the packet capture if possible).

I have set up a batch file with the following contents:

set NSPR_LOG_MODULES=pop:5
set NSPR_LOG_FILE=%APPDATA%\kimspop.log
"C:\Program Files\Mozilla Thunderbird\thunderbird.exe"

The log file produced is empty, 0 bytes.

I will attempt wireshark and report back, but have no idea how to attach anything to these messages.
Comment 9 Wayne Mery (:wsmwk, NI for questions) 2010-08-29 07:31:20 PDT
kim, you need pop3:5  not pop:5  :)
Comment 10 Michael A. Pasek 2010-08-29 08:31:09 PDT
(In reply to comment #9)
> kim, you need pop3:5  not pop:5  :)

[Thanks, Wayne]  To attach something to a bug report, use the "Add an attachment" link, just above the original problem description (left-hand side).
Comment 11 Kim Burton 2010-08-29 09:27:42 PDT
I just started uploading the log file, then noticed it was huge, approx 20mb! So I've aborted. I've typed the file and it contains thousands of lines "0[1b29140]: POP3: Entering state: 47" 

The main bit of the file is:

0[1b29140]: Setting server busy in nsPop3Protocol::LoadUrl
0[1b29140]: Entering NET_ProcessPop3 32
0[1b29140]: POP3: Entering state: 1
0[1b29140]: POP3: Entering state: 2
0[1b29140]: POP3: Entering state: 4
0[1b29140]: RECV: +OK connected to pop3 on 3611 
0[1b29140]: POP3: Entering state: 26
0[1b29140]: SEND: AUTH0[1b29140]: Entering NET_ProcessPop3 22
0[1b29140]: POP3: Entering state: 3
0[1b29140]: RECV: -ERR unknown command
0[1b29140]: POP3: Entering state: 27
0[1b29140]: POP3: Entering state: 28
0[1b29140]: SendCapa()
0[1b29140]: SEND: CAPA0[1b29140]: Entering NET_ProcessPop3 22
0[1b29140]: POP3: Entering state: 3
0[1b29140]: RECV: -ERR unknown command
0[1b29140]: POP3: Entering state: 29
0[1b29140]: POP3: Entering state: 30
0[1b29140]: ProcessAuth()
0[1b29140]: POP auth: server caps 0x4AA, pref 0x1C00, failed 0x0, avail caps 0x400
0[1b29140]: (GSSAPI = 0x100000, CRAM = 0x2000, APOP = 0x4000, NTLM = 0x8000, MSN =  

0x10000, PLAIN = 0x1000, LOGIN = 0x800, USER/PASS = 0x400)
0[1b29140]: trying auth method 0x400
0[1b29140]: POP username
0[1b29140]: POP3: Entering state: 5
0[1b29140]: OnPromptStart()
0[1b29140]: Entering NET_ProcessPop3 48
0[1b29140]: POP3: Entering state: 47
0[1b29140]: POP3: Entering state: 47........etc.

I will upload the wireshark capture and if I'm reading this correctly pop.freeserve.net responds with a "Disconnect because authentication is too long" message in a malformed packet.
Comment 12 Kim Burton 2010-08-29 09:30:01 PDT
Created attachment 470301 [details]
Wireshark Capture -Thunderbird Crash

Wireshark Capture.
Comment 13 Michael A. Pasek 2010-08-29 11:13:15 PDT
The disconnect occurs after one minute (and, as the reporter notes, is malformed because it does not begin with -ERR).  It's possible the disconnect is causing a loop (i.e., POP handler doesn't recognize the connection's gone).

I don't know if the behavior noted in Bug 533083 (or the disconnect therefrom) is what's causing the hang, though.  I tried to recreate using just a plain password prompt (I have no master PW), and I didn't "hang" even though the connection was closed by server after 1 minute -- the code path could be different for the master PW case, though.
Comment 14 Kim Burton 2010-08-29 12:46:48 PDT
It should be easy to recreate the hang by just setting any mail account to point to pop.freeserve.net. It wouldn't have to actually log in to that server as the hang occurs before any username or password is sent.
Comment 15 Michael A. Pasek 2010-08-29 16:05:59 PDT
I don't have any saved passwords, nor a MasterPW, but the problem does NOT happen by just letting the server password prompt sit for 10 minutes; the POP log never shows state 47.  That code is all new, and was added by changeset "5495:2fb73ad3a589".

Anybody (besides Kim) happen to have saved passwords & a Master Password, who can recreate & set status to "NEW" ?
Comment 16 Kim Burton 2010-09-11 08:50:56 PDT
Bug still there in latest release:

Mozilla/5.0 (Windows; U; Windows NT 5.1; en-GB; rv:1.9.2.9) Gecko/20100825 Thunderbird/3.1.3
Comment 17 Ludovic Hirlimann [:Usul] 2010-09-14 01:42:04 PDT
Can you give us a stack trace as described at https://developer.mozilla.org/en/How_to_get_a_stacktrace_with_WinDbg ?
Comment 18 Kim Burton 2010-09-14 13:42:32 PDT
Created attachment 475200 [details]
Debug log file
Comment 19 Kim Burton 2010-09-14 13:50:14 PDT
I've attached the log file from windbg. I tried changing Firefox to Thunderbird when following the instructions on the link, but got an error when loading the symbols. If it isn't any good, I can try again if you can supply the correct URL to the Thunderbird symbols.
Comment 20 Ludovic Hirlimann [:Usul] 2010-09-15 10:05:21 PDT
http://symbols.mozilla.org/thunderbird should do it
Comment 21 Kim Burton 2010-09-19 02:38:37 PDT
Created attachment 476617 [details]
Debug file

Second go at creating a stack trace.
Comment 22 Kim Burton 2010-09-19 02:43:50 PDT
Debug file has been uploaded, hope it helps.
Note: hook.dll is part of my mouse driver.

Problem still exists with version Mozilla/5.0 (Windows; U; Windows NT 5.1; en-GB; rv:1.9.2.9) Gecko/20100915 Thunderbird/3.1.4

If Thunderbird is left long enough without a master password entered it will eventually crash my entire computer.
Comment 23 Ludovic Hirlimann [:Usul] 2010-09-21 08:08:32 PDT
(In reply to comment #21)
> Created attachment 476617 [details]
> Debug file
> 
> Second go at creating a stack trace.

David anything interesting here ?
Comment 24 David :Bienvenu 2010-09-21 08:45:54 PDT
yeah, that stack trace is potentially illuminating - I suspect we're spinning forever in the   while(!m_pop3ConData->pause_for_read) loop. We may not have realized that the connection was closed while the password prompt was up.
Comment 25 Matthias Versen [:Matti] 2010-10-09 06:48:24 PDT
*** Bug 603064 has been marked as a duplicate of this bug. ***
Comment 26 Kim Burton 2010-12-03 14:29:01 PST
Any progress fixing this bug?
Comment 27 Matthias Versen [:Matti] 2011-01-07 16:52:43 PST
*** Bug 623924 has been marked as a duplicate of this bug. ***
Comment 28 Wayne Mery (:wsmwk, NI for questions) 2011-01-09 07:10:52 PST
xref pop Bug 533006 - We don't notice that the server closed the connection after failed password

I may have seen something like this on wife's work computer, but think her accounts are all imap - off to do some digging
Comment 30 arno renevier 2011-02-15 02:12:18 PST
I can reproduce the bug with pop.sfr.fr on linux platform
Comment 31 arno renevier 2011-02-15 08:40:32 PST
(In reply to comment #24)
> yeah, that stack trace is potentially illuminating - I suspect we're spinning
> forever in the   while(!m_pop3ConData->pause_for_read) loop. We may not have
> realized that the connection was closed while the password prompt was up.

One of the problems is that, when m_pop3ConData->next_state is not trapped by the switch cases and ends up in the default statement, an infinite loop happens. Returning after NS_ERROR prevents the interface from freezing (but may be it does not fix the root problem, I'm not sure)
Comment 32 arno renevier 2011-02-15 08:43:26 PST
Created attachment 512500 [details] [diff] [review]
patch

return after NS_ERROR to avoid infinite loop
Comment 33 WADA 2011-02-15 09:17:39 PST
(In reply to comment #32)
> patch
> return after NS_ERROR to avoid infinite loop

No need of NSPR logging or assertion for ease of problem analysis?
It's done by caller if NS_ERROR_FAILURE is returned from nsPop3Protocol::ProcessProtocol?
Comment 34 arno renevier 2011-02-21 07:50:51 PST
(In reply to comment #32)
> Created attachment 512500 [details] [diff] [review]
> patch
> 
> return after NS_ERROR to avoid infinite loop

When using this patch, thunderbird does not try to prompt for password any more to the server until thunderbird is restarted.
You may also want to remove 
ClearFlag(POP3_PASSWORD_FAILED|POP3_AUTH_FAILURE);
in nsPop3Protocol::OnStopRequest so thunderbird will prompt for password again. I'm not sure of all the drawbacks of this modifications.
Comment 35 Mark Banner (:standard8) (afk until 26th July) 2011-04-21 01:53:25 PDT
Comment on attachment 512500 [details] [diff] [review]
patch

David, this patch has been up for a bit, can you take a look?
Comment 36 David :Bienvenu 2011-04-21 07:37:24 PDT
Comment on attachment 512500 [details] [diff] [review]
patch

What is the unexpected state, I wonder? And does the patch in bug 428611, which has to do with our handling of dropped connections, affect this?

I'd really prefer to see a explicit case statement for the unexpected state we're getting to, and some code to handle it, even if that code is to return NS_ERROR_FAILURE (and I think you might be right about clearing the auth failure flags). This approach might be an acceptable stop-gap, but I'd really prefer something explicit.
Comment 37 Rik 2011-05-10 03:36:41 PDT
I have the same problems:

If i spent too much time to answer the master-password-dialog, the dialog consumes 100% CPU-Power and there is no chance to type in the passwort.

My Scenario: Windows XP, 3x POP accounts (no freenet), 
autostart-folder contains: firefox, thunderbird, ...
Comment 38 Wayne Mery (:wsmwk, NI for questions) 2011-06-16 03:15:04 PDT
http://getsatisfaction.com/mozilla_messaging/topics/thunderbird_freezes_when_the_user_doesnt_log_in_fast_enough is potentially a report of this.
Comment 39 :aceman 2011-10-17 14:02:22 PDT
I can confirm comment 31.
On the server from comment 30, there is an infinite loop saying "POP3: Entering state: 47" that fills the logfile.

This does not happen on my normal pop3 server.
Comment 40 :aceman 2012-01-09 01:28:47 PST
*** Bug 715805 has been marked as a duplicate of this bug. ***
Comment 41 Cyril C. 2012-01-28 09:45:54 PST
User agent: Mozilla/5.0 (Windows NT 5.1; rv:9.0) Gecko/20111222 Thunderbird/9.0.1

I confirm that i had the problem with pop.sfr.fr

After disabling the "check mail on start up" for this specific account, i cannot reproduce the problem anymore.
Comment 42 Wayne Mery (:wsmwk, NI for questions) 2012-02-17 08:51:24 PST
arno, are you up for taking another swing at this?


(In reply to David :Bienvenu from comment #36)
> Comment on attachment 512500 [details] [diff] [review]
> patch
> 
> What is the unexpected state, I wonder? And does the patch in bug 428611,
> which has to do with our handling of dropped connections, affect this?
> 
> I'd really prefer to see a explicit case statement for the unexpected state
> we're getting to, and some code to handle it, even if that code is to return
> NS_ERROR_FAILURE (and I think you might be right about clearing the auth
> failure flags). This approach might be an acceptable stop-gap, but I'd
> really prefer something explicit.
Comment 43 Wayne Mery (:wsmwk, NI for questions) 2012-02-19 14:37:45 PST
*** Bug 691494 has been marked as a duplicate of this bug. ***
Comment 44 Wayne Mery (:wsmwk, NI for questions) 2012-02-22 03:52:28 PST
Arno seems to be gone.
Comment 45 :aceman 2012-02-22 04:01:19 PST
Maybe POP3 would be a better component for this.
Comment 47 :aceman 2012-02-22 04:54:27 PST
I consider it a bug in bugzilla, that when changing component it resets the assignee by default :) It should only do it if the previous assignee was the previous component's default one.

Actually couldn't find any dupes in the linked query.
Comment 48 Ludovic Hirlimann [:Usul] 2012-02-22 07:43:14 PST
Aceman are you taking up the pacth ?
Comment 49 :aceman 2012-02-22 07:50:43 PST
I had to assign this to myself 2 times today. So it seems I'll look into it :)
Comment 50 Ludovic Hirlimann [:Usul] 2012-02-23 02:16:34 PST
*** Bug 729433 has been marked as a duplicate of this bug. ***
Comment 51 :aceman 2012-02-24 12:16:05 PST
The problem still happens in TB13.
In the log you can see these states:
POP3_FINISH_OBTAIN_PASSWORD_BEFORE_USERNAME, ( 48)
POP3_OBTAIN_PASSWORD_BEFORE_USERNAME,       ( 47) - spinning in this state.

-1218537216[b734e1c0]: POP username
-1218537216[b734e1c0]: POP3: Entering state: 5
-1218537216[b734e1c0]: OnPromptStart()
-1218537216[b734e1c0]: Entering NET_ProcessPop3 48
-1218537216[b734e1c0]: POP3: Entering state: 47
-1218537216[b734e1c0]: ###!!! ASSERTION: Got to unexpected state in nsPop3Protocol::ProcessProtocolState: 'Error', file /var/SSD/TB-hg/mailnews/local/src/nsPop3Protocol.cpp, line 4170
-1218537216[b734e1c0]: POP3: Entering state: 47
-1218537216[b734e1c0]: ###!!! ASSERTION: Got to unexpected state in nsPop3Protocol::ProcessProtocolState: 'Error', file /var/SSD/TB-hg/mailnews/local/src/nsPop3Protocol.cpp, line 4170

From the log I can't see if the server closed the connection.

On a normal server the log is like this:
-1218586368[b734e1c0]: OnPromptStart()
-1218586368[b734e1c0]: Entering NET_ProcessPop3 0
-1218586368[b734e1c0]: POP3: Entering state: 24
-1218586368[b734e1c0]: POP3: Entering state: 25
-1218586368[b734e1c0]: Clearing server busy in POP3_FREE
-1218586368[b734e1c0]: Clearing running protocol in POP3_FREE
-1218586368[b734e1c0]: WARNING: NS_ENSURE_SUCCESS(rv, false) failed with result 0x8000FFFF: file /var/SSD/TB-hg/mozilla/content/base/src/nsContentUtils.cpp, line 2625
-1218586368[b734e1c0]: WARNING: NS_ENSURE_TRUE(pusher.Push(aBoundElement)) failed: file /var/SSD/TB-hg/mozilla/content/xbl/src/nsXBLProtoImplMethod.cpp, line 359
-1218586368[b734e1c0]: WARNING: NS_ENSURE_SUCCESS(rv, false) failed with result 0x8000FFFF: file /var/SSD/TB-hg/mozilla/content/base/src/nsContentUtils.cpp, line 2625
-1218586368[b734e1c0]: WARNING: NS_ENSURE_TRUE(pusher.Push(aBoundElement)) failed: file /var/SSD/TB-hg/mozilla/content/xbl/src/nsXBLProtoImplMethod.cpp, line 359
-1218586368[b734e1c0]: ###!!! ASSERTION: Invalid next_state in GetNextPasswordObtainState: 'Not Reached', file /var/SSD/TB-hg/mailnews/local/src/nsPop3Protocol.cpp, line 744
-1218586368[b734e1c0]: Entering NET_ProcessPop3 0
-1218586368[b734e1c0]: POP3: Entering state: 24
-1218586368[b734e1c0]: POP3: Entering state: 25
-1218586368[b734e1c0]: Clearing server busy in POP3_FREE
-1218586368[b734e1c0]: Clearing running protocol in POP3_FREE
-1218586368[b734e1c0]: Calling ReleaseFolderLock from ~nsPop3Sink

The connection is probably closed too so providing the password does not help. But there is no loop.
Comment 52 :aceman 2012-02-24 13:46:53 PST
Created attachment 600510 [details] [diff] [review]
patch v2

This is my attempt at this.

I do not yet know why we get into POP3_OBTAIN_PASSWORD_BEFORE_USERNAME in ProcessProtocolState. The function does not check for that state it should probably be processed somewhere else (in the GetAsyncPassword functionality?).

Adding the status=-1 to the unknown case makes the function exit cleanly with POP3_ERROR_DONE. Cancelling or filling the password prompt makes subsequent connections work fine (either asking the password again or connecting with the username and password obtained). I tested this with the real password dialog, not password manager.
Comment 53 David :Bienvenu 2012-03-05 16:04:00 PST
Comment on attachment 600510 [details] [diff] [review]
patch v2

I'd probably prefer an explicit check for the state we're getting into in the switch.
Comment 54 :aceman 2012-03-06 10:48:36 PST
Created attachment 603352 [details] [diff] [review]
patch v3

Ok.
Comment 55 David :Bienvenu 2012-03-08 16:38:26 PST
Comment on attachment 603352 [details] [diff] [review]
patch v3

thx for the patch
Comment 56 Ryan VanderMeulen [:RyanVM] 2012-03-09 14:46:46 PST
http://hg.mozilla.org/comm-central/rev/9ebce24271f8

For future patches, please try to make the checkin comment more descriptive of what the patch is actually doing rather than just re-stating the bug title. Thanks!
Comment 57 Wayne Mery (:wsmwk, NI for questions) 2012-06-07 05:53:04 PDT
https://getsatisfaction.com/mozilla_messaging/topics/thunderbird_freezes_when_the_user_doesnt_log_in_fast_enough confirms fixed in v13

Note You need to log in before you can comment on or make changes to this bug.