Closed Bug 897854 Opened 11 years ago Closed 9 years ago

cannot connect to imap server (server doesn't correctly respond to ' list "" "*"' after bug 799821), and if server receives FIN from PC's TCP, connection enters CLOSE_WAIT, and server's TCP sends FIN after timeout detection, connection enters TIME_WAIT

Categories

(Thunderbird :: Mail Window Front End, defect)

Product:
Thunderbird
Component:
Mail Window Front End
Version:
24 Branch
Platform:
x86_64
Windows 7
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED INVALID

People

(Reporter: gworley, Unassigned)

Details

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:16.0; WUID=e44baded1c92cf712b201676e1a4568c; WTB=3253) Gecko/20100101 Firefox/16.0 (Beta/Release)
Build ID: 20130618035212

Steps to reproduce:

Tied to connect to my IMAP4 server and connecting properly is not working.


Actual results:

With 17.0.7, I am able to connect to my IMAP4 server.    The log files from the Mdeamon:

Thu 2013-07-25 00:08:02: [4442:11] Session 4442; child 11
Thu 2013-07-25 00:08:02: [4442:11] Accepting IMAP connection from [64.183.132.254:62836] to [172.16.0.2:143]
Thu 2013-07-25 00:08:02: [4442:11] --> * OK pic.dyndns.org IMAP4rev1 MDaemon 13.0.4 ready
Thu 2013-07-25 00:08:14: [4442:11] <-- 1 capability
Thu 2013-07-25 00:08:14: [4442:11] --> * CAPABILITY IMAP4rev1 NAMESPACE AUTH=CRAM-MD5 AUTH=LOGIN AUTH=PLAIN IDLE COMPRESS=DEFLATE ACL UNSELECT UIDPLUS QUOTA BINARY
Thu 2013-07-25 00:08:14: [4442:11] --> 1 OK CAPABILITY completed
Thu 2013-07-25 00:08:22: [4442:11] <-- 2 authenticate CRAM-MD5
Thu 2013-07-25 00:08:22: [4442:11] --> + PE1EQUVNT04tRjIwMTMwNzI1MDAwOC5BQTA4MjI3MDNNRDAwMTJAcGljLmR5bmRucy5vcmc+
Thu 2013-07-25 00:08:22: [4442:11] <-- Z3dvcmxleUBieWdlb3JnZWNvbXB1dGVyLmNvbSBmOGZiZmFhMjdhMjA1NzYwOTg0ODBkZjY0NDNkMzA0Mw==
Thu 2013-07-25 00:08:22: [4442:11] Authenticated as gworley@pic.dyndns.org
Thu 2013-07-25 00:08:22: [4442:11] --> 2 OK AUTHENTICATE completed
Thu 2013-07-25 00:08:22: [4442:11] <-- 3 namespace
Thu 2013-07-25 00:08:22: [4442:11] --> * NAMESPACE (("" "/")) (("Shared Folders/" "/")) (("Public Folders/" "/"))
Thu 2013-07-25 00:08:22: [4442:11] --> 3 OK NAMESPACE completed
Thu 2013-07-25 00:08:22: [4442:11] <-- 4 COMPRESS DEFLATE
Thu 2013-07-25 00:08:22: [4442:11] --> 4 OK DEFLATE active
Thu 2013-07-25 00:08:22: [4442:11] <-- 5 lsub "" "*"

and the server starts listing the folders (which I don't believe is not needed when the folders haven't changed)

With EarlyBird 24.0a2 (2013-07-24) the log file is follows:
Wed 2013-07-24 18:42:21: [4097:9] Session 4097; child 9
Wed 2013-07-24 18:42:21: [4097:9] Accepting IMAP connection from [64.183.132.254:51538] to [172.16.0.2:143]
Wed 2013-07-24 18:42:21: [4097:9] --> * OK pic.dyndns.org IMAP4rev1 MDaemon 13.0.4 ready
Wed 2013-07-24 18:42:21: [4097:9] <-- 1 capability
Wed 2013-07-24 18:42:21: [4097:9] --> * CAPABILITY IMAP4rev1 NAMESPACE AUTH=CRAM-MD5 AUTH=LOGIN AUTH=PLAIN IDLE COMPRESS=DEFLATE ACL UNSELECT UIDPLUS QUOTA BINARY
Wed 2013-07-24 18:42:21: [4097:9] --> 1 OK CAPABILITY completed
Wed 2013-07-24 18:42:21: [4097:9] <-- 2 authenticate CRAM-MD5
Wed 2013-07-24 18:42:21: [4097:9] --> + PE1EQUVNT04tRjIwMTMwNzI0MTg0Mi5BQTQyMjE1OTNNRDAwMTJAcGljLmR5bmRucy5vcmc+
Wed 2013-07-24 18:42:21: [4097:9] <-- Z3dvcmxleUBieWdlb3JnZWNvbXB1dGVyLmNvbSBiNGM5M2QyMzBkN2ZlODQxOTY5NGEwM2Q1N2VkMzc0Mw==
Wed 2013-07-24 18:42:21: [4097:9] Authenticated as gworley@pic.dyndns.org
Wed 2013-07-24 18:42:21: [4097:9] --> 2 OK AUTHENTICATE completed
Wed 2013-07-24 18:42:21: [4097:9] <-- 3 COMPRESS DEFLATE
Wed 2013-07-24 18:42:21: [4097:9] --> 3 OK DEFLATE active
Wed 2013-07-24 18:42:21: [4097:9] <-- 4 list "" "*"

and for the next 10 to 15 minutes it sets there without any output from the server. Then it will list the first 10 folders then pause for another 10 minutes next the next thing in the log file a winsock error 10053 in the middle of listing the folders and never complete listing of the folders.   I have about 400 private folders and about 400 public folders.

Even though I have a limit of 4 imap sessions defined in the server settings I at one time had 100 imap sessions attempted sessions at one time.


Expected results:

An established IMAP session.
Component: Untriaged → Mail Window Front End
> Bug summary : cannot connect to imap server

It's wrong.
According to IMAP log, Tb did successfully login to server, and Tb sent "COMPRESS DEFLATE", and your IMAP server returned OK response to "COMPRESS DEFLATE" correctly.

According to IMAP log, problem with Tb 24 is :
  Your server doesn't respond to '4 list "" "*"' correctly.
Because response to list command is multi-line response, as seen in IMAP log with Tb 17, log line should be written for each list response line, if response is returned from server correctly. 

Difference between Tb 17 and Tb 24 is:
  Tb 17 : NAMESPACE command is sent before "lsub" command.
          5 lsub "" "*"
  Tb 24 : NAMESPACE command is NOT sent before "list" command.
          4 list "" "*"

Is same profile used?
Is "show subscribed folders only" checked in both cases? (Server Settings/Avdanced) 

Is your IMAP server properly configured?
e.g. (a) Expects NAMESPACE command always. (b) When 'list "" "*"' is sent from IMAP client, your server can't run normally.
See bug 859269 for example of (b).

What is your "NAMESPACE" setting in Server Settings/Advanced?

Do you enable "outgoing mail scanner"(port scan type or proxy type. SSL tunnel type if SSL is used) of anti-virus software for this IMAP account? Or you use proxy server for this IMAP account?
If so, it may be problem in IMAP proxy when NAMESPACE command is not issued because "allow server to override" is disabled.

It may be Tb's response parser problem when NAMESPACE command response is not received.
> Even though I have a limit of 4 imap sessions defined in the server settings
> I at one time had 100 imap sessions attempted sessions at one time.

After TCP connection loss, TCP connection is kept with TIME-WAIT or CLOSE-WAIT status. This is design of TCP. This is "no Socket is opened" for application like Tb. So, by next try of server connection, new TCP connection is established.
Are you talking about many TCP connections of TIME-WAIT or CLOSE-WAIT status? (check by "NETSTAT /n /b /o" at Command Prompt)
(In reply to WADA from comment #1)
> > Bug summary : cannot connect to imap server
> 
> It's wrong.
> According to IMAP log, Tb did successfully login to server, and Tb sent
> "COMPRESS DEFLATE", and your IMAP server returned OK response to "COMPRESS
> DEFLATE" correctly.

As far is as I am concerned if I cannot get to my inbox in 24 then there is no true connection established. There may have been login but there is nothing really being transferred except that of trying to establish namespace which it never does while 17 does establish name space.  So IMHO no true login -- meaning being able to read email -- happens.
(In reply to WADA from comment #2)
> > Even though I have a limit of 4 imap sessions defined in the server settings
> > I at one time had 100 imap sessions attempted sessions at one time.
> 
> After TCP connection loss, TCP connection is kept with TIME-WAIT or
> CLOSE-WAIT status. This is design of TCP. This is "no Socket is opened" for
> application like Tb. So, by next try of server connection, new TCP
> connection is established.
> Are you talking about many TCP connections of TIME-WAIT or CLOSE-WAIT
> status? (check by "NETSTAT /n /b /o" at Command Prompt)

This has nothing to due with local TCP connection stack.  It has to do with how many connections are being established on my server -- at one point on the Mdaemon console there was over 100 sessions where 24 was trying to establish namespace and for what ever reason could not.   The Mdaemon server was soon getting Winsock 10053 - WSAECONNABORTED: Software caused connection abort. An established connection was aborted by the software in your host computer, possibly due to a data transmission time-out or protocol error.

This means that Thunderbird aborted the connection in the middle of trying to establish namespace with the server.
(In reply to WADA from comment #1)

> Difference between Tb 17 and Tb 24 is:
>   Tb 17 : NAMESPACE command is sent before "lsub" command.
>           5 lsub "" "*"
>   Tb 24 : NAMESPACE command is NOT sent before "list" command.
>           4 list "" "*"
> 
> Is same profile used?

It happened on the same profile then I created a new profile for TB 24 without any add-ons.  With the same results.

> Is "show subscribed folders only" checked in both cases? (Server
> Settings/Avdanced) 

Yes and then no with same results.

> Is your IMAP server properly configured?
> e.g. (a) Expects NAMESPACE command always. (b) When 'list "" "*"' is sent
> from IMAP client, your server can't run normally.
> See bug 859269 for example of (b).

a) I have no way of configuring this Mdeamon.  With other clients I haven't had this problem.   Thunderbird is the only one that I see a complete listing of all of my folders unless I ask for folder reset.
> 
> What is your "NAMESPACE" setting in Server Settings/Advanced?
> 
> Do you enable "outgoing mail scanner"(port scan type or proxy type. SSL
> tunnel type if SSL is used) of anti-virus software for this IMAP account? Or
> you use proxy server for this IMAP account?

No

> If so, it may be problem in IMAP proxy when NAMESPACE command is not issued
> because "allow server to override" is disabled.
 
> It may be Tb's response parser problem when NAMESPACE command response is
> not received.


I created another account on my server that doesn't have over 400 folders and the result was almost instantaneous that I got connected and was able to read email on that folder:

Thu 2013-07-25 12:15:16: [909:1] Session 909; child 1
Thu 2013-07-25 12:15:16: [909:1] Accepting IMAP connection from [64.183.132.254:54158] to [172.16.0.2:143]
Thu 2013-07-25 12:15:16: [909:1] --> * OK pic.dyndns.org IMAP4rev1 MDaemon 13.0.4 ready
Thu 2013-07-25 12:15:16: [909:1] <-- 1 capability
Thu 2013-07-25 12:15:16: [909:1] --> * CAPABILITY IMAP4rev1 NAMESPACE AUTH=CRAM-MD5 AUTH=LOGIN AUTH=PLAIN IDLE COMPRESS=DEFLATE ACL UNSELECT UIDPLUS QUOTA BINARY
Thu 2013-07-25 12:15:16: [909:1] --> 1 OK CAPABILITY completed
Thu 2013-07-25 12:15:16: [909:1] <-- 2 authenticate CRAM-MD5
Thu 2013-07-25 12:15:16: [909:1] --> + PE1EQUVNT04tRjIwMTMwNzI1MTIxNS5BQTE1MTY2NzFNRDAwMTJAcGljLmR5bmRucy5vcmc+
Thu 2013-07-25 12:15:16: [909:1] <-- dHJpbml0eWVjIDExZDgwMmE4MmFjMmQxOTI1ZmZlZGQ1NjY4YjUyYmU1
Thu 2013-07-25 12:15:16: [909:1] Authenticated as trinityec@pic.dyndns.org
Thu 2013-07-25 12:15:16: [909:1] --> 2 OK AUTHENTICATE completed
Thu 2013-07-25 12:15:16: [909:1] <-- 3 namespace
Thu 2013-07-25 12:15:16: [909:1] --> * NAMESPACE (("" "/")) (("Shared Folders/" "/")) (("Public Folders/" "/"))
Thu 2013-07-25 12:15:16: [909:1] --> 3 OK NAMESPACE completed
Thu 2013-07-25 12:15:16: [909:1] <-- 4 COMPRESS DEFLATE
Thu 2013-07-25 12:15:16: [909:1] --> 4 OK DEFLATE active
Thu 2013-07-25 12:15:16: [909:1] <-- 5 list "" "*"
Thu 2013-07-25 12:15:24: [909:1] --> * LIST () "/" "INBOX"
Thu 2013-07-25 12:15:24: [909:1] --> * LIST () "/" "Contacts"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Drafts"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Junk E-mail"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Junk"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Sent"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Trash"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Public Folders/Bayesian Learning"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Public Folders/Gay PICS"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Public Folders/Trinity Times"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Public Folders/Bayesian Learning/Non-Spam"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Public Folders/Bayesian Learning/Spam"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Public Folders/Gay PICS/AlexBoys"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Public Folders/Mail Archive/Yahoo/foot-torture-videos"
Thu 2013-07-25 12:15:25: [909:1] --> 5 OK LIST completed
Thu 2013-07-25 12:15:25: [909:1] <-- 6 lsub "" "*"
Thu 2013-07-25 12:15:25: [909:1] --> * LSUB () "/" "Trash"
Thu 2013-07-25 12:15:25: [909:1] --> * LSUB () "/" "Junk"
Thu 2013-07-25 12:15:25: [909:1] --> * LSUB () "/" "Drafts"
Thu 2013-07-25 12:15:25: [909:1] --> * LSUB () "/" "Sent"
Thu 2013-07-25 12:15:25: [909:1] --> 6 OK LSUB completed
Thu 2013-07-25 12:15:25: [909:1] <-- 7 list "" "Shared Folders/*"
Thu 2013-07-25 12:15:25: [909:1] --> 7 OK LIST completed
Thu 2013-07-25 12:15:25: [909:1] <-- 8 lsub "" "Shared Folders/*"
Thu 2013-07-25 12:15:25: [909:1] --> 8 OK LSUB completed
Thu 2013-07-25 12:15:25: [909:1] <-- 9 list "" "Public Folders/*"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Public Folders/Bayesian Learning"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Public Folders/Trinity Times"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Public Folders/Bayesian Learning/Non-Spam"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Public Folders/Bayesian Learning/Spam"
Thu 2013-07-25 12:15:25: [909:1] --> * LIST () "/" "Public Folders/Mail Archive/Yahoo/foot-torture-videos"
Thu 2013-07-25 12:15:25: [909:1] --> 9 OK LIST completed
Thu 2013-07-25 12:15:25: [909:1] <-- 10 lsub "" "Public Folders/*"
Thu 2013-07-25 12:15:25: [909:1] --> 10 OK LSUB completed
(In reply to George Worley from comment #5)
> I created another account on my server that doesn't have over 400 folders
> and the result was almost instantaneous that I got connected and was able to read email on that folder:

Log after "2 OK AUTHENTICATE completed",
> Thu 2013-07-25 12:15:16: [909:1] <-- 3 namespace
> Thu 2013-07-25 12:15:16: [909:1] --> * NAMESPACE (("" "/")) (("Shared
> Folders/" "/")) (("Public Folders/" "/"))
> Thu 2013-07-25 12:15:16: [909:1] --> 3 OK NAMESPACE completed
> Thu 2013-07-25 12:15:16: [909:1] <-- 4 COMPRESS DEFLATE
> Thu 2013-07-25 12:15:16: [909:1] --> 4 OK DEFLATE active
> Thu 2013-07-25 12:15:16: [909:1] <-- 5 list "" "*"
> Thu 2013-07-25 12:15:24: [909:1] --> * LIST () "/" "INBOX"
>(snip)
> Thu 2013-07-25 12:15:25: [909:1] --> 5 OK LIST completed
> Thu 2013-07-25 12:15:25: [909:1] <-- 6 lsub "" "*"
> Thu 2013-07-25 12:15:25: [909:1] --> 6 OK LSUB completed

(C) Tb 24 : account of less than 400 folders
            NAMESPACE command is sent before "list", "lsub" command.
            5 list "" "*"
            => LIST response normally returned. 
            6 lsub "" "*"
            => LSUB response normally returned.

What is difference from following in comment #0?
I can't imagine reason why NAMESPACE command was sent by Tb in case (C) but NAMESPACE command is NOT sent in case (B), if difference between case (C) and cace (B) is "number of folders of IMAP account" only.

> (A) Tb 17 : account of more than 400 folders
>             NAMESPACE command is sent before "lsub" command.
>             5 lsub "" "*"
>             => LSUB response normally returned.
> (B) Tb 24 : account of more than 400 folders
>             NAMESPACE command is NOT sent before "list" command.
>             4 list "" "*"
>             => LIST response is not correctly returned.

"Allow server to override" of NAMESPACE setting is enabled by default. So, when newly defined account, "Allow server to override" of NAMESPACE setting is checked.

Did you uncheck "Allow server to override" of NAMESPACE setting when case (A) and case (B)?

If Yes, why NAMESPACE is not issued in case (B) may be:
- When "Allow server to override" is Unchecked,
  - Tb 17 issues NAMESPACE command.
  - Tb 24 doesn't issue NAMESPACE command, because "NAMESPACE response
    is always ignored by Tb.

If No, it may be that "CAPABILITY response during AUTHENTICATE" doesn't contain NAMESPACE when account has over 400 folders.
  - Tb 17 doesn't look CAPABILITY response during AUTHENTICATE.
  - Tb 24 does look CAPABILITY response during AUTHENTICATE.
Summary: cannot connect to imap server → cannot connect to imap server (IMAP server doesn't correctly respond to ' list "" "*"', which is used after bug 799821, for some account)
When "Show subscribed folders only" is disabled(unchcked), Tb uses "list %" and "list %/%" instead of "list *" followed by "lsub *".
Does your IMAP server return response to "list %" and "list %/%" correctly when NAMESPACE command is not issued by Tb?
Here are my server logs for 24.0a2 (2013-07-25):

Show Only Subscribed Folders unchecked:
Fri 2013-07-26 23:19:32: [4941:2] Session 4941; child 2
Fri 2013-07-26 23:19:32: [4941:2] Accepting IMAP connection from [64.183.132.254:55340] to [172.16.0.2:143]
Fri 2013-07-26 23:19:32: [4941:2] --> * OK pic.dyndns.org IMAP4rev1 MDaemon 13.0.4 ready
Fri 2013-07-26 23:19:33: [4941:2] <-- 1 capability
Fri 2013-07-26 23:19:33: [4941:2] --> * CAPABILITY IMAP4rev1 NAMESPACE AUTH=CRAM-MD5 AUTH=LOGIN AUTH=PLAIN IDLE COMPRESS=DEFLATE ACL UNSELECT UIDPLUS QUOTA BINARY
Fri 2013-07-26 23:19:33: [4941:2] --> 1 OK CAPABILITY completed
Fri 2013-07-26 23:19:33: [4941:2] <-- 2 authenticate plain
Fri 2013-07-26 23:19:33: [4941:2] --> + 
Fri 2013-07-26 23:19:33: [4941:2] <-- ******
Fri 2013-07-26 23:19:33: [4941:2] Authenticated as gworley@pic.dyndns.org
Fri 2013-07-26 23:19:33: [4941:2] --> 2 OK AUTHENTICATE completed
Fri 2013-07-26 23:19:33: [4941:2] <-- 3 COMPRESS DEFLATE
Fri 2013-07-26 23:19:33: [4941:2] --> 3 OK DEFLATE active
Fri 2013-07-26 23:19:33: [4941:2] <-- 4 list "" "%"
Fri 2013-07-26 23:19:33: [4941:2] --> * LIST () "/" "INBOX"
Fri 2013-07-26 23:19:33: [4941:2] --> * LIST () "/" "Archives"
Fri 2013-07-26 23:19:33: [4941:2] --> * LIST () "/" "Contacts"
Fri 2013-07-26 23:19:33: [4941:2] --> * LIST () "/" "Deleted Items"
Fri 2013-07-26 23:19:33: [4941:2] --> * LIST () "/" "Drafts"
Fri 2013-07-26 23:19:33: [4941:2] --> * LIST () "/" "Folders"
Fri 2013-07-26 23:19:34: [4941:2] --> * LIST () "/" "Junk"
Fri 2013-07-26 23:19:34: [4941:2] --> * LIST () "/" "Pruned"
Fri 2013-07-26 23:19:34: [4941:2] --> * LIST () "/" "remote_pinerc"
Fri 2013-07-26 23:19:34: [4941:2] --> * LIST () "/" "Sent Items"
Fri 2013-07-26 23:19:34: [4941:2] --> * LIST () "/" "Sent"
Fri 2013-07-26 23:19:34: [4941:2] --> * LIST () "/" "Spam"
Fri 2013-07-26 23:19:34: [4941:2] --> * LIST () "/" "Templates"
Fri 2013-07-26 23:19:34: [4941:2] --> * LIST () "/" "Trash"
Fri 2013-07-26 23:19:34: [4941:2] --> 4 OK LIST completed
Fri 2013-07-26 23:19:34: [4941:2] <-- 5 list "" "%/%"

Show Only Subscribed folders checked:
Fri 2013-07-26 23:24:16: [4957:1] Session 4957; child 1
Fri 2013-07-26 23:24:16: [4957:1] Accepting IMAP connection from [64.183.132.254:55529] to [172.16.0.2:143]
Fri 2013-07-26 23:24:16: [4957:1] --> * OK pic.dyndns.org IMAP4rev1 MDaemon 13.0.4 ready
Fri 2013-07-26 23:24:16: [4957:1] <-- 1 capability
Fri 2013-07-26 23:24:16: [4957:1] --> * CAPABILITY IMAP4rev1 NAMESPACE AUTH=CRAM-MD5 AUTH=LOGIN AUTH=PLAIN IDLE COMPRESS=DEFLATE ACL UNSELECT UIDPLUS QUOTA BINARY
Fri 2013-07-26 23:24:16: [4957:1] --> 1 OK CAPABILITY completed
Fri 2013-07-26 23:24:16: [4957:1] <-- 2 authenticate plain
Fri 2013-07-26 23:24:16: [4957:1] --> + 
Fri 2013-07-26 23:24:16: [4957:1] <-- ******
Fri 2013-07-26 23:24:16: [4957:1] Authenticated as gworley@pic.dyndns.org
Fri 2013-07-26 23:24:16: [4957:1] --> 2 OK AUTHENTICATE completed
Fri 2013-07-26 23:24:16: [4957:1] <-- 3 namespace
Fri 2013-07-26 23:24:16: [4957:1] --> * NAMESPACE (("" "/")) (("Shared Folders/" "/")) (("Public Folders/" "/"))
Fri 2013-07-26 23:24:16: [4957:1] --> 3 OK NAMESPACE completed
Fri 2013-07-26 23:24:16: [4957:1] <-- 4 COMPRESS DEFLATE
Fri 2013-07-26 23:24:16: [4957:1] --> 4 OK DEFLATE active
Fri 2013-07-26 23:24:16: [4957:1] <-- 5 list "" "*"

For version 17.0.7
Show Only Subscribed folders unchecked:
Fri 2013-07-26 23:48:06: [4992:1] Session 4992; child 1
Fri 2013-07-26 23:48:06: [4992:1] Accepting IMAP connection from [64.183.132.254:56433] to [172.16.0.2:143]
Fri 2013-07-26 23:48:06: [4992:1] --> * OK pic.dyndns.org IMAP4rev1 MDaemon 13.0.4 ready
Fri 2013-07-26 23:48:14: [4992:1] <-- 1 capability
Fri 2013-07-26 23:48:14: [4992:1] --> * CAPABILITY IMAP4rev1 NAMESPACE AUTH=CRAM-MD5 AUTH=LOGIN AUTH=PLAIN IDLE COMPRESS=DEFLATE ACL UNSELECT UIDPLUS QUOTA BINARY
Fri 2013-07-26 23:48:14: [4992:1] --> 1 OK CAPABILITY completed
Fri 2013-07-26 23:48:21: [4992:1] <-- 2 authenticate CRAM-MD5
Fri 2013-07-26 23:48:21: [4992:1] --> + PE1EQUVNT04tRjIwMTMwNzI2MjM0OC5BQTQ4MjEwNk1EMDAxMkBwaWMuZHluZG5zLm9yZz4=
Fri 2013-07-26 23:48:21: [4992:1] <-- Z3dvcmxleUBieWdlb3JnZWNvbXB1dGVyLmNvbSAyOWU5MjFhNGIwZDQ0NTQxZTIyYTA3ZmZjZjEzNjNiMw==
Fri 2013-07-26 23:48:21: [4992:1] Authenticated as gworley@pic.dyndns.org
Fri 2013-07-26 23:48:21: [4992:1] --> 2 OK AUTHENTICATE completed
Fri 2013-07-26 23:48:21: [4992:1] <-- 3 namespace
Fri 2013-07-26 23:48:21: [4992:1] --> * NAMESPACE (("" "/")) (("Shared Folders/" "/")) (("Public Folders/" "/"))
Fri 2013-07-26 23:48:21: [4992:1] --> 3 OK NAMESPACE completed
Fri 2013-07-26 23:48:21: [4992:1] <-- 4 COMPRESS DEFLATE
Fri 2013-07-26 23:48:21: [4992:1] --> 4 OK DEFLATE active
Fri 2013-07-26 23:48:21: [4992:1] <-- 5 list "" "%"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "INBOX"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "Archives"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "Contacts"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "Deleted Items"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "Drafts"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "Folders"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "Junk"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "Pruned"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "remote_pinerc"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "Sent Items"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "Sent"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "Spam"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "Templates"
Fri 2013-07-26 23:48:21: [4992:1] --> * LIST () "/" "Trash"
Fri 2013-07-26 23:48:21: [4992:1] --> 5 OK LIST completed
Fri 2013-07-26 23:48:22: [4992:1] <-- 6 list "" "%/%"
Then a very long pause of output.


Show Only Subscribed folders checked:
Fri 2013-07-26 23:36:27: [4985:1] Session 4985; child 1
Fri 2013-07-26 23:36:27: [4985:1] Accepting IMAP connection from [64.183.132.254:55981] to [172.16.0.2:143]
Fri 2013-07-26 23:36:27: [4985:1] --> * OK pic.dyndns.org IMAP4rev1 MDaemon 13.0.4 ready
Fri 2013-07-26 23:36:45: [4985:1] <-- 1 capability
Fri 2013-07-26 23:36:45: [4985:1] --> * CAPABILITY IMAP4rev1 NAMESPACE AUTH=CRAM-MD5 AUTH=LOGIN AUTH=PLAIN IDLE COMPRESS=DEFLATE ACL UNSELECT UIDPLUS QUOTA BINARY
Fri 2013-07-26 23:36:45: [4985:1] --> 1 OK CAPABILITY completed
Fri 2013-07-26 23:36:51: [4985:1] <-- 2 authenticate CRAM-MD5
Fri 2013-07-26 23:36:51: [4985:1] --> + PE1EQUVNT04tRjIwMTMwNzI2MjMzNi5BQTM2NTE5OTFNRDAwMTJAcGljLmR5bmRucy5vcmc+
Fri 2013-07-26 23:36:52: [4985:1] <-- Z3dvcmxleUBieWdlb3JnZWNvbXB1dGVyLmNvbSAzOWI2NmZkMTljZGVhMzVmZTNiNjY5YmY0NzE1NWIzNw==
Fri 2013-07-26 23:36:52: [4985:1] Authenticated as gworley@pic.dyndns.org
Fri 2013-07-26 23:36:52: [4985:1] --> 2 OK AUTHENTICATE completed
Fri 2013-07-26 23:36:52: [4985:1] <-- 3 namespace
Fri 2013-07-26 23:36:52: [4985:1] --> * NAMESPACE (("" "/")) (("Shared Folders/" "/")) (("Public Folders/" "/"))
Fri 2013-07-26 23:36:52: [4985:1] --> 3 OK NAMESPACE completed
Fri 2013-07-26 23:36:52: [4985:1] <-- 4 COMPRESS DEFLATE
Fri 2013-07-26 23:36:52: [4985:1] --> 4 OK DEFLATE active
Fri 2013-07-26 23:36:52: [4985:1] <-- 5 lsub "" "*"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "Sent"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "Spam"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "Templates"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "remote_pinerc"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "Trash"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "INBOX"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "Archives"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "Drafts"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "Folders/- software orders"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "Folders/-/- ---- save"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "Folders/-/ - USAA Insurance"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "Folders/-/- Eagle Scout"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "Folders/-/- Gift(s)"
Fri 2013-07-26 23:36:52: [4985:1] --> * LSUB () "/" "Folders/-/- inbox keep"
Til I got all of the folders in a matter of a short time.

With TB 24 I was able to finally get a listing of email after 2 days of leaving the TB 24 open with fresh unused profile to my primary email address and coming in and keep refreshing in the subscribe window.  Which then after restarting TB 24 I was able then to get to the Inbox in about 30 minutes.  With TB 17 and show only subscribed folders checked I can get to the Inbox in less than 2 minutes and about 15 minutes if I have the option unchecked.
With Tb 24, why NAMESPACE is sent by Tb in some cases but NAMESPACE is not sent by Tb in other cases?
What is difference?

> Fri 2013-07-26 23:48:22: [4992:1] <-- 6 list "" "%/%"
> Then a very long pause of output.

In this case, NAMESPACE is normally sent by Tb 24.
Phenomenon like "LIST with wild card takes long when over 400 folders, until cached at server"?
  wild card in this context:
    list "" "*"    when "show subscribed folder only" is checked.
                   (Tb 17 doesn't issue this command. lsub "" "*" only.)
    list "" "%/%"  when "show subscribed folder only" is unchecked
                   (Both Tb 17 and Tb 24 issues this command)
Something I have just noticed on the profile that existed before is TB 24 is telling me that the connection has timed out when on the server TB 24 is creating new connections to the server according to the server session monitor yet the connection on the server hasn't gone away.   TB 24 must be timing out before the server can respond.
Just for the heck of it I set up Outlook 2013 and was able to get to my primary Inbox including folders in about 90 seconds.  Started listing headers almost as soon is I established the account.

After about 24 hours of running strictly TB 24 with the profile that I had been using for testing TB 24, I will post the TB MailNews:Logging as described on https://wiki.mozilla.org/MailNews:Logging.  I took a look at the contents and there is a lot of disconnecting and reconnecting yet the server side sees no termination of connections for at least 15 minutes after the disconnection.
Used command is;
                  Show suscribed folder only
             Checked                     Unchecked
   Tb 17 :   lsub "" "*"                 list "%", list "%/%"
   Tb 24 :   list "" "*", lsub "" "*"    Same as Tb 17
"very long pause of output" for list "%/%" perhaps produced timeout in Tb. And, list "" "*" usually takes longer than list "%/%".

Default timeout setting for TCP connection is not so long.
  mailnews.tcptimeout = 100 (perhaps 100 sec)
Try with larger mailnews.tcptimeout, please.

> I took a look at the contents and there is a lot of disconnecting and reconnecting yet
> the server side sees no termination of connections for at least 15 minutes after the disconnection.

IIRC, TCP keeps lost(or closed) connection for 12 minutes(or around 12) for reuse. It's spec of TCP.
In your case, TCP connection is perhaps not cleanly closed by logout and normal socket close when timeout happened in Tb, because status for Tb is "server doesn't respond to IMAP command" and status for PC's TCP is "waiting for data from server".
So, phenomenon is normal when "unexpectd connection loss" repeatedly happened.
FYI.
As written in bug 541367 comment #9, mailnews.tcptimeout value is passed to TCP layer instead of direct use by Tb's code. So, timeout occurs at TCP layer.
Following is a web page found by Goole Search for "tcp close_wait vs time-wait".
> http://blog.zhuzhaoyuan.com/2009/03/a-word-on-time_wait-and-close_wait/
> The value of TIME_WAIT delay is 2MSL,
> which is TCP implementation dependent and is generally about 1-4 minutes.
Time of "around 12 minutes" which I called seems "2 * MSL" written in this document.

If server receives FIN from PC's TCP, connection enters CLOSE_WAIT, and server's TCP sends FIN after timeout detection, connection enters TIME_WAIT.
When PC'S TCP detects timeout, I believe PC's TCP sends FIN.
So, following you saw is perhaps:
  the FIN from PC is not arrived or not processed at server as expected,
  then server detects timeout and sends FIN, and enters TIME_WAIT.
  And, timeout + "2 * MSL" == around 15 minutes in your server.
> there is a lot of disconnecting and reconnecting yet the server side
> sees no termination of connections for at least 15 minutes after the disconnection.
invalid based on wada's feedback
Status: UNCONFIRMED → RESOLVED
Closed: 9 years ago
Resolution: --- → INVALID
Summary: cannot connect to imap server (IMAP server doesn't correctly respond to ' list "" "*"', which is used after bug 799821, for some account) → cannot connect to imap server (server doesn't correctly respond to ' list "" "*"' after bug 799821), and if server receives FIN from PC's TCP, connection enters CLOSE_WAIT, and server's TCP sends FIN after timeout detection, connection enters TIME_WAIT
You need to log in before you can comment on or make changes to this bug.