361718 - Command stream end of file, while reading line (Tb silently kills IMAP+SSL/TLS connection upon shutdown, without terminating IDLE/without sending LOGOUT)

Status: RESOLVED WORKSFORME

(MailNews Core :: Networking: IMAP, defect)

Description

[JoungKyun.Kim]

User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.1; ko; rv:1.8.1) Gecko/20061010 Firefox/2.0
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; ko; rv:1.8.1) Gecko/20061010 Firefox/2.0

When close thunderbird 2.0b tinderbox release, imap server remains "ommand stream end of file, while reading line" log message. thunderbird 1.5.x is no problems.

Reproducible: Always

Steps to Reproduce:
1. login imaps account
2. close thunderbird
3.

Actual Results:  
mail log has follow messages every time, and sometimes, mail box crash.

Nov 24 17:19:08 main imapd[26830]: imaps SSL service init from xxx.xxx.xxx.xxx
Nov 24 17:19:08 main imapd[26830]: Authenticated user=oops host=[xxx.xxx.xxx.xxx]
Nov 24 17:19:16 main imapd[26830]: Command stream end of file, while reading line user=oops host=[xxx.xxx.xxx.xxx]
Nov 24 17:19:16 main imapd[26829]: Command stream end of file, while reading line user=oops host=[xxx.xxx.xxx.xxx]
Nov 24 17:19:16 main imapd[26828]: Command stream end of file, while reading line user=oops host=[xxx.xxx.xxx.xxx]
Nov 24 17:19:16 main imapd[26827]: Command stream end of file, while reading line user=oops host=[xxx.xxx.xxx.xxx]

Expected Results:  
no messages

Server Envionments

package: wu-imap-2004g
protocol: imaps

Client Environments

thunderbird tinderbox release 20061123 (2.0 beta 1 - korean version)
http://ftp.mozilla.org/pub/mozilla.org/thunderbird/tinderbox/latest-mozilla1.8-l10n/thunderbird-2.0b1pre.ko.win32.zip

Comment 1

[JoungKyun.Kim]

english version has same problems. I tested 2007.1.1 AM 2:00 tinderbox release.

Comment 2

[Channy Yun [:channy]]

Scott, would you check this problem? Many of IMAP users over SSL was troubled including me.

Comment 3

[JoungKyun.Kim]

This problem occured close thunderbird with close button [x] in title bar on IMAP + TLS or IMAP + SSL.

Comment 4

[David :Bienvenu]

Can you generate the corresponding imap protocol log and attach here, or e-mail me?

http://www.mozilla.org/quality/mailnews/mail-troubleshoot.html#imap

Comment 5

[JoungKyun.Kim]

Attachment: thunderbird protocol debug log on IMAP + (SSL or TLS)

(In reply to comment #4)
> Can you generate the corresponding imap protocol log and attach here, or e-mail
> me?
> 
> http://www.mozilla.org/quality/mailnews/mail-troubleshoot.html#imap
> 

I See. I attached debug log file. And add follow server log (imap 2006e)

Mar  1 18:30:07 main imapd[16146]: imaps SSL service init from 211.187.1.23
Mar  1 18:30:10 main imapd[16146]: Authenticated user=oops host=[211.187.1.23] mech=PLAIN
Mar  1 18:30:28 main imapd[16146]: Unexpected client disconnect, while reading line user=oops host=[211.187.1.23]

Comment 6

[JoungKyun.Kim]

Will be fixed this bug on TB 2.0.0.1 ?

Comment 7

[nitrox]

Same here...

TB 2.0.0.0 + SSL(993) on UW-IMAP 2004.357
On exit i get these "Command stream end of file, while reading line.." logs.

TB 1.5.0.10 was ok.

Hope it´s getting fixed in next release.

Comment 8

[nitrox]

TB 2.0.0.4 + SSL(993) on UW-IMAP 2004.357
On exit i get these "Command stream end of file, while reading line.." logs.

TB 1.5.0.12 was ok.

Still not fixed in 2.0.0.4 :/

There seems to be no progress, although its marked as "critical", how many people do they need to get status changed to "confirmed"?

Comment 9

[JoungKyun.Kim]

I posted with "critical" cause my mail box was crashed. Anyway, I don't know reason of crash. :-)

I think that this problem is clealy bug, but why don't fixed?

Comment 10

[nitrox]

TB 2.0.0.6 + SSL(993) on UW-IMAP 2006j.389
On exit i get these "Command stream end of file, while reading line.." logs.

TB 1.5.0.12 was ok.

Still not fixed in 2.0.0.6 :/

How can we help to find the reason of this nasty bug? i sent a few logs to scotty, maybe he can atleast confirm this bug.

Comment 11

[Scott MacGregor]

confirming, I've gotten a couple e-mails from folks running into this issue. I take it this problem goes away if you turn off SSL / TLS? 

i wonder if this is related to Bug 368611?

Comment 12

[JoungKyun.Kim]

(In reply to comment #11)
> confirming, I've gotten a couple e-mails from folks running into this issue. I
> take it this problem goes away if you turn off SSL / TLS? 

Yes, turn off SSL / TLS, no problems.

> i wonder if this is related to Bug 368611?
> 

I think that Bug 368611 is other case.

Comment 13

[JoungKyun.Kim]

Dose not fix this bug forever? I'm waiting to fix this bug for using TB 2.0.

Comment 14

[WADA:World Anti-bad-Duping Agency]

>thunderbird protocol debug log on IMAP + (SSL or TLS)
> 4004[2610de0]: 25f2328:mail.oops.org:S-INBOX:SendData: 19 IDLE
> 4004[2610de0]: ReadNextLine [stream=255fe28 nb=20 needmore=0]
> 4004[2610de0]: 25f2328:mail.oops.org:S-INBOX:CreateNewLineFromSocket: + Waiting for DONE
> 0[2c46f8]: 25f2328:mail.oops.org:S-INBOX:TellThreadToDie: close socket connection
> 4004[2610de0]: ImapThreadMainLoop leaving [this=25f2328]

(1) Server is waiting for DONE from TB after sending "+ Waiting for DONE".
(2) Tb closes socket immediately without sending DONE, data for closing of session or SSL/TLS connection etc.
This explains following log at IMAP server, and (2) is apparently Tb's fault.
> Command stream end of file, while reading line..

However, IMAP server side behavior after (1) then (2) doesn't seem to be good,
 a. if "Command stream end of file, while reading" is infinitely issued
    at IMAP server, even after unexpected connection loss due to (2) while (1).  
 b. if the connection loss will cause "my mail box was crashed",
    which is reported by you in Comment #0 and Comment #9.
To JoungKyun.Kim(bug opener):
  Is server side setting appropriate?
  (especially setting for SSL/TLS related ones, such as timeout, retry count)

Comment 15

[JoungKyun.Kim]

(In reply to comment #14)
> >thunderbird protocol debug log on IMAP + (SSL or TLS)
> > 4004[2610de0]: 25f2328:mail.oops.org:S-INBOX:SendData: 19 IDLE
> > 4004[2610de0]: ReadNextLine [stream=255fe28 nb=20 needmore=0]
> > 4004[2610de0]: 25f2328:mail.oops.org:S-INBOX:CreateNewLineFromSocket: + Waiting for DONE
> > 0[2c46f8]: 25f2328:mail.oops.org:S-INBOX:TellThreadToDie: close socket connection
> > 4004[2610de0]: ImapThreadMainLoop leaving [this=25f2328]
> 
> (1) Server is waiting for DONE from TB after sending "+ Waiting for DONE".
> (2) Tb closes socket immediately without sending DONE, data for closing of
> session or SSL/TLS connection etc.
> This explains following log at IMAP server, and (2) is apparently Tb's fault.
> > Command stream end of file, while reading line..
> 
> However, IMAP server side behavior after (1) then (2) doesn't seem to be good,
>  a. if "Command stream end of file, while reading" is infinitely issued
>     at IMAP server, even after unexpected connection loss due to (2) while (1). 
>  b. if the connection loss will cause "my mail box was crashed",
>     which is reported by you in Comment #0 and Comment #9.
> To JoungKyun.Kim(bug opener):
>   Is server side setting appropriate?
>   (especially setting for SSL/TLS related ones, such as timeout, retry count)
> 

I make a conjecture cause of mail box crash, but it is arised from other reason. So, on this bug, I don't want to fix crash. I want to fix "Command stream end of file, while reading" log on server side.

my imaps setting is follows.

service imaps
{
    disable = no
    socket_type     = stream
    wait            = no
    user            = root
    server          = /usr/sbin/imapd
    log_on_success  += HOST DURATION
    log_on_failure  += HOST
}

There is no specialy settings.

Comment 16

[WADA:World Anti-bad-Duping Agency]

(In reply to comment #15)
> I make a conjecture cause of mail box crash, but it is arised from other reason.

If so, this bug can't be "critical", unless infinite message loop of "Command stream end of file, while reading line.." by your IMAP server and system crash or freeze due to message loop by the IMAP server(e.g. disk full by syslog).
And, even though your problem is infinite loop and is initiated by TB's bad behavior of above (2) while (1), root cause of such problem(infinite message loop) itself is usually inappropriate IMAP server set-up, because "no response from client due to network error" can occur in any environment/in any situation and IMAP server is responsible to detect error such as "no-response from IMAP client".

To JoungKyun.Kim(bug opener):
Is this bug's problem still "critical"?
Do you still think "keep this bug critical" is proper action as bug processing procedure in bugzilla.mozilla.org?  

Comment 17

[JoungKyun.Kim]

I concur regarding status change from Critical to Normal.

Nevertheless, I disagree that this is a server setting issue, considering the fact that the same settings worked fine for TB 1.5.0.12 and Outlook.  This problem only arises for TB 2.0 using the *SAME* IMAP settings and running environment.  Unless settings for TB 1.5 have changed drastically vis a vis TB 2.0, I can only deduce that this error is being caused by changes in TB 2.0's internal process.  Since *ONLY* TB has changed ( no environment change, no IMAP server/server setting change ) please elaborate on how this is a IMAP server setting issue.  If you still think this is a IMAP server issue, and since we have used TB 1.5 successfully in the past, my only choice will be to revert back to TB 1.5 unless a fix can be suggested.

Comment 18

[WADA:World Anti-bad-Duping Agency]

(In reply to comment #17)
> I concur regarding status change from Critical to Normal.
Thanks for your agreement.

>I disagree that this is a server setting issue,
Please note that I never say server's fault. I say that server is not configured well, if, and only if message loop is initiate by Tb's bad behavior and/or "my mail box was crashed" is caused by Tb's bad behavior. As your NSPR log says, there is apparently TB's fault when SSL/TLS enabled connection termination. It should be executed cleanly because your case is normal termination of TB.

Comment 19

[WADA:World Anti-bad-Duping Agency]

Tb's problem(fault) looks "no IMAP logout command issued with SSL connections"(Bug 471115), and is already fixed by Tb trunk.

JoungKyun.Kim, can you still see the problem with Tb latest-trunk?

Comment 20

[JoungKyun.Kim]

(In reply to comment #19)
> Tb's problem(fault) looks "no IMAP logout command issued with SSL
> connections"(Bug 471115), and is already fixed by Tb trunk.
> JoungKyun.Kim, can you still see the problem with Tb latest-trunk?

I still see on TB2. But, I confirmed that fixed this problem on TB3 last trunk.

On this problems, I got crash mail box 2times. When this problem occures, TB don't delete mail that has DELETE MARK. After close TB, and reopen other mail client, my mail box was crashed. (some times. not alwarys.. --;) So, I'm still using TB 1.5.

I want to fix on TB 2 tree too. Release of TB3 is so far...

Comment 21

[WADA:World Anti-bad-Duping Agency]

Adding some words in bug summary for ease of search.

Comment 22

[Wayne Mery (:wsmwk)]

WFM per comment 20