Closed Bug 281857 Opened 20 years ago Closed 9 months ago

"Connection to server localhost timed out." Feb 9 22:38:35 viper imapd[28027]: Command stream end of file, while reading line user=timeless host=localhost.localdomain [127.0.0.1]

Categories

(MailNews Core :: Networking: IMAP, defect)

Product:
MailNews Core
Component:
Networking: IMAP
Platform:
x86
Windows XP
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: timeless, Unassigned)

Details

(Whiteboard: [closeme 2023-12-15]) 

As of tuesday, mozmail will no longer open my inbox.

Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8b) Gecko/20050207
[wXPsp2]

I've tried creating a new mail account with the same profile and it didn't fair
any better.

imap:5 nsprlog (as seen by debugview, [2372] is the pid, 2996 should be the
threadid):
[2372] 2996[116a1e8]: ImapThreadMainLoop entering [this=10c8f860]
[2372] 2996[116a1e8]: 10c8f860:localhost:NA:ProcessCurrentURL: entering
[2372] 2996[116a1e8]:
10c8f860:localhost:NA:ProcessCurrentURL:imap://timeless@localhost:143/fetch%3EUID%3E/INBOX%3E356188:
 = currentUrl
[2372] 2996[116a1e8]: ReadNextLine [stream=1f06840 nb=161 needmore=0]
[2372] 2996[116a1e8]: 10c8f860:localhost:NA:CreateNewLineFromSocket: * OK
[CAPABILITY IMAP4REV1 LOGIN-REFERRALS STARTTLS AUTH=GSSAPI AUTH=LOGIN]
localhost.localdomain IMAP4rev1 2003.338rh at Thu, 10 Feb 2005 11:58:13 -0500 (EST) 
[2372] 2996[116a1e8]: 10c8f860:localhost:NA:SendData: 1 authenticate login 
[2372] 2996[116a1e8]: ReadNextLine [stream=1f06840 nb=20 needmore=0]
[2372] 2996[116a1e8]: 10c8f860:localhost:NA:CreateNewLineFromSocket: +
VXNlciBOYW1lAA== 
[2372] 2996[116a1e8]: 10c8f860:localhost:NA:SendData: Logging suppressed for
this command (it probably contained authentication information)
[2372] 2996[116a1e8]: ReadNextLine [stream=1f06840 nb=16 needmore=0]
[2372] 2996[116a1e8]: 10c8f860:localhost:NA:CreateNewLineFromSocket: + UGFzc3dvcmQA 
[2372] 2996[116a1e8]: 10c8f860:localhost:NA:SendData: Logging suppressed for
this command (it probably contained authentication information)
[2372] 2996[116a1e8]: ReadNextLine [stream=1f06840 nb=168 needmore=0]
[2372] 2996[116a1e8]: 10c8f860:localhost:NA:CreateNewLineFromSocket: 1 OK
[CAPABILITY IMAP4REV1 IDLE NAMESPACE MAILBOX-REFERRALS BINARY UNSELECT SCAN SORT
THREAD=REFERENCES THREAD=ORDEREDSUBJECT MULTIAPPEND] User timeless authenticated 
[2372] 2996[116a1e8]: 10c8f860:localhost:A:SendData: 2 select "INBOX" 
[2372] 2996[116a1e8]: ReadNextLine [stream=1f06840 nb=0 needmore=1]
[2372] 2996[116a1e8]: 10c8f860:localhost:A:CreateNewLineFromSocket: clearing
IMAP_CONNECTION_IS_OPEN - rv = 804b000e
[2372] 2996[116a1e8]: 10c8f860:localhost:A:TellThreadToDie: close socket connection
[2372] 2996[116a1e8]: 10c8f860:localhost:A:CreateNewLineFromSocket: (null)
[2372] 2996[116a1e8]: 10c8f860:localhost:A:ProcessCurrentURL: aborting queued urls
[2372] 2996[116a1e8]: ImapThreadMainLoop leaving [this=10c8f860]

message found in server log:
Feb  9 22:38:35 viper imapd[28027]: Command stream end of file, while reading
line user=timeless host=localhost.localdomain [127.0.0.1]

steps:
1. open mozmail
2. select inbox
3. enter password

expect:
4. access to mailbox

actual result:
dialog complaining that connection to server was lost or something (i can get
the specific message if necessary, but it's hardly useful).

I'd set this to major or blocker since w/o this i can no longer access my inbox
which is a fairly serious problem for working on mozilla, but i'm too lazy to do
that or justify it to others.
is your server particularly slow, or do you have a virus checker installed that
makes it look slow? Did the message say something about the connection timing
out? If so, that's what happened.  Can you try increasing your mailnews
tcptimeout? The default is 60 seconds. The pref is pref("mailnews.tcptimeout",
60); Try increasing it to 120 seconds or so...

I have seen this message when SSL handshaking was not working, and it
was nothing to do with the client.
note this is imap over ssh, not imap over ssl. the ssh tunnel is perfectly
operational.

Connection to server localhost timed out.

the server is not slow. there is a virusscanner locally, but i don't think we've
reached the interesting part of a handshake.

i changed the number to 120. it didn't help (i did not restart, i presume i
don't need to).
yes, you have to restart.
(according to the log file, |CreateNewLineFromSocket| aborted due to rv =
0x804b000e, i.e., a NS_ERROR_NET_TIMEOUT error)
ok, that 'fixed' it, can we change the code to automatically bump the timeout if
it fails? (establish a ceiling of course). i don't quite understand why i didn't
see more messages in the log, but i have 357,000+ headers to be retrieved, so i
think mail should be willing to wait a while to get all of them (it takes a while).

11:06:12.496A
[14348] 13232[c82e2f0]: 10d72c20:localhost:A:CreateNewLineFromSocket: * LIST
(\NoInferiors) NIL INBOX
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=22 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:A:CreateNewLineFromSocket: 12 OK LIST
completed
[14348] 13232[c82e2f0]: 10d72c20:localhost:A:SendData: 13 select "INBOX"
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=17 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:A:CreateNewLineFromSocket: * 356877
EXISTS
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=14 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:A:CreateNewLineFromSocket: * 945 RECENT
11:07:31.886A

11:07:31.896A
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:SendData: 14 UID fetch 1:*
(FLAGS)
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=33 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: * 1
FETCH (UID 1 FLAGS (\Seen))
11:07:32.527A

11:18:54.334A
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: *
356877 FETCH (UID 357945 FLAGS (\Recent))
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=17 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: *
356890 EXISTS
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=14 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: *
958 RECENT
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=27 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: 14
OK UID FETCH completed
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:SendData: 15 check
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=17 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: *
356891 EXISTS
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=14 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: *
959 RECENT
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=28 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: 15
OK Checkpoint completed
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:SendData: 16 UID fetch
356189:357945 (UID RFC822.SIZE FLAGS BODY.PEEK[HEADER.FIELDS (From To Cc Subject
Date Message-ID Priority X-Priority References Newsgroups In-Reply-To
Content-Type)])
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=208 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: *
355121 FETCH (UID 356189 RFC822.SIZE 8335 FLAGS () BODY[HEADER.FIELDS ("FROM"
"TO" "CC" "SUBJECT" "DATE" "MESSAGE-ID" "PRIORITY" "X-PRIORITY" "REFERENCES"
"NEWSGROUPS" "IN-REPLY-TO" "CONTENT-TYPE")] {255}
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:STREAM:OPEN Size: 8335: Begin
Message Download Stream
11:19:08.972A

11:19:47.203A
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: *
356877 FETCH (UID 357945 RFC822.SIZE 1551 FLAGS (\Recent) BODY[HEADER.FIELDS
("FROM" "TO" "CC" "SUBJECT" "DATE" "MESSAGE-ID" "PRIORITY" "X-PRIORITY"
"REFERENCES" "NEWSGROUPS" "IN-REPLY-TO" "CONTENT-TYPE")] {263}
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:STREAM:OPEN Size: 1551: Begin
Message Download Stream
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:STREAM:CLOSE: Normal Message
End Download Stream
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=17 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: *
356892 EXISTS
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=14 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: *
960 RECENT
[14348] 13232[c82e2f0]: ReadNextLine [stream=31ff570 nb=27 needmore=0]
[14348] 13232[c82e2f0]: 10d72c20:localhost:S-INBOX:CreateNewLineFromSocket: 16
OK UID FETCH completed
11:19:47.223A
Status: UNCONFIRMED → NEW
Ever confirmed: true
Priority: -- → P5
Product: Core → MailNews Core
QA Contact: grylchan → networking.imap
timeless, are you in a position to verify whether this still fails?
Assignee: mozilla → nobody
Priority: P5 → --
Summary: Feb 9 22:38:35 viper imapd[28027]: Command stream end of file, while reading line user=timeless host=localhost.localdomain [127.0.0.1] → "Connection to server localhost timed out." Feb 9 22:38:35 viper imapd[28027]: Command stream end of file, while reading line user=timeless host=localhost.localdomain [127.0.0.1]
Severity: normal → S3

Do you still experience this issue?

Flags: needinfo?(timeless)
Whiteboard: [closeme 2023-12-15]
Status: NEW → RESOLVED
Closed: 9 months ago
Flags: needinfo?(timeless)
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.