Closed Bug 335562 Opened 18 years ago Closed 14 years ago

TLS not working as intended - Thunderbird tries to log on using username/password before asking for encryption

Categories

(Thunderbird :: Security, defect)

x86
Windows XP
defect
Not set
major

Tracking

(blocking-thunderbird3.0 -)

RESOLVED WORKSFORME
Tracking Status
blocking-thunderbird3.0 --- -

People

(Reporter: u.j.jerpseth, Assigned: Bienvenu)

Details

Attachments

(5 files)

User-Agent:       Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; InfoPath.1; .NET CLR 1.1.4322; .NET CLR 2.0.50727)
Build Identifier: version 1.5.0.2 (20060308) and older

Thunderbird tries to log on using username/password before asking for encryption. This results in Thunderbird not being able to communicate with server if server requires encryption.
Tested with other e-mail client (Eudora on Mac) and it managed to communicate by TLS using same server/port etc.
Error message: You cannot log in to imap.uio.no because the server has disabled login.

Reproducible: Always

Steps to Reproduce:
1. Choose Account Setting -> Server Settings -> TLS/143 (not TLS if available)
2. Turn off any unencrypted communication on mail server

Actual Results:  
You no longer receive e-mail/get error message because Thunderbird tries to log on using username/password before asking for encryption. 

Expected Results:  
Asked for encrypted line before tring to log on using username/password

Tested on Thunderbird 1.0.2 -> 1.5.0.2 on several hundreds of users (unintended)
Assignee: dveditz → bienvenu
imap? pop3? can we get a protocol log of the session?

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

Status: UNCONFIRMED → ASSIGNED
Ever confirmed: true
imap (cyrus):
Log:

0[2c48d8]: 293f9b8:imap.uio.no:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
0[2c48d8]: 2944168:imap.uio.no:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
3972[275a0d8]: ImapThreadMainLoop entering [this=293f9b8]
3972[275a0d8]: 293f9b8:imap.uio.no:NA:ProcessCurrentURL: entering
3972[275a0d8]: 293f9b8:imap.uio.no:NA:ProcessCurrentURL:imap://jarre@imap.uio.no:143/select%3E.INBOX:  = currentUrl
4024[29791c8]: ImapThreadMainLoop entering [this=2944168]
4024[29791c8]: 2944168:imap.uio.no:NA:ProcessCurrentURL: entering
4024[29791c8]: 2944168:imap.uio.no:NA:ProcessCurrentURL:imap://jarre@imap.uio.no:143/folderstatus%3E.Tivoli.Ifi:  = currentUrl
4024[29791c8]: ReadNextLine [stream=1edd9d0 nb=46 needmore=0]
4024[29791c8]: 2944168:imap.uio.no:NA:CreateNewLineFromSocket: * OK IMAP4 Ready mail-proxy1.uio.no 0002258c

3972[275a0d8]: ReadNextLine [stream=2850938 nb=46 needmore=0]
3972[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * OK IMAP4 Ready mail-proxy2.uio.no 0002258d

4024[29791c8]: 2944168:imap.uio.no:NA:SendData: 1 capability

3972[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 1 capability

4024[29791c8]: ReadNextLine [stream=1edd9d0 nb=228 needmore=0]
4024[29791c8]: 2944168:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGINDISABLED

3972[275a0d8]: ReadNextLine [stream=2850938 nb=228 needmore=0]
3972[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGINDISABLED

4024[29791c8]: ReadNextLine [stream=1edd9d0 nb=17 needmore=0]
4024[29791c8]: 2944168:imap.uio.no:NA:CreateNewLineFromSocket: 1 OK CAPABILITY

4024[29791c8]: 2944168:imap.uio.no:NA:SendData: 2 STARTTLS

3972[275a0d8]: ReadNextLine [stream=2850938 nb=17 needmore=0]
3972[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: 1 OK CAPABILITY

3972[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 2 STARTTLS

4024[29791c8]: ReadNextLine [stream=1edd9d0 nb=32 needmore=0]
4024[29791c8]: 2944168:imap.uio.no:NA:CreateNewLineFromSocket: 2 OK Begin TLS negotiation now

4024[29791c8]: 2944168:imap.uio.no:NA:SendData: 3 capability

3972[275a0d8]: ReadNextLine [stream=2850938 nb=32 needmore=0]
3972[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: 2 OK Begin TLS negotiation now

3972[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 3 capability

4024[29791c8]: ReadNextLine [stream=1edd9d0 nb=205 needmore=0]
4024[29791c8]: 2944168:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE

3972[275a0d8]: ReadNextLine [stream=2850938 nb=205 needmore=0]
3972[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE

4024[29791c8]: ReadNextLine [stream=1edd9d0 nb=17 needmore=0]
4024[29791c8]: 2944168:imap.uio.no:NA:CreateNewLineFromSocket: 3 OK CAPABILITY

0[2c48d8]: 2bb1ff8:imap.uio.no:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
4024[29791c8]: 2944168:imap.uio.no:NA:ProcessCurrentURL: aborting queued urls
4024[29791c8]: 2944168:imap.uio.no:NA:SendData: 4 logout

3972[275a0d8]: ReadNextLine [stream=2850938 nb=17 needmore=0]
3972[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: 3 OK CAPABILITY

3896[26cda78]: ImapThreadMainLoop entering [this=2bb1ff8]
3896[26cda78]: 2bb1ff8:imap.uio.no:NA:ProcessCurrentURL: entering
3896[26cda78]: 2bb1ff8:imap.uio.no:NA:ProcessCurrentURL:imap://jarre@imap.uio.no:143/folderstatus%3E.Tivoli.HF:  = currentUrl
4024[29791c8]: ReadNextLine [stream=1edd9d0 nb=38 needmore=0]
4024[29791c8]: 2944168:imap.uio.no:NA:CreateNewLineFromSocket: * BYE IMAP4 server logging out, mate

4024[29791c8]: 2944168:imap.uio.no:NA:TellThreadToDie: close socket connection
4024[29791c8]: ImapThreadMainLoop leaving [this=2944168]
3896[26cda78]: ReadNextLine [stream=2961fa0 nb=46 needmore=0]
3896[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: * OK IMAP4 Ready mail-proxy2.uio.no 0002258d

3896[26cda78]: 2bb1ff8:imap.uio.no:NA:SendData: 1 capability

3896[26cda78]: ReadNextLine [stream=2961fa0 nb=228 needmore=0]
3896[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGINDISABLED

3972[275a0d8]: 293f9b8:imap.uio.no:NA:ProcessCurrentURL: aborting queued urls
3972[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 4 logout

3972[275a0d8]: ReadNextLine [stream=2850938 nb=38 needmore=0]
3972[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * BYE IMAP4 server logging out, mate

3972[275a0d8]: 293f9b8:imap.uio.no:NA:TellThreadToDie: close socket connection
3972[275a0d8]: ImapThreadMainLoop leaving [this=293f9b8]
3896[26cda78]: ReadNextLine [stream=2961fa0 nb=17 needmore=0]
3896[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: 1 OK CAPABILITY

3896[26cda78]: 2bb1ff8:imap.uio.no:NA:SendData: 2 STARTTLS

3896[26cda78]: ReadNextLine [stream=2961fa0 nb=32 needmore=0]
3896[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: 2 OK Begin TLS negotiation now

3896[26cda78]: 2bb1ff8:imap.uio.no:NA:SendData: 3 capability

3896[26cda78]: ReadNextLine [stream=2961fa0 nb=205 needmore=0]
3896[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE

3896[26cda78]: ReadNextLine [stream=2961fa0 nb=17 needmore=0]
3896[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: 3 OK CAPABILITY

0[2c48d8]: 293f9b8:imap.uio.no:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
3896[26cda78]: 2bb1ff8:imap.uio.no:NA:ProcessCurrentURL: aborting queued urls
3896[26cda78]: 2bb1ff8:imap.uio.no:NA:SendData: 4 logout

1520[275a0d8]: ImapThreadMainLoop entering [this=293f9b8]
1520[275a0d8]: 293f9b8:imap.uio.no:NA:ProcessCurrentURL: entering
1520[275a0d8]: 293f9b8:imap.uio.no:NA:ProcessCurrentURL:imap://jarre@imap.uio.no:143/folderstatus%3E.Tivoli.vakt:  = currentUrl
3896[26cda78]: ReadNextLine [stream=2961fa0 nb=38 needmore=0]
3896[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: * BYE IMAP4 server logging out, mate

1520[275a0d8]: ReadNextLine [stream=2810d30 nb=46 needmore=0]
1520[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * OK IMAP4 Ready mail-proxy1.uio.no 0002258c

3896[26cda78]: 2bb1ff8:imap.uio.no:NA:TellThreadToDie: close socket connection
3896[26cda78]: ImapThreadMainLoop leaving [this=2bb1ff8]
1520[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 1 capability

1520[275a0d8]: ReadNextLine [stream=2810d30 nb=228 needmore=0]
1520[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGINDISABLED

1520[275a0d8]: ReadNextLine [stream=2810d30 nb=17 needmore=0]
1520[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: 1 OK CAPABILITY

1520[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 2 STARTTLS

1520[275a0d8]: ReadNextLine [stream=2810d30 nb=32 needmore=0]
1520[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: 2 OK Begin TLS negotiation now

1520[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 3 capability

1520[275a0d8]: ReadNextLine [stream=2810d30 nb=205 needmore=0]
1520[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE

1520[275a0d8]: ReadNextLine [stream=2810d30 nb=17 needmore=0]
1520[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: 3 OK CAPABILITY

0[2c48d8]: 2bb1ff8:imap.uio.no:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
1520[275a0d8]: 293f9b8:imap.uio.no:NA:ProcessCurrentURL: aborting queued urls
1520[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 4 logout

824[26cda78]: ImapThreadMainLoop entering [this=2bb1ff8]
824[26cda78]: 2bb1ff8:imap.uio.no:NA:ProcessCurrentURL: entering
824[26cda78]: 2bb1ff8:imap.uio.no:NA:ProcessCurrentURL:imap://jarre@imap.uio.no:143/folderstatus%3E.Tivoli.uwwhichpr:  = currentUrl
1520[275a0d8]: ReadNextLine [stream=2810d30 nb=38 needmore=0]
1520[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * BYE IMAP4 server logging out, mate

1520[275a0d8]: 293f9b8:imap.uio.no:NA:TellThreadToDie: close socket connection
1520[275a0d8]: ImapThreadMainLoop leaving [this=293f9b8]
824[26cda78]: ReadNextLine [stream=280f388 nb=46 needmore=0]
824[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: * OK IMAP4 Ready mail-proxy2.uio.no 0002258d

824[26cda78]: 2bb1ff8:imap.uio.no:NA:SendData: 1 capability

824[26cda78]: ReadNextLine [stream=280f388 nb=228 needmore=0]
824[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGINDISABLED

824[26cda78]: ReadNextLine [stream=280f388 nb=17 needmore=0]
824[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: 1 OK CAPABILITY

824[26cda78]: 2bb1ff8:imap.uio.no:NA:SendData: 2 STARTTLS

824[26cda78]: ReadNextLine [stream=280f388 nb=32 needmore=0]
824[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: 2 OK Begin TLS negotiation now

824[26cda78]: 2bb1ff8:imap.uio.no:NA:SendData: 3 capability

824[26cda78]: ReadNextLine [stream=280f388 nb=205 needmore=0]
824[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE

824[26cda78]: ReadNextLine [stream=280f388 nb=17 needmore=0]
824[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: 3 OK CAPABILITY

0[2c48d8]: 293f9b8:imap.uio.no:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
824[26cda78]: 2bb1ff8:imap.uio.no:NA:ProcessCurrentURL: aborting queued urls
824[26cda78]: 2bb1ff8:imap.uio.no:NA:SendData: 4 logout

1440[275a0d8]: ImapThreadMainLoop entering [this=293f9b8]
1440[275a0d8]: 293f9b8:imap.uio.no:NA:ProcessCurrentURL: entering
1440[275a0d8]: 293f9b8:imap.uio.no:NA:ProcessCurrentURL:imap://jarre@imap.uio.no:143/folderstatus%3E.Tivoli.Watcher:  = currentUrl
824[26cda78]: ReadNextLine [stream=280f388 nb=38 needmore=0]
824[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: * BYE IMAP4 server logging out, mate

824[26cda78]: 2bb1ff8:imap.uio.no:NA:TellThreadToDie: close socket connection
824[26cda78]: ImapThreadMainLoop leaving [this=2bb1ff8]
1440[275a0d8]: ReadNextLine [stream=26a80e0 nb=46 needmore=0]
1440[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * OK IMAP4 Ready mail-proxy1.uio.no 0002258c

1440[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 1 capability

1440[275a0d8]: ReadNextLine [stream=26a80e0 nb=228 needmore=0]
1440[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGINDISABLED

1440[275a0d8]: ReadNextLine [stream=26a80e0 nb=17 needmore=0]
1440[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: 1 OK CAPABILITY

1440[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 2 STARTTLS

1440[275a0d8]: ReadNextLine [stream=26a80e0 nb=32 needmore=0]
1440[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: 2 OK Begin TLS negotiation now

1440[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 3 capability

1440[275a0d8]: ReadNextLine [stream=26a80e0 nb=205 needmore=0]
1440[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE

1440[275a0d8]: ReadNextLine [stream=26a80e0 nb=17 needmore=0]
1440[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: 3 OK CAPABILITY

0[2c48d8]: 2bb1ff8:imap.uio.no:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
1440[275a0d8]: 293f9b8:imap.uio.no:NA:ProcessCurrentURL: aborting queued urls
1440[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 4 logout

1512[26cda78]: ImapThreadMainLoop entering [this=2bb1ff8]
1512[26cda78]: 2bb1ff8:imap.uio.no:NA:ProcessCurrentURL: entering
1512[26cda78]: 2bb1ff8:imap.uio.no:NA:ProcessCurrentURL:imap://jarre@imap.uio.no:143/folderstatus%3E.Tivoli.Statistikk:  = currentUrl
1440[275a0d8]: ReadNextLine [stream=26a80e0 nb=38 needmore=0]
1440[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * BYE IMAP4 server logging out, mate

1440[275a0d8]: 293f9b8:imap.uio.no:NA:TellThreadToDie: close socket connection
1440[275a0d8]: ImapThreadMainLoop leaving [this=293f9b8]
1512[26cda78]: ReadNextLine [stream=2961fa0 nb=46 needmore=0]
1512[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: * OK IMAP4 Ready mail-proxy2.uio.no 0002258d

1512[26cda78]: 2bb1ff8:imap.uio.no:NA:SendData: 1 capability

1512[26cda78]: ReadNextLine [stream=2961fa0 nb=228 needmore=0]
1512[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGINDISABLED

1512[26cda78]: ReadNextLine [stream=2961fa0 nb=17 needmore=0]
1512[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: 1 OK CAPABILITY

1512[26cda78]: 2bb1ff8:imap.uio.no:NA:SendData: 2 STARTTLS

1512[26cda78]: ReadNextLine [stream=2961fa0 nb=32 needmore=0]
1512[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: 2 OK Begin TLS negotiation now

1512[26cda78]: 2bb1ff8:imap.uio.no:NA:SendData: 3 capability

1512[26cda78]: ReadNextLine [stream=2961fa0 nb=205 needmore=0]
1512[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE

1512[26cda78]: ReadNextLine [stream=2961fa0 nb=17 needmore=0]
1512[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: 3 OK CAPABILITY

0[2c48d8]: 293f9b8:imap.uio.no:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
1512[26cda78]: 2bb1ff8:imap.uio.no:NA:ProcessCurrentURL: aborting queued urls
1512[26cda78]: 2bb1ff8:imap.uio.no:NA:SendData: 4 logout

2740[275a0d8]: ImapThreadMainLoop entering [this=293f9b8]
2740[275a0d8]: 293f9b8:imap.uio.no:NA:ProcessCurrentURL: entering
2740[275a0d8]: 293f9b8:imap.uio.no:NA:ProcessCurrentURL:imap://jarre@imap.uio.no:143/folderstatus%3E.Tivoli.nyTMR:  = currentUrl
2740[275a0d8]: ReadNextLine [stream=2810d30 nb=46 needmore=0]
2740[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * OK IMAP4 Ready mail-proxy1.uio.no 0002258c

1512[26cda78]: ReadNextLine [stream=2961fa0 nb=38 needmore=0]
1512[26cda78]: 2bb1ff8:imap.uio.no:NA:CreateNewLineFromSocket: * BYE IMAP4 server logging out, mate

1512[26cda78]: 2bb1ff8:imap.uio.no:NA:TellThreadToDie: close socket connection
1512[26cda78]: ImapThreadMainLoop leaving [this=2bb1ff8]
2740[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 1 capability

2740[275a0d8]: ReadNextLine [stream=2810d30 nb=228 needmore=0]
2740[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGINDISABLED

2740[275a0d8]: ReadNextLine [stream=2810d30 nb=17 needmore=0]
2740[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: 1 OK CAPABILITY

2740[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 2 STARTTLS

2740[275a0d8]: ReadNextLine [stream=2810d30 nb=32 needmore=0]
2740[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: 2 OK Begin TLS negotiation now

2740[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 3 capability

2740[275a0d8]: ReadNextLine [stream=2810d30 nb=205 needmore=0]
2740[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE

2740[275a0d8]: ReadNextLine [stream=2810d30 nb=17 needmore=0]
2740[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: 3 OK CAPABILITY

0[2c48d8]: 1e0ba18:imap.uio.no:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
3804[26cda78]: ImapThreadMainLoop entering [this=1e0ba18]
3804[26cda78]: 1e0ba18:imap.uio.no:NA:ProcessCurrentURL: entering
3804[26cda78]: 1e0ba18:imap.uio.no:NA:ProcessCurrentURL:imap://jarre@imap.uio.no:143/folderstatus%3E.Tivoli.Vogel:  = currentUrl
3804[26cda78]: ReadNextLine [stream=2c3fb70 nb=46 needmore=0]
3804[26cda78]: 1e0ba18:imap.uio.no:NA:CreateNewLineFromSocket: * OK IMAP4 Ready mail-proxy2.uio.no 0002258d

3804[26cda78]: 1e0ba18:imap.uio.no:NA:SendData: 1 capability

3804[26cda78]: ReadNextLine [stream=2c3fb70 nb=228 needmore=0]
3804[26cda78]: 1e0ba18:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGINDISABLED

2740[275a0d8]: 293f9b8:imap.uio.no:NA:ProcessCurrentURL: aborting queued urls
2740[275a0d8]: 293f9b8:imap.uio.no:NA:SendData: 4 logout

2740[275a0d8]: ReadNextLine [stream=2810d30 nb=38 needmore=0]
2740[275a0d8]: 293f9b8:imap.uio.no:NA:CreateNewLineFromSocket: * BYE IMAP4 server logging out, mate

2740[275a0d8]: 293f9b8:imap.uio.no:NA:TellThreadToDie: close socket connection
2740[275a0d8]: ImapThreadMainLoop leaving [this=293f9b8]
3804[26cda78]: ReadNextLine [stream=2c3fb70 nb=17 needmore=0]
3804[26cda78]: 1e0ba18:imap.uio.no:NA:CreateNewLineFromSocket: 1 OK CAPABILITY

3804[26cda78]: 1e0ba18:imap.uio.no:NA:SendData: 2 STARTTLS

3804[26cda78]: ReadNextLine [stream=2c3fb70 nb=32 needmore=0]
3804[26cda78]: 1e0ba18:imap.uio.no:NA:CreateNewLineFromSocket: 2 OK Begin TLS negotiation now

3804[26cda78]: 1e0ba18:imap.uio.no:NA:SendData: 3 capability

3804[26cda78]: ReadNextLine [stream=2c3fb70 nb=205 needmore=0]
3804[26cda78]: 1e0ba18:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE

3804[26cda78]: ReadNextLine [stream=2c3fb70 nb=17 needmore=0]
3804[26cda78]: 1e0ba18:imap.uio.no:NA:CreateNewLineFromSocket: 3 OK CAPABILITY

0[2c48d8]: 2c1ad28:imap.uio.no:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
1448[275a0d8]: ImapThreadMainLoop entering [this=2c1ad28]
1448[275a0d8]: 2c1ad28:imap.uio.no:NA:ProcessCurrentURL: entering
1448[275a0d8]: 2c1ad28:imap.uio.no:NA:ProcessCurrentURL:imap://jarre@imap.uio.no:143/folderstatus%3E.Tivoli.cvs:  = currentUrl
1448[275a0d8]: ReadNextLine [stream=26a80e0 nb=46 needmore=0]
1448[275a0d8]: 2c1ad28:imap.uio.no:NA:CreateNewLineFromSocket: * OK IMAP4 Ready mail-proxy1.uio.no 0002258c

1448[275a0d8]: 2c1ad28:imap.uio.no:NA:SendData: 1 capability

1448[275a0d8]: ReadNextLine [stream=26a80e0 nb=228 needmore=0]
1448[275a0d8]: 2c1ad28:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGINDISABLED

3804[26cda78]: 1e0ba18:imap.uio.no:NA:ProcessCurrentURL: aborting queued urls
3804[26cda78]: 1e0ba18:imap.uio.no:NA:SendData: 4 logout

3804[26cda78]: ReadNextLine [stream=2c3fb70 nb=38 needmore=0]
3804[26cda78]: 1e0ba18:imap.uio.no:NA:CreateNewLineFromSocket: * BYE IMAP4 server logging out, mate

3804[26cda78]: 1e0ba18:imap.uio.no:NA:TellThreadToDie: close socket connection
3804[26cda78]: ImapThreadMainLoop leaving [this=1e0ba18]
1448[275a0d8]: ReadNextLine [stream=26a80e0 nb=17 needmore=0]
1448[275a0d8]: 2c1ad28:imap.uio.no:NA:CreateNewLineFromSocket: 1 OK CAPABILITY

1448[275a0d8]: 2c1ad28:imap.uio.no:NA:SendData: 2 STARTTLS

1448[275a0d8]: ReadNextLine [stream=26a80e0 nb=32 needmore=0]
1448[275a0d8]: 2c1ad28:imap.uio.no:NA:CreateNewLineFromSocket: 2 OK Begin TLS negotiation now

1448[275a0d8]: 2c1ad28:imap.uio.no:NA:SendData: 3 capability

1448[275a0d8]: ReadNextLine [stream=26a80e0 nb=205 needmore=0]
1448[275a0d8]: 2c1ad28:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE

1448[275a0d8]: ReadNextLine [stream=26a80e0 nb=17 needmore=0]
1448[275a0d8]: 2c1ad28:imap.uio.no:NA:CreateNewLineFromSocket: 3 OK CAPABILITY

0[2c48d8]: 2a312d0:imap.uio.no:NA:SetupWithUrl: clearing IMAP_CONNECTION_IS_OPEN
888[26cda78]: ImapThreadMainLoop entering [this=2a312d0]
888[26cda78]: 2a312d0:imap.uio.no:NA:ProcessCurrentURL: entering
888[26cda78]: 2a312d0:imap.uio.no:NA:ProcessCurrentURL:imap://jarre@imap.uio.no:143/folderstatus%3E.Tivoli.Patching:  = currentUrl
888[26cda78]: ReadNextLine [stream=294a648 nb=46 needmore=0]
888[26cda78]: 2a312d0:imap.uio.no:NA:CreateNewLineFromSocket: * OK IMAP4 Ready mail-proxy2.uio.no 0002258d

888[26cda78]: 2a312d0:imap.uio.no:NA:SendData: 1 capability

888[26cda78]: ReadNextLine [stream=294a648 nb=228 needmore=0]
888[26cda78]: 2a312d0:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGINDISABLED

1448[275a0d8]: 2c1ad28:imap.uio.no:NA:ProcessCurrentURL: aborting queued urls
1448[275a0d8]: 2c1ad28:imap.uio.no:NA:SendData: 4 logout

1448[275a0d8]: ReadNextLine [stream=26a80e0 nb=38 needmore=0]
1448[275a0d8]: 2c1ad28:imap.uio.no:NA:CreateNewLineFromSocket: * BYE IMAP4 server logging out, mate

1448[275a0d8]: 2c1ad28:imap.uio.no:NA:TellThreadToDie: close socket connection
1448[275a0d8]: ImapThreadMainLoop leaving [this=2c1ad28]
888[26cda78]: ReadNextLine [stream=294a648 nb=17 needmore=0]
888[26cda78]: 2a312d0:imap.uio.no:NA:CreateNewLineFromSocket: 1 OK CAPABILITY

888[26cda78]: 2a312d0:imap.uio.no:NA:SendData: 2 STARTTLS

888[26cda78]: ReadNextLine [stream=294a648 nb=32 needmore=0]
888[26cda78]: 2a312d0:imap.uio.no:NA:CreateNewLineFromSocket: 2 OK Begin TLS negotiation now

888[26cda78]: 2a312d0:imap.uio.no:NA:SendData: 3 capability

888[26cda78]: ReadNextLine [stream=294a648 nb=205 needmore=0]
888[26cda78]: 2a312d0:imap.uio.no:NA:CreateNewLineFromSocket: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE

0[2c48d8]: 2a312d0:imap.uio.no:NA:SendData: 4 logout

888[26cda78]: ReadNextLine [stream=294a648 nb=17 needmore=0]
888[26cda78]: 2a312d0:imap.uio.no:NA:CreateNewLineFromSocket: 3 OK CAPABILITY

0[2c48d8]: 2a312d0:imap.uio.no:NA:TellThreadToDie: close socket connection
888[26cda78]: 2a312d0:imap.uio.no:NA:ProcessCurrentURL: aborting queued urls
888[26cda78]: ImapThreadMainLoop leaving [this=2a312d0]

Thanks for the log. Next time please add things like that as an attachment rather than an in-line comment, thanks!
All I see in that log is us trying STARTTLS and it failing - did we actually successfully logon in that session?
(In reply to comment #4)
> All I see in that log is us trying STARTTLS and it failing - did we actually
> successfully logon in that session?

No. It looks as if Thunderbird try to log in using username/passowrd anyway, before asking to turn encryption on. 
So logon fails (unless imap-server accepts unencrypted logon, but then it succeeds without encryption, and that was not what was wanted).

Only problem when starting Thunderbird. If you start Thunderbird and then turn unecrypted authentiction off on the imap-server everything works well. So it's looks like the problem is in the sequence of actions (ask for encryption first, then authenticate. Not the other way around)
Can you attach a log showing that? This log, as I said, just shows STARTTLS failing over and over again, and no actual logon attempt, successful or otherwise. Or else I'm missing something - do you see an actual logon in that log?
I've checked in the last patch in bug 311939 - if you want to try a trunk build from tomorrow or later and let me know what shows up in our imap protocol log in this situation, that would be very helpful. That patch detects an ssl level error doing starttls and aborts the connection if it gets such an error. I've added the error value to the log as well. Thx!

http://www.mozilla.org/quality/mailnews/mail-troubleshoot.html#imap
Installed and tested using http://ftp.mozilla.org/pub/mozilla.org/thunderbird/nightly/latest-trunk/thunderbird-3.0a1.en-US.win32.installer.exe
Here the bug was fixed (TLS worked on encrypted imap)

1. Do you still want a log? 
2. Have been trying to find a log from the imap-server showing the problem better than thunderbirds log. Still digging though.

JarrE
a Thunderbird protocol log from that build would still be interesting to me, because I could see what error you're getting - I'm glad it's working for you, but I doubt we're putting up an appropriate error message in your situation, and that's what I'd like to try to do.
Here is log from startup with TLS and nightly build
JarrE, do you still see this problem?   

If so, log needs analysis
Keywords: qawanted
(In reply to comment #11)
> JarrE, do you still see this problem?   
> If so, log needs analysis

The problem was fixed (Thunderbird failed if imap-server demanded encrypted line, since it first tried unencrytpted and received error message).
What remained was fixing error-messages since messages and errors were uncorrect.

So severity is no minor, but it should be fixed so that it is easier to understand what failes based on error-messages...

Mvh/
JarrE
Do we know if what's left to do described in bug 347995, bug 376252 or elsewhere?
Uncertain what you mean. 
It looks as if 347995 and 376252 is the same bug as what remains of this. Main problem (if I have understood and remeber correctly) is that there is an incorrect mapping of errors and messages...
Do not think there exists a description for what's left to do except sort of 'check mapping between errors and messages'
Hi JarrE. what I mean is, do those bugs describe ALL of what is you think is still incorrect - as stated in comment 12?  If not, please file a new bug.  

As for this bug, I suggest the original problem as described is done - fixed by bug 311939 as you state in comment 8.  duping to bug 311939.
Status: ASSIGNED → RESOLVED
Closed: 16 years ago
Keywords: qawanted
Resolution: --- → DUPLICATE
Summary: TLS not working as intended → TLS not working as intended - Thunderbird tries to log on using username/password before asking for encryption
(In reply to comment #15)
> Hi JarrE. what I mean is, do those bugs describe ALL of what is you think is
> still incorrect - as stated in comment 12?  

Yes
This bug is reopened as TLS again is broken (TB 3.0RC1 & TB 3.0RC2)
Attach log
Symptoms the same as before, TLS, port 143 to encrypted imap (not allowing unsecure connections) fails with no error
Status: RESOLVED → REOPENED
blocking-thunderbird3.0: --- → ?
Flags: blocking-thunderbird3?
Resolution: DUPLICATE → ---
Startup log for STARTTLS and TB 3.0RC2
Not blocking 3.0 on this as we've not had other reports as far as we can tell, and I'd expect to hear something else if this isn't working properly.

Will consider for blocking TB 3.0.1 though.
Flags: blocking-thunderbird3? → blocking-thunderbird3-
What's odd is that the server isn't returning STARTTLS as a capability anymore, unless I'm reading something wrong.
Nobody else reported it the last time either (I think very few don't allow uncryptet login). But it worked on TB 3.0 a1, so something has changed
Looks as if it works on Windows 7 (64 bit), but not on Windows XP
Will test more
TLS works on Windows 7 (64-bit) but fails on Vista and XP (32-bit)
Included log from imap-server (which doesn't say much)
To me, this sounds like an edge-case situation, especially as I believe we haven't seen other reports of it. Therefore not blocking 3.0.x at the moment. If more information comes to light then we can reconsider.
blocking-thunderbird3.0: ? → -
The same bug still holds for Thunderbird 3.0.1 and Lanikai 3.1a1
Log from imap-server:
2010/03/25 09:10:36 [info] 22340#0: *1 client ::ffff:129.240.202.95
connected to [::]:143
2010/03/25 09:10:36 [debug] 22340#0: *1 imap auth state
2010/03/25 09:10:36 [debug] 22340#0: *1 imap auth command: 3
2010/03/25 09:10:36 [debug] 22340#0: *1 imap auth state
2010/03/25 09:10:36 [debug] 22340#0: *1 imap auth command: 5
2010/03/25 09:11:04 [info] 22340#0: *1 peer closed connection in SSL
handshake while in starttls state, client: ::ffff:129.240.202.95 using
starttls, server: [::]:143
2010/03/25 09:11:04 [debug] 22340#0: *1 close mail connection: 14

Thunderbird logs on if TLS-security is set to Off
If set to 'Only' (as we use) or 'On' Thunderbird (3.x, from Windows 32-bit) fails

This is still a problem and is affecting all our users and makes Thunderbird (or Postbox) useless - please keep Thunderbird 2 alive til this problem is solved (else you just lost 40k users)

The problem has been solved once before (by David :Bienvenu I believe)  

JarrE
Your server is dropping the connection during the STARTTLS process, according to that log.  That implies a configuration issue on the server, or unhappiness perhaps with a client cert. Is there an ssl cert installed on the client? The fix for bug 549457, which landed yesterday, makes us tell the user when there was an error doing starttls.
Same profile and user on different computers. Win32 (XP & Vista) fails. Linux & Windows 7 (64-bit) works. 
Sounds like the problem follows the OS, not the server (we have 14000 computers (laptops etc excluded) and tested on many of those. No exceptions in behaviour so far). And no certs installed (tried clean installations of OSs with no other programs installed)
In case it is of any help...
Further testing shows the same error using imap-servers:
nginx 0.8.35
nginx 0.7.65
cyrus imapd 2.2.12
courier imapd 4.4.1

and clients:
Postbox
Thunderbird
Zimbra
Eudora (8.0 b9)
Seamonkey
The error is actually specific to the use of port 143.


New TCP connection #1: lipk-test03.uio.no(4434) <-> mail-utv1.uio.no(1143)
TCP: mail-utv1.uio.no(1143) -> lipk-test03.uio.no(4434) Seq 4016422102.(18) ACK 2547582691 PUSH
0.0026 (0.0026)  S>C
---------------------------------------------------------------
* OK IMAP4 ready
---------------------------------------------------------------

TCP: lipk-test03.uio.no(4434) -> mail-utv1.uio.no(1143) Seq 2547582691.(0) ACK 4016422120
TCP: lipk-test03.uio.no(4434) -> mail-utv1.uio.no(1143) Seq 2547582691.(14) ACK 4016422120 PUSH
0.4015 (0.3989)  C>S
---------------------------------------------------------------
1 capability
---------------------------------------------------------------

TCP: mail-utv1.uio.no(1143) -> lipk-test03.uio.no(4434) Seq 4016422120.(0) ACK 2547582705
TCP: mail-utv1.uio.no(1143) -> lipk-test03.uio.no(4434) Seq 4016422120.(244) ACK 2547582705 PUSH
0.4021 (0.0006)  S>C
---------------------------------------------------------------
* CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGI
NDISABLED
1 OK completed
---------------------------------------------------------------

TCP: lipk-test03.uio.no(4434) -> mail-utv1.uio.no(1143) Seq 2547582705.(12) ACK 4016422364 PUSH
0.4086 (0.0065)  C>S
---------------------------------------------------------------
2 STARTTLS
---------------------------------------------------------------

TCP: mail-utv1.uio.no(1143) -> lipk-test03.uio.no(4434) Seq 4016422364.(16) ACK 2547582717 PUSH
0.4089 (0.0003)  S>C
---------------------------------------------------------------
2 OK completed
---------------------------------------------------------------

TCP: lipk-test03.uio.no(4434) -> mail-utv1.uio.no(1143) Seq 2547582717.(167) ACK 4016422380 PUSH
1 1  0.4101 (0.0011)  C>S V3.1(162)  Handshake
TCP: mail-utv1.uio.no(1143) -> lipk-test03.uio.no(4434) Seq 4016422380.(2920) ACK 2547582884
1 2  0.4107 (0.0006)  S>C V3.1(74)  Handshake

################################################################################

We see here that the Windows-machine starts a SSL-handshake package. But it does not the same on using port 143. Instead it only sends an ACK-package, not containing any data, followed by a FIN-package.


################################################################################
New TCP connection #2: lipk-test03.uio.no(4410) <-> mail-utv1.uio.no(143)
TCP: mail-utv1.uio.no(143) -> lipk-test03.uio.no(4410) Seq 3885353851.(18) ACK 3060510995 PUSH
0.0005 (0.0005)  S>C
---------------------------------------------------------------
* OK IMAP4 ready
---------------------------------------------------------------

TCP: lipk-test03.uio.no(4410) -> mail-utv1.uio.no(143) Seq 3060510995.(14) ACK 3885353869 PUSH
0.0059 (0.0053)  C>S
---------------------------------------------------------------
1 capability
---------------------------------------------------------------

TCP: mail-utv1.uio.no(143) -> lipk-test03.uio.no(4410) Seq 3885353869.(0) ACK 3060511009
TCP: mail-utv1.uio.no(143) -> lipk-test03.uio.no(4410) Seq 3885353869.(244) ACK 3060511009 PUSH
0.0060 (0.0000)  S>C
---------------------------------------------------------------
* CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS LOGINDISABLED
1 OK completed
---------------------------------------------------------------

TCP: lipk-test03.uio.no(4410) -> mail-utv1.uio.no(143) Seq 3060511009.(12) ACK 3885354113 PUSH
0.0070 (0.0010)  C>S
---------------------------------------------------------------
2 STARTTLS
---------------------------------------------------------------

TCP: mail-utv1.uio.no(143) -> lipk-test03.uio.no(4410) Seq 3885354113.(16) ACK 3060511021 PUSH
0.0071 (0.0000)  S>C
---------------------------------------------------------------
2 OK completed
---------------------------------------------------------------

TCP: lipk-test03.uio.no(4410) -> mail-utv1.uio.no(143) Seq 3060511021.(0) ACK 3885354129
TCP: lipk-test03.uio.no(4410) -> mail-utv1.uio.no(143) Seq 3060511021.(0) ACK 3885354129 FIN
2    38.3540 (38.3469)  C>S  TCP FIN
TCP: mail-utv1.uio.no(143) -> lipk-test03.uio.no(4410) Seq 3885354129.(0) ACK 3060511022 FIN
2    38.3544 (0.0004)  S>C  TCP FIN
TCP: lipk-test03.uio.no(4410) -> mail-utv1.uio.no(143) Seq 3060511022.(0) ACK 3885354130

################################################################################

So the e-mail server (nginx tested here) and Thunderbird communicates using TLS as long as the imap-server is not using the port 143

Please FIX!

Regards/
JarrE
Problem found, solved and it was ours (embarrased now).

You can close the bug. 
For the record the bug existed because of a misconfigured anti-virus server which checked traffic on port 143, delaying it til it used to much time for communication to work.

Thank you for all time used trying to understand the problem and trying to solve it...

Regards/
JarrE
Thanks for the clarification, closing.
Status: REOPENED → RESOLVED
Closed: 16 years ago14 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: