Closed Bug 1759271 Opened 5 months ago Closed 5 months ago

get an alert appears saying 'server required encrypted password' - pop3AuthChangePlainToEncrypt

Categories

(MailNews Core :: Networking: POP, defect)

Thunderbird 99
defect

Tracking

(thunderbird_esr91 unaffected, thunderbird99 fixed)

RESOLVED FIXED
100 Branch
Tracking Status
thunderbird_esr91 --- unaffected
thunderbird99 --- fixed

People

(Reporter: yoz, Assigned: rnons)

References

(Regression)

Details

(Keywords: regression)

Attachments

(5 files, 1 obsolete file)

User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/15.3 Safari/605.1.15

Steps to reproduce:

  1. (Upgrade to 99.0b1 from 98.0b2)
  2. Choose 'Get message' in the tool bar

Actual results:

  1. an alert appears saying 'server required encrypted password'
  2. (change account setting and get message again)
  3. an alert appears saying '[AUTH] CRAM-MD5 authentication is disabled.'

Expected results:

connect server successfully

What was the setting originally, and what did you change it to?
Can you provide a pop3 protocol log? - https://wiki.mozilla.org/MailNews:Logging

Group: mail-core-security
Component: Mail Window Front End → Networking: POP
Keywords: regression
Product: Thunderbird → MailNews Core
Summary: pop3AuthChangePlainToEncrypt → get an alert appears saying 'server required encrypted password' - pop3AuthChangePlainToEncrypt

I changed nothing in the account settings.
Same POP3 server, same connection settings below:
INCOMING: account5, , (pop3) pop.pluto.dti.ne.jp:110, 0, passwordCleartext

I got POP3 protocol log reproducing the issue. Here we go:

2022-03-13 09:02:52.610634 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=131ebd0e0] BeginMailDelivery acquiring semaphore
2022-03-13 09:02:52.626387 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13ec27cc0] BeginMailDelivery acquiring semaphore
2022-03-13 09:02:52.657666 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=131ebd0e0] Calling ReleaseFolderLock from EndMailDelivery
2022-03-13 09:02:52.657671 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=131ebd0e0] ReleaseFolderLock haveSemaphore = TRUE
2022-03-13 09:02:52.661963 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13ec27cc0] Calling ReleaseFolderLock from EndMailDelivery
2022-03-13 09:02:52.661965 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13ec27cc0] ReleaseFolderLock haveSemaphore = TRUE
2022-03-13 09:02:52.676587 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13ec27e60] BeginMailDelivery acquiring semaphore
2022-03-13 09:02:52.809217 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13ec27e60] Calling ReleaseFolderLock from EndMailDelivery
2022-03-13 09:02:52.809226 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13ec27e60] ReleaseFolderLock haveSemaphore = TRUE
2022-03-13 09:02:59.407490 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13675f230] BeginMailDelivery acquiring semaphore
2022-03-13 09:02:59.430034 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=136bb8f40] BeginMailDelivery acquiring semaphore
2022-03-13 09:02:59.445464 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13675f230] Calling ReleaseFolderLock from EndMailDelivery
2022-03-13 09:02:59.445468 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13675f230] ReleaseFolderLock haveSemaphore = TRUE
2022-03-13 09:02:59.466843 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=136bb8f40] Calling ReleaseFolderLock from EndMailDelivery
2022-03-13 09:02:59.466847 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=136bb8f40] ReleaseFolderLock haveSemaphore = TRUE
2022-03-13 09:02:59.496573 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=136bb9010] BeginMailDelivery acquiring semaphore
2022-03-13 09:02:59.617427 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=136bb9010] Calling ReleaseFolderLock from EndMailDelivery
2022-03-13 09:02:59.617437 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=136bb9010] ReleaseFolderLock haveSemaphore = TRUE
2022-03-13 09:03:02.761868 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13544b300] Calling ReleaseFolderLock from AbortMailDelivery
2022-03-13 09:03:02.761878 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13544b300] ReleaseFolderLock haveSemaphore = FALSE
2022-03-13 09:03:04.088287 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13ec27e60] Calling ReleaseFolderLock from ~nsPop3Sink
2022-03-13 09:03:04.088293 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13ec27e60] ReleaseFolderLock haveSemaphore = FALSE
2022-03-13 09:03:04.088300 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13ec27cc0] Calling ReleaseFolderLock from ~nsPop3Sink
2022-03-13 09:03:04.088302 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13ec27cc0] ReleaseFolderLock haveSemaphore = FALSE
2022-03-13 09:03:04.088304 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=131ebd0e0] Calling ReleaseFolderLock from ~nsPop3Sink
2022-03-13 09:03:04.088305 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=131ebd0e0] ReleaseFolderLock haveSemaphore = FALSE
2022-03-13 09:03:04.088322 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=136bb9010] Calling ReleaseFolderLock from ~nsPop3Sink
2022-03-13 09:03:04.088324 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=136bb9010] ReleaseFolderLock haveSemaphore = FALSE
2022-03-13 09:03:04.088327 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=136bb8f40] Calling ReleaseFolderLock from ~nsPop3Sink
2022-03-13 09:03:04.088328 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=136bb8f40] ReleaseFolderLock haveSemaphore = FALSE
2022-03-13 09:03:04.088330 UTC - [Parent 27126: Main Thread]: D/POP3 sink: [this=13675f2

Can this help you?

But you say you changed the setting in step 2?

Please get logging using the mailnews.pop3.loglevel method (see the wiki), since since 99 the new pop3-js implementation is used.

OK. Please ignore step 2. The issue was step 1. Even though the server accepts clear text for password, TB99b1 showed the alert.

In step 2, the change of my setting was 'clear text' -> 'encrypted' in password. The result was NG.
But, today, I got an advise from my ISP how to change the setting on their server to accept encrypted password. So, right now, my own problem was solved.

Anyway, I'll try to get some logs.

Oops. Sorry for the double post.

The logs above might be not suitable.
I changed the settings of the server. So, right now, the server accepts encrypted password. It may not accept clear text password.
I'll try gettin logs again tomorrow.

At last, I got logs. Here we go:

mailnews.pop3: Connecting to pop://pop.pluto.dti.ne.jp:110 Pop3Client.jsm:126:18
mailnews.pop3: Connected Pop3Client.jsm:249:18
mailnews.pop3: S: +OK melody-2.1j-DTI server ready <0026920.1647255886@silkpop21.cm2.dti.ne.jp>

Pop3Client.jsm:290:18
mailnews.pop3: C: CAPA Pop3Client.jsm:402:20
mailnews.pop3: S: +OK Capability list follows.

TOP

USER

SASL CRAM-MD5

RESP-CODE

AUTH-RESP-CODE

LOGIN-DELAY 300 USER

PIPELINING

EXPIRE 0 USER

UIDL

IMPLEMENTATION melody-2.1j-DTI

.

Pop3Client.jsm:290:18
mailnews.pop3: Possible auth methods: Pop3Client.jsm:477:18
mailnews.pop3: Got an error name=pop3AuthChangePlainToEncrypt Pop3Client.jsm:1184:18
_actionError resource:///modules/Pop3Client.jsm:1184
_actionChooseFirstAuthMethod resource:///modules/Pop3Client.jsm:499
_actionCapaResponse resource:///modules/Pop3Client.jsm:445
read resource:///modules/LineReader.jsm:55
_actionCapaResponse resource:///modules/Pop3Client.jsm:433
_onData resource:///modules/Pop3Client.jsm:292
mailnews.pop3: C: QUIT Pop3Client.jsm:402:20
mailnews.pop3: Connection closed. Pop3Client.jsm:313:18
mailnews.pop3: S: +OK Closing session.

Pop3Client.jsm:290:18

Hi, you mentioned the server supports plain text auth, but according to SASL CRAM-MD5 in comment 10, only CRAM-MD5 is supported.

But, today, I got an advise from my ISP how to change the setting on their server to accept encrypted password. So, right now, my own problem was solved.

Did you also remove plaintext auth so that explains comment 10?

Hi.

but according to SASL CRAM-MD5 in comment 10, only CRAM-MD5 is supported.

I agree with you. However, TB was connecting to a server that returns such results with a plain text password.
FYI, I found that I have TB78.14 on my Raspberry Pi. It connects correctly to the server (pop.pluto.dti.ne.jp) with plain text password.

Did you also remove plaintext auth so that explains comment 10?

No. I didn't remove plaintext auth. I changed my configuration to connect to the another server that supports connection with SSL.
Like : pop.pluto.dti.ne.jp -> pop.cm.dream.jp (They are provided by same ISP)
It seems that pop.cm.dream.jp is using a different POP server than the previous server.
So, since this problem originated from the previous server, my configuration changes are not relevant.

Attached file TB78.14 (obsolete) —
I got logs with TB78.14.  Does this help?
Attached file TB78.14-2
Please discard the log of TB78.14 that I mentioned earlier. Here is the correct one.
Attachment #9267845 - Attachment is obsolete: true

Very helpful, the key is RECV: USER after SEND: CAPA, which means your server supports USERPASS auth. I got this wrong in the code, will make a fix soon. Thanks.

Assignee: nobody → remotenonsense
Status: UNCONFIRMED → ASSIGNED
Ever confirmed: true
Target Milestone: --- → 100 Branch

Pushed by mkmelin@iki.fi:
https://hg.mozilla.org/comm-central/rev/dbc775a37ad6
Fix USERPASS auth in POP3Client.jsm. r=mkmelin

Status: ASSIGNED → RESOLVED
Closed: 5 months ago
Resolution: --- → FIXED

Comment on attachment 9267966 [details]
Bug 1759271 - Fix USERPASS auth in POP3Client.jsm. r=mkmelin

[Approval Request Comment]
Regression caused by (bug #): bug 1707548
User impact if declined: USERPASS auth may not work for some server and user config combinations.
Testing completed (on c-c, etc.): c-c
Risk to taking this patch (and alternatives if risky): low

Attachment #9267966 - Flags: approval-comm-beta?

Comment on attachment 9267966 [details]
Bug 1759271 - Fix USERPASS auth in POP3Client.jsm. r=mkmelin

[Triage Comment]
Approved for beta

Attachment #9267966 - Flags: approval-comm-beta? → approval-comm-beta+
You need to log in before you can comment on or make changes to this bug.