Closed Bug 1759271 Opened 2 years ago Closed 2 years ago

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

Categories

(MailNews Core :: Networking: POP, defect)

Product:
MailNews Core
Component:
Networking: POP
Version:
Thunderbird 99
Type:
defect

Tracking

(thunderbird_esr91 unaffected, thunderbird99 fixed)

Status:
RESOLVED FIXED
Milestone:
100 Branch
Tracking Flags:
Tracking Status
thunderbird_esr91 --- unaffected
thunderbird99 --- fixed

People

(Reporter: yoz, Assigned: rnons)

References

(Regression)

Details

(Keywords: regression)

Attachments

(5 files, 1 obsolete file)

log in error console and trouble shooting info
20.62 KB, text/plain
Details
mailnews.pop3.loglevel = ALL
2.12 KB, text/plain
Details
mailnews.pop3.loglevel = ALL
2.12 KB, text/plain
Details
TB78.14-2
10.21 KB, text/plain
Details
Bug 1759271 - Fix USERPASS auth in POP3Client.jsm. r=mkmelin
48 bytes, text/x-phabricator-request
wsmwk
: approval-comm-beta+
Details | Review

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

    
  
Keywords: checkin-needed-tb
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: 2 years ago
Keywords: checkin-needed-tb
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.
        






  

    
  







  

    

      
Attachment

      

      
      
      
      
    

    

      

        

          

            
General

            

              Creator: 



            

            
Created: 

            
Updated: 

            
Size: