Thunderbird connects but will not download IMAP messages

User Help for Mozilla Thunderbird
Post Reply
gabrielse
Guest

Thunderbird connects but will not download IMAP messages

Post by gabrielse »

Puzzling symptoms:
Over most internet connections the laptop has no trouble connecting to my IMAP email server. Everything works fine.
At my apartment my desktop has no trouble connecting to my IMAP email server. Everything works fine.
At my apartment my laptop (with nothing at at all changed in its configuration)
- authenticates and connects to my IMAP server just fine
- but it does not succeed in downloading messages from the same email server.
At my apartment my laptop (via a VPN connection to the server)
- has no trouble connecting to my IMAP email server and downloading messages


I recorded log files from thunderbird, the email client that I use, for the two cases.
The problem comes after the line:
3076[241d0e0]: 278e008:gg-office.harvard.edu:S-INBOX:SendData: 11 UID fetch 1:* (FLAGS)
The case that succeeds in downloading email has the next line:
6828[27a8c00]: ReadNextLine [stream=2538b20 nb=47 needmore=0]
The case that fails has instead as its next line:
3076[241d0e0]: ReadNextLine [stream=2520e88 nb=0 needmore=1]


Longer sections of the logfiles when thunderbird succeeds and fails follow:



Thunderbird IMAP logfile section --- when thunderbird succeeds in "opening files" and downloading email

6828[27a8c00]: 27958c8:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: * MYRIGHTS "INBOX" lrswipcda
6828[27a8c00]: ReadNextLine [stream=2538b20 nb=25 needmore=0]
6828[27a8c00]: 27958c8:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: 9 OK MYRIGHTS completed
6828[27a8c00]: 27958c8:gg-office.harvard.edu:S-INBOX:SendData: 10 getacl "INBOX"
6828[27a8c00]: ReadNextLine [stream=2538b20 nb=57 needmore=0]
6828[27a8c00]: 27958c8:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: * ACL "INBOX" ** e-mail address removed by moderator ** lrswipcda
6828[27a8c00]: ReadNextLine [stream=2538b20 nb=24 needmore=0]
6828[27a8c00]: 27958c8:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: 10 OK GETACL completed
6828[27a8c00]: 27958c8:gg-office.harvard.edu:S-INBOX:SendData: 11 UID fetch 1:* (FLAGS)
6828[27a8c00]: ReadNextLine [stream=2538b20 nb=47 needmore=0]
6828[27a8c00]: 27958c8:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: * 1 FETCH (UID 68610 FLAGS (\Seen \Answered))
6828[27a8c00]: ReadNextLine [stream=2538b20 nb=37 needmore=0]
6828[27a8c00]: 27958c8:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: * 2 FETCH (UID 68611 FLAGS (\Seen))
6828[27a8c00]: ReadNextLine [stream=2538b20 nb=37 needmore=0]
6828[27a8c00]: 27958c8:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: * 3 FETCH (UID 68612 FLAGS (\Seen))
6828[27a8c00]: ReadNextLine [stream=2538b20 nb=37 needmore=0]
6828[27a8c00]: 27958c8:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: * 4 FETCH (UID 68613 FLAGS (\Seen))
6828[27a8c00]: ReadNextLine [stream=2538b20 nb=37 needmore=0]
6828[27a8c00]: 27958c8:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: * 5 FETCH (UID 68614 FLAGS (\Seen))

(continues on)




Same section of Thunderbird IMAP logfile section -- when thunderbird fails in "opening files" and fails in downloading email

3076[241d0e0]: 278e008:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: * MYRIGHTS "INBOX" lrswipcda
3076[241d0e0]: ReadNextLine [stream=2520e88 nb=25 needmore=0]
3076[241d0e0]: 278e008:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: 9 OK MYRIGHTS completed
3076[241d0e0]: 278e008:gg-office.harvard.edu:S-INBOX:SendData: 10 getacl "INBOX"
3076[241d0e0]: ReadNextLine [stream=2520e88 nb=57 needmore=0]
3076[241d0e0]: 278e008:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: * ACL "INBOX" *********** lrswipcda
3076[241d0e0]: ReadNextLine [stream=2520e88 nb=24 needmore=0]
3076[241d0e0]: 278e008:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: 10 OK GETACL completed
3076[241d0e0]: 278e008:gg-office.harvard.edu:S-INBOX:SendData: 11 UID fetch 1:* (FLAGS)
3076[241d0e0]: ReadNextLine [stream=2520e88 nb=0 needmore=1]
3076[241d0e0]: 278e008:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: clearing IMAP_CONNECTION_IS_OPEN - rv = 4b000e
3076[241d0e0]: 278e008:gg-office.harvard.edu:S-INBOX:TellThreadToDie: close socket connection
3076[241d0e0]: 278e008:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: (null)
0[348c8]: creating protocol instance to retry queued url:imap://***********:993/select>/INBOX
0[348c8]: retrying url:imap://************:993/select>/INBOX
0[348c8]: 334cbd8:gg-office.harvard.edu:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
3076[241d0e0]: ImapThreadMainLoop leaving [this=278e008]
7564[27ab018]: ImapThreadMainLoop entering [this=334cbd8]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:NA:ProcessCurrentURL: entering
7564[27ab018]: 334cbd8:gg-office.harvard.edu:NA:ProcessCurrentURL:imap://***************:993/select%3E/INBOX: = currentUrl
7564[27ab018]: ReadNextLine [stream=2526a80 nb=58 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:NA:CreateNewLineFromSocket: * OK gg-office.harvard.edu IMAP4rev1 MDaemon 9.6.3 ready
7564[27ab018]: 334cbd8:gg-office.harvard.edu:NA:SendData: 1 capability
7564[27ab018]: ReadNextLine [stream=2526a80 nb=91 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4rev1 NAMESPACE AUTH=CRAM-MD5 AUTH=LOGIN AUTH=PLAIN ACL UNSELECT UIDPLUS
7564[27ab018]: ReadNextLine [stream=2526a80 nb=27 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:NA:CreateNewLineFromSocket: 1 OK CAPABILITY completed
7564[27ab018]: 334cbd8:gg-office.harvard.edu:NA:SendData: 2 authenticate CRAM-MD5
7564[27ab018]: ReadNextLine [stream=2526a80 nb=84 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:NA:CreateNewLineFromSocket: + PE1EQUVNT04tRjIwMDgwMTEME1EMDAxMkBnZy1vZmZpY2UuaGFydmFyZC5lZHU+
7564[27ab018]: 334cbd8:gg-office.harvard.edu:NA:SendData: Z2FicmllbHNlIDIyNjRkZDgzODc2MzU0ZTQyNDVkMTA2MGMy
7564[27ab018]: ReadNextLine [stream=2526a80 nb=29 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:NA:CreateNewLineFromSocket: 2 OK AUTHENTICATE completed
7564[27ab018]: 334cbd8:gg-office.harvard.edu:A:SendData: 3 select "INBOX"
7564[27ab018]: ReadNextLine [stream=2526a80 nb=60 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:A:CreateNewLineFromSocket: * FLAGS (\Seen \Answered \Flagged \Deleted \Draft \Recent)
7564[27ab018]: ReadNextLine [stream=2526a80 nb=15 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:A:CreateNewLineFromSocket: * 4730 EXISTS
7564[27ab018]: ReadNextLine [stream=2526a80 nb=12 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:A:CreateNewLineFromSocket: * 0 RECENT
7564[27ab018]: ReadNextLine [stream=2526a80 nb=32 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:A:CreateNewLineFromSocket: * OK [UNSEEN 382] first unseen
7564[27ab018]: ReadNextLine [stream=2526a80 nb=42 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:A:CreateNewLineFromSocket: * OK [UIDVALIDITY 1014506745] UIDs valid
7564[27ab018]: ReadNextLine [stream=2526a80 nb=41 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:A:CreateNewLineFromSocket: * OK [UIDNEXT 73481] Predicted next UID
7564[27ab018]: ReadNextLine [stream=2526a80 nb=68 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:A:CreateNewLineFromSocket: * OK [PERMANENTFLAGS (\Seen \Answered \Flagged \Deleted \Draft)] .
7564[27ab018]: ReadNextLine [stream=2526a80 nb=36 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:A:CreateNewLineFromSocket: 3 OK [READ-WRITE] SELECT completed
7564[27ab018]: 334cbd8:gg-office.harvard.edu:S-INBOX:SendData: 4 UID fetch 1:* (FLAGS)
7564[27ab018]: ReadNextLine [stream=2526a80 nb=0 needmore=1]
7564[27ab018]: ReadNextLine [stream=2526a80 nb=4294967295 needmore=0]
7564[27ab018]: 334cbd8:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: clearing IMAP_CONNECTION_IS_OPEN - rv = 80470002
7564[27ab018]: 334cbd8:gg-office.harvard.edu:S-INBOX:TellThreadToDie: close socket connection
7564[27ab018]: 334cbd8:gg-office.harvard.edu:S-INBOX:CreateNewLineFromSocket: (null)
0[348c8]: creating protocol instance to retry queued url:imap://****************:993/select>/INBOX
0[348c8]: retrying url:imap://******************:993/select>/INBOX
0[348c8]: 333f5b0:gg-office.harvard.edu:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
7564[27ab018]: ImapThreadMainLoop leaving [this=334cbd8]
4700[241d0e0]: ImapThreadMainLoop entering [this=333f5b0]

(This keeps repeating)
User avatar
Daifne
Moderator
Posts: 123071
Joined: July 31st, 2005, 9:17 pm
Location: Where the Waters Meet, Wisconsin

Post by Daifne »

I removed your e-mail address because spammers harvest email addresses from public forums like this.
Guest
Guest

More information: IMAP log shows problem is "winsock e

Post by Guest »

Below are relevant sections of the IMAP server log showing that the problem is a "winsock error". I do not know why this should occur on some otherwise good internet connection sites and not others.

Here are the last two lines before the error:
Tue 2008-01-15 18:17:05: <11> 11 OK FETCH completed
(more successful fetching lines follow)
The next lines when the IMAP message download is going to fail is insted:
Wed 2008-01-16 03:15:18: Error writing to socket
Wed 2008-01-16 03:15:18: * Winsock Error 10060 The connection timed out.
Wed 2008-01-16 03:15:18: IMAP session terminated, (11589 bytes)
Wed 2008-01-16 03:15:18: ----------








This is the relevant section from the log of the IMAP server showing a successfull IMAP connection being made.
An unsuccessful attempt (below) is identical until after the space that I inserted in the following record.


Tue 2008-01-15 18:54:08: Session 857; child 2; thread 500
Tue 2008-01-15 18:16:49: Accepting IMAP connection from [169.254.173.132:3158]
Tue 2008-01-15 18:16:58: SSL negotiation successful (TLS 1.0, 1024 bit key exchange, 128 bit RC4 encryption)
Tue 2008-01-15 18:16:58: --> * OK gg-office.harvard.edu IMAP4rev1 MDaemon 9.6.3 ready
Tue 2008-01-15 18:16:58: <1> * CAPABILITY IMAP4rev1 NAMESPACE AUTH=CRAM-MD5 AUTH=LOGIN AUTH=PLAIN ACL UNSELECT UIDPLUS
Tue 2008-01-15 18:16:58: --> 1 OK CAPABILITY completed
Tue 2008-01-15 18:17:03: <2> + PE1EQUVNT04tRjIwMDgwMTE1MTgxZWR1Pg==
Tue 2008-01-15 18:17:03: <Z2FicmllbHNlIDEyNjczNGYyZjZj> 2 OK AUTHENTICATE completed
Tue 2008-01-15 18:17:03: <3> * NAMESPACE (("" "/")) (("~" "/")) (("#" "/"))
Tue 2008-01-15 18:17:03: --> 3 OK NAMESPACE completed
Tue 2008-01-15 18:17:04: <4> 4 OK LSUB completed
Tue 2008-01-15 18:17:04: <5> 5 OK LSUB completed
Tue 2008-01-15 18:17:04: <6> 6 OK LSUB completed
Tue 2008-01-15 18:17:04: <7> 7 OK LIST completed
Tue 2008-01-15 18:17:04: <8> * FLAGS (\Seen \Answered \Flagged \Deleted \Draft \Recent)
Tue 2008-01-15 18:17:04: --> * 4733 EXISTS
Tue 2008-01-15 18:17:04: --> * 2 RECENT
Tue 2008-01-15 18:17:04: --> * OK [UNSEEN 382] first unseen
Tue 2008-01-15 18:17:04: --> * OK [UIDVALIDITY 1014506745] UIDs valid
Tue 2008-01-15 18:17:04: --> * OK [UIDNEXT 73484] Predicted next UID
Tue 2008-01-15 18:17:04: --> * OK [PERMANENTFLAGS (\Seen \Answered \Flagged \Deleted \Draft)] .
Tue 2008-01-15 18:17:04: --> 8 OK [READ-WRITE] SELECT completed
Tue 2008-01-15 18:17:05: <9> * MYRIGHTS "INBOX" lrswipcda
Tue 2008-01-15 18:17:05: --> 9 OK MYRIGHTS completed
Tue 2008-01-15 18:17:05: <10> * ACL "INBOX" ******************************** lrswipcda
Tue 2008-01-15 18:17:05: --> 10 OK GETACL completed
Tue 2008-01-15 18:17:05: <11> 11 OK FETCH completed
Tue 2008-01-15 18:17:15: <12> 12 OK FETCH completed
Tue 2008-01-15 18:17:15: <13> * OK gg-office.harvard.edu IMAP4rev1 MDaemon 9.6.3 ready
Wed 2008-01-16 03:14:08: <1> * CAPABILITY IMAP4rev1 NAMESPACE AUTH=CRAM-MD5 AUTH=LOGIN AUTH=PLAIN ACL UNSELECT UIDPLUS
Wed 2008-01-16 03:14:08: --> 1 OK CAPABILITY completed
Wed 2008-01-16 03:14:16: <2> + PE1EQUVNg==
Wed 2008-01-16 03:14:16: <Z2FicmllbHNlIDhhNGU3MTE3MDU1Y2EzODY0Y2Y1MzExMzJkOWFhM2E3> 2 OK AUTHENTICATE completed
Wed 2008-01-16 03:14:16: <3> * NAMESPACE (("" "/")) (("~" "/")) (("#" "/"))
Wed 2008-01-16 03:14:16: --> 3 OK NAMESPACE completed
Wed 2008-01-16 03:14:16: <4> 4 OK LSUB completed
Wed 2008-01-16 03:14:17: <5> 5 OK LSUB completed
Wed 2008-01-16 03:14:17: <6> 6 OK LSUB completed
Wed 2008-01-16 03:14:17: <7> 7 OK LIST completed
Wed 2008-01-16 03:14:17: <8> * FLAGS (\Seen \Answered \Flagged \Deleted \Draft \Recent)
Wed 2008-01-16 03:14:17: --> * 4738 EXISTS
Wed 2008-01-16 03:14:17: --> * 4 RECENT
Wed 2008-01-16 03:14:17: --> * OK [UNSEEN 382] first unseen
Wed 2008-01-16 03:14:17: --> * OK [UIDVALIDITY 1014506745] UIDs valid
Wed 2008-01-16 03:14:17: --> * OK [UIDNEXT 73489] Predicted next UID
Wed 2008-01-16 03:14:17: --> * OK [PERMANENTFLAGS (\Seen \Answered \Flagged \Deleted \Draft)] .
Wed 2008-01-16 03:14:17: --> 8 OK [READ-WRITE] SELECT completed
Wed 2008-01-16 03:14:18: <9> * MYRIGHTS "INBOX" lrswipcda
Wed 2008-01-16 03:14:18: --> 9 OK MYRIGHTS completed
Wed 2008-01-16 03:14:18: <10> * ACL "INBOX" ******************************************** lrswipcda
Wed 2008-01-16 03:14:18: --> 10 OK GETACL completed
Wed 2008-01-16 03:14:18: <-- 11 UID fetch 1:* (FLAGS)
Wed 2008-01-16 03:14:18: Sending FETCH response (not logged)...

Wed 2008-01-16 03:15:18: Error writing to socket
Wed 2008-01-16 03:15:18: * Winsock Error 10060 The connection timed out.
Wed 2008-01-16 03:15:18: IMAP session terminated, (11589 bytes)
Wed 2008-01-16 03:15:18: ----------

(after this the system repeatedly tries again but with the same result each time)
Guest
Guest

Fixed -- never mind

Post by Guest »

Fixed by running WinsockFixXp utility which resets registry parameters that could have been reset by spyware detection programs that have been removed.
Post Reply