[Courier-imap] Problem about "not support the selected authentication method" after version upgrade

SourceForge Headquarters 1320 Columbia Street Suite 310 San Diego, CA 92101 +1 (858) 422-6466

Hi courier-imap mail list.

I am newbie in list.
I using courier-imap and work fine, but encounter problem after upgrade to
5.0 (other courier relation package upgrade to latest version also).
Can help me?

Situation:
Server: FreeBSD Release 11.2 amd64. openssl: 1.0.2p, hostname: epopen.com
Courier-imap: Two IMAP accounts(as below sy...@ep... and other one)
using, work with MySQL authentication back-end via "courier-authlib-base"
and "courier-authlib-mysql".
Open port 143 (STARTTLS).

Description:
courier-imap version upgraded from 4.18.2 to 5.0 and converted maildir
folders' names to Unicode by "maildirmake".
Open Thunderbird 60.2.1 (64bit @ Ubuntu 16.04) got below error message and
can't download any mail.
    "The IMAP server imap.epopen.com does not support the selected
authentication method. Please change the 'Authentication method' in the
'Account Settings| Server settings'."

Debug:Thunderbird side:
1.Open terminal, add "export MOZ_LOG=IMAP:5,timestamp" and "
*export MOZ_LOG_FILE=/tmp/imap.log" into eniverment variable, start
Thunderbird and got below error message from /tmp/imap.log*

*   2018-11-01 03:30:11.327085 UTC - [31322:Unnamed thread 0x7fd914905280]:
D/IMAP ImapThreadMainLoop entering [this=0x7fd915778000]   2018-11-01
03:30:11.328700 UTC - [31322:Unnamed thread 0x7fd9149055e0]: D/IMAP
ImapThreadMainLoop entering [this=0x7fd915787000]   2018-11-01
03:30:11.332843 UTC - [31322:Main Thread]: I/IMAP
0x7fd915778000:imap.epopen.com:NA:SetupWithUrlCallback: clearing
IMAP_CONNECTION_IS_OPEN   2018-11-01 03:30:11.332879 UTC - [31322:Unnamed
thread 0x7fd914905280]: I/IMAP
0x7fd915778000:imap.epopen.com:NA:ProcessCurrentURL: entering   2018-11-01
03:30:11.332882 UTC - [31322:Unnamed thread 0x7fd914905280]: I/IMAP
0x7fd915778000:imap.epopen.com:NA:ProcessCurrentURL:imap://system%40epopen%2E...@im...:143/select%3E.INBOX
<http://system%40epopen%2E...@im...:143/select%3E.INBOX>:  =
currentUrl   2018-11-01 03:30:11.332914 UTC - [31322:Main Thread]: I/IMAP
0x7fd915787000:imap.epopen.com:NA:SetupWithUrlCallback: clearing
IMAP_CONNECTION_IS_OPEN   2018-11-01 03:30:11.332950 UTC - [31322:Unnamed
thread 0x7fd9149055e0]: I/IMAP
0x7fd915787000:imap.epopen.com:NA:ProcessCurrentURL: entering   2018-11-01
03:30:11.332953 UTC - [31322:Unnamed thread 0x7fd9149055e0]: I/IMAP
0x7fd915787000:imap.epopen.com:NA:ProcessCurrentURL:imap://general%40epopen%2E...@im...:143/select%3E.INBOX
<http://general%40epopen%2E...@im...:143/select%3E.INBOX>:  =
currentUrl   2018-11-01 03:30:11.461707 UTC - [31322:Unnamed thread
0x7fd9149055e0]: D/IMAP ReadNextLine [stream=0x7fd91223cb80 nb=275
needmore=0]   2018-11-01 03:30:11.461712 UTC - [31322:Unnamed thread
0x7fd9149055e0]: I/IMAP
0x7fd915787000:imap.epopen.com:NA:CreateNewLineFromSocket: * OK [CAPABILITY
IMAP4rev1 UIDPLUS CHILDREN NAMESPACE THREAD=ORDEREDSUBJECT
THREAD=REFERENCES SORT QUOTA IDLE ACL ACL2=UNION STARTTLS LOGINDISABLED
ENABLE UTF8=ACCEPT] Courier-IMAP ready. Copyright 1998-2018 Double
Precision, Inc.  See COPYING for distribution information.   2018-11-01
03:30:11.462675 UTC - [31322:Unnamed thread 0x7fd914905280]: D/IMAP
ReadNextLine [stream=0x7fd91223c700 nb=275 needmore=0]   2018-11-01
03:30:11.462679 UTC - [31322:Unnamed thread 0x7fd914905280]: I/IMAP
0x7fd915778000:imap.epopen.com:NA:CreateNewLineFromSocket: * OK [CAPABILITY
IMAP4rev1 UIDPLUS CHILDREN NAMESPACE THREAD=ORDEREDSUBJECT
THREAD=REFERENCES SORT QUOTA IDLE ACL ACL2=UNION STARTTLS LOGINDISABLED
ENABLE UTF8=ACCEPT] Courier-IMAP ready. Copyright 1998-2018 Double
Precision, Inc.  See COPYING for distribution information.   2018-11-01
03:30:11.463753 UTC - [31322:Unnamed thread 0x7fd9149055e0]: I/IMAP
0x7fd915787000:imap.epopen.com:NA:SendData: 1 STARTTLS   2018-11-01
03:30:11.463759 UTC - [31322:Unnamed thread 0x7fd914905280]: I/IMAP
0x7fd915778000:imap.epopen.com:NA:SendData: 1 STARTTLS   2018-11-01
03:30:11.493226 UTC - [31322:Unnamed thread 0x7fd9149055e0]: D/IMAP
ReadNextLine [stream=0x7fd91223cb80 nb=37 needmore=0]   2018-11-01
03:30:11.493246 UTC - [31322:Unnamed thread 0x7fd9149055e0]: I/IMAP
0x7fd915787000:imap.epopen.com:NA:CreateNewLineFromSocket: 1 OK Begin
SSL/TLS negotiation now.   2018-11-01 03:30:11.493248 UTC - [31322:Unnamed
thread 0x7fd914905280]: D/IMAP ReadNextLine [stream=0x7fd91223c700 nb=37
needmore=0]   2018-11-01 03:30:11.493251 UTC - [31322:Unnamed thread
0x7fd914905280]: I/IMAP
0x7fd915778000:imap.epopen.com:NA:CreateNewLineFromSocket: 1 OK Begin
SSL/TLS negotiation now.   2018-11-01 03:30:11.493798 UTC - [31322:Unnamed
thread 0x7fd9149055e0]: I/IMAP 0x7fd915787000:imap.epopen.com:NA:SendData:
2 capability   2018-11-01 03:30:11.493824 UTC - [31322:Unnamed thread
0x7fd914905280]: I/IMAP 0x7fd915778000:imap.epopen.com:NA:SendData: 2
capability   2018-11-01 03:30:11.524571 UTC - [31322:Unnamed thread
0x7fd9149055e0]: D/IMAP ReadNextLine [stream=0x7fd91223cb80 nb=0
needmore=1]   2018-11-01 03:30:11.524577 UTC - [31322:Unnamed thread
0x7fd9149055e0]: I/IMAP
0x7fd915787000:imap.epopen.com:NA:CreateNewLineFromSocket: clearing
IMAP_CONNECTION_IS_OPEN - rv = 805a2fe7   2018-11-01 03:30:11.524687 UTC -
[31322:Unnamed thread 0x7fd9149055e0]: I/IMAP
0x7fd915787000:imap.epopen.com:NA:TellThreadToDie: close socket
connection   2018-11-01 03:30:11.524690 UTC - [31322:Unnamed thread
0x7fd9149055e0]: I/IMAP
0x7fd915787000:imap.epopen.com:NA:CreateNewLineFromSocket: (null)
2018-11-01 03:30:11.524713 UTC - [31322:Unnamed thread 0x7fd9149055e0]:
D/IMAP try to log in   2018-11-01 03:30:11.524714 UTC - [31322:Unnamed
thread 0x7fd9149055e0]: D/IMAP IMAP auth: server caps 0x44c2321, pref
0x1006, failed 0x0, avail caps 0x0   2018-11-01 03:30:11.524716 UTC -
[31322:Unnamed thread 0x7fd9149055e0]: D/IMAP (GSSAPI = 0x1000000, CRAM =
0x20000, NTLM = 0x100000, MSN = 0x200000, PLAIN = 0x1000, LOGIN = 0x2,
old-style IMAP login = 0x4, auth external IMAP login = 0x20000000, OAUTH2 =
0x800000000)   2018-11-01 03:30:11.524717 UTC - [31322:Unnamed thread
0x7fd9149055e0]: D/IMAP no remaining auth method   2018-11-01
03:30:11.526962 UTC - [31322:Unnamed thread 0x7fd9149055e0]: E/IMAP login
failed entirely   2018-11-01 03:30:11.526967 UTC - [31322:Unnamed thread
0x7fd914905280]: D/IMAP ReadNextLine [stream=0x7fd91223c700 nb=0
needmore=1]   2018-11-01 03:30:11.526971 UTC - [31322:Unnamed thread
0x7fd914905280]: I/IMAP
0x7fd915778000:imap.epopen.com:NA:CreateNewLineFromSocket: clearing
IMAP_CONNECTION_IS_OPEN - rv = 805a2fe7   2018-11-01 03:30:11.527312 UTC -
[31322:Unnamed thread 0x7fd9149055e0]: I/IMAP
0x7fd915787000:imap.epopen.com:NA:ProcessCurrentURL: aborting queued urls
2018-11-01 03:30:11.527373 UTC - [31322:Unnamed thread 0x7fd914905280]:
I/IMAP 0x7fd915778000:imap.epopen.com:NA:TellThreadToDie: close socket
connection   2018-11-01 03:30:11.527374 UTC - [31322:Unnamed thread
0x7fd9149055e0]: D/IMAP ImapThreadMainLoop leaving [this=0x7fd915787000]
2018-11-01 03:30:11.527393 UTC - [31322:Unnamed thread 0x7fd914905280]:
I/IMAP 0x7fd915778000:imap.epopen.com:NA:CreateNewLineFromSocket: (null)
2018-11-01 03:30:11.527405 UTC - [31322:Unnamed thread 0x7fd914905280]:
D/IMAP try to log in   2018-11-01 03:30:11.527406 UTC - [31322:Unnamed
thread 0x7fd914905280]: D/IMAP IMAP auth: server caps 0x44c2321, pref
0x1006, failed 0x0, avail caps 0x0   2018-11-01 03:30:11.527408 UTC -
[31322:Unnamed thread 0x7fd914905280]: D/IMAP (GSSAPI = 0x1000000, CRAM =
0x20000, NTLM = 0x100000, MSN = 0x200000, PLAIN = 0x1000, LOGIN = 0x2,
old-style IMAP login = 0x4, auth external IMAP login = 0x20000000, OAUTH2 =
0x800000000)   2018-11-01 03:30:11.527408 UTC - [31322:Unnamed thread
0x7fd914905280]: D/IMAP no remaining auth method   2018-11-01
03:30:11.558448 UTC - [31322:Unnamed thread 0x7fd914905280]: E/IMAP login
failed entirely   2018-11-01 03:30:11.560863 UTC - [31322:Unnamed thread
0x7fd914905280]: I/IMAP
0x7fd915778000:imap.epopen.com:NA:ProcessCurrentURL: aborting queued urls
2018-11-01 03:30:11.560903 UTC - [31322:Unnamed thread 0x7fd914905280]:
D/IMAP ImapThreadMainLoop leaving [this=0x7fd915778000]*

2. In Thunderbird windows, Press Ctrl+Shift+ J to open browser console and
error message as below.
   An error occurred during a connection to imap.epopen.com:143.
   SSL received a record that exceeded the maximum permissible length.
   Error code: <a id="errorCode"
title="SSL_ERROR_RX_RECORD_TOO_LONG">SSL_ERROR_RX_RECORD_TOO_LONG</a>

*Debug: Server side:*
*1.courier-authlib: *Add "DEBUG_LOGIN=2" into "authdaemonrc" and got result
from "/var/log/debug" as below.
   Nov  1 11:19:21 mail imapd: Connection, ip=[::ffff:60.251.70.131]
   Nov  1 11:19:22 mail imapd: Disconnected, ip=[::ffff:60.251.70.131],
time=1
2./var/log/maillog haven't any message generated when login.

Rollback courier-imap to latest series 4 version: 4.18.2, other courier
relation package "KEEP" latest version as below.
courier-authlib-base: 0.69.0
courier-authlib-mysql: 0.69.0
courier-unicode: 2.1
Thunderbird work file!

Configure file for reference (Courier-imap 4.18.2 and 5.0 SAME).
/usr/local/etc/authlib/authdaemonrc:
   authmodulelist="authmysql"
   daemons=1
   authdaemonvar=/var/run/authdaemond
   subsystem=mail
   DEBUG_LOGIN=2
   DEFAULTOPTIONS="wbnodsn=1"
   LOGGEROPTS=""
/usr/local/etc/courier-imap/imapd  (Compare with v5.0's updated imapd.dist
and don't modify)
   daemons=1
   authdaemonvar=/var/run/authdaemond
   subsystem=mail
   DEBUG_LOGIN=2
   DEFAULTOPTIONS="wbnodsn=1"
   ADDRESS=0
   PORT=143
   MAXDAEMONS=24
   MAXPERIP=20
   PIDFILE=/var/run/imapd.pid
   TCPDOPTS="-nodnslookup -noidentlookup"
   IMAPACCESSFILE=/usr/local/etc/courier-imap/imapaccess
   LOGGEROPTS="-name=imapd"
   IMAP_CAPABILITY="IMAP4rev1 UIDPLUS CHILDREN NAMESPACE
THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT QUOTA IDLE"
   IMAP_KEYWORDS=1
   IMAP_ACL=1
   IMAP_CAPABILITY_ORIG="IMAP4rev1 UIDPLUS CHILDREN NAMESPACE
THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT QUOTA AUTH=CRAM-MD5
AUTH=CRAM-SHA1 AUTH=CRAM-SHA256 IDLE"
   IMAP_PROXY=0
   IMAP_PROXY_FOREIGN=0
   IMAP_IDLE_TIMEOUT=120
   IMAP_MAILBOX_SANITY_CHECK=1
   IMAP_CAPABILITY_TLS="$IMAP_CAPABILITY AUTH=PLAIN"
   IMAP_CAPABILITY_TLS_ORIG="$IMAP_CAPABILITY_ORIG AUTH=PLAIN"
   IMAP_DISABLETHREADSORT=0
   IMAP_CHECK_ALL_FOLDERS=0
   IMAP_OBSOLETE_CLIENT=0
   IMAP_UMASK=022
   IMAP_ULIMITD=65536
   IMAP_USELOCKS=1
   IMAP_SHAREDINDEXFILE=/usr/local/etc/courier-imap/shared/index
   IMAP_ENHANCEDIDLE=1
   IMAP_TRASHFOLDERNAME=Trash
   IMAP_EMPTYTRASH=Trash:7
   IMAP_MOVE_EXPUNGE_TO_TRASH=0
   SENDMAIL=/usr/sbin/sendmail
   HEADERFROM=X-IMAP-Sender
   IMAPDSTART=NO
   MAILDIRPATH=.Maildir

Can help me debug?
Thanks a lot.

-- 
Regards,
Wei-Jen Chang

[Courier-imap] Problem about "not support the selected authentication method" after version upgrade

[Courier-imap] Problem about "not support the selected authentication method" after version upgrade from 4.18.2 to 5.0.