1 Topic by loudking

  • loudking
  • Member
  • Offline
  • Registered: 2015-04-22
  • Posts: 41

Topic: login failed

==== Required information ====
- iRedMail version (check /etc/iredmail-release): 0.9.1
- Linux/BSD distribution name and version: CentOS 6.6
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): MySQL
- Web server (Apache or Nginx): Apache
- Manage mail accounts with iRedAdmin-Pro?
- Related log if you're reporting an issue:
====
Hello, I cannot login to my mail server any more. Below is log from dovecot.log. Please help. Thanks.

Jul 01 06:54:33 imap: Error: Authentication server didn't send valid SPID as expected: MECH     PLAIN   plaintext
Jul 01 06:54:33 imap: Error: Disconnected from auth server, aborting (client-pid=19977 client-id=1)
Jul 01 06:54:33 auth: Error: BUG: Authentication client sent unknown handshake command: REQUEST?2052456449?19977?1?78ab6ae4d376d5a54f5e857f4b804027
Jul 01 06:54:33 imap-login: Info: Internal login failure (pid=19977 id=1) (internal failure, 1 succesful auths): user=<hongliang.wang@knowsg.com>, method=PLAIN, rip=220.255.242.60, lip=203.175.171.53, mpid=19979, TLS, session=<zNy6FsQZpgDc//I8>
Jul 01 06:54:33 imap-login: Info: Disconnected (auth failed, 1 attempts in 17 secs): user=<hongliang.wang@knowsg.com>, method=PLAIN, rip=220.255.242.60, lip=203.175.171.53, TLS: Disconnected, session=<BYv5FcQZHADc//I8>

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

2 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,770

Re: login failed

loudking wrote:

Jul 01 06:54:33 auth: Error: BUG: Authentication client sent unknown handshake command: REQUEST?2052456449?19977?1?78ab6ae4d376d5a54f5e857f4b804027

What's your mail client application? Dovecot says it sent an known handshake command (REQUEST).

3 Reply by loudking

  • loudking
  • Member
  • Offline
  • Registered: 2015-04-22
  • Posts: 41

Re: login failed

Both iPhone app and webmail of roundcube

ZhangHuangbin wrote:
loudking wrote:

Jul 01 06:54:33 auth: Error: BUG: Authentication client sent unknown handshake command: REQUEST?2052456449?19977?1?78ab6ae4d376d5a54f5e857f4b804027

What's your mail client application? Dovecot says it sent an known handshake command (REQUEST).

4 Reply by loudking

  • loudking
  • Member
  • Offline
  • Registered: 2015-04-22
  • Posts: 41

Re: login failed

No user is able to login. See /var/log/maillog:
Jul  1 15:01:11 knowsg roundcube: <j2qa50ht> IMAP Error: Login failed for anthony.tan@knowsg.com from 180.255.242.4. LOGIN: Internal error occurred. Refer to server log for more information. in /var/www/roundcubemail-1.1.1/program/lib/Roundcube/rcube_imap.php on line 198 (POST /mail/?_task=login?_task=login&_action=login)
Jul  1 15:17:27 knowsg postfix/qmgr[869]: 49FA96921EA6: from=<internal@KnowSG.com>, size=2703, nrcpt=1 (queue active)
Jul  1 15:17:27 knowsg postfix/pipe[20940]: 49FA96921EA6: to=<hongliang.wang@knowsg.com>, relay=dovecot, delay=13095, delays=13095/0.02/0/0.03, dsn=4.3.0, status=deferred (temporary failure)
Jul  1 15:25:55 knowsg postfix/smtpd[20947]: connect from b3.webhostsg.com[210.193.32.185]
Jul  1 15:25:57 knowsg cbpolicyd[9454]: module=Greylisting, action=pass, host=210.193.32.185, helo=b3.webhostsg.com, from=noreply@econnectous.com, to=hongliang.wang@knowsg.com, reason=authenticated
Jul  1 15:25:57 knowsg postfix/smtpd[20947]: NOQUEUE: reject: RCPT from b3.webhostsg.com[210.193.32.185]: 450 4.1.8 <noreply@econnectous.com>: Sender address rejected: Domain not found; from=<noreply@econnectous.com> to=<hongliang.wang@knowsg.com> proto=ESMTP helo=<b3.webhostsg.com>
Jul  1 15:25:57 knowsg postfix/smtpd[20947]: disconnect from b3.webhostsg.com[210.193.32.185]


ZhangHuangbin wrote:
loudking wrote:

Jul 01 06:54:33 auth: Error: BUG: Authentication client sent unknown handshake command: REQUEST?2052456449?19977?1?78ab6ae4d376d5a54f5e857f4b804027

What's your mail client application? Dovecot says it sent an known handshake command (REQUEST).

5 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,770

Re: login failed

Any related error message in /var/log/dovecot*?
Please turn on debug mode in Dovecot and try again, paste related debug message in /var/log/dovecot* here so that others can help troubleshoot.

Reference: http://www.iredmail.org/docs/debug.dovecot.html

6 Reply by loudking

  • loudking
  • Member
  • Offline
  • Registered: 2015-04-22
  • Posts: 41

Re: login failed

I turned on debug mode and restart dovecot then strangely log in succeed.
Then I turned off debug mode again and problem disappeared.
I am curious to know what the problem really is. How to figure it out please?

ZhangHuangbin wrote:

Any related error message in /var/log/dovecot*?
Please turn on debug mode in Dovecot and try again, paste related debug message in /var/log/dovecot* here so that others can help troubleshoot.

Reference: http://www.iredmail.org/docs/debug.dovecot.html

7 Reply by loudking

  • loudking
  • Member
  • Offline
  • Registered: 2015-04-22
  • Posts: 41

Re: login failed

/var/log/dovecot.log before debug mode:
Jul 01 18:57:29 auth: Error: BUG: Authentication client sent unknown handshake command: USER?1?internal@knowsg.com?service=lda
Jul 01 19:06:21 imap-login: Info: Disconnected (no auth attempts in 1 secs): user=<>, rip=141.212.122.90, lip=203.175.171.53, TLS: Disconnected, session=<rkQfUM4ZXwCN1Hpa>
Jul 01 20:07:29 auth: Error: BUG: Authentication client sent unknown handshake command: USER?1?internal@knowsg.com?service=lda
Jul 01 20:34:29 auth-worker(21505): Info: mysql(127.0.0.1): Connected to database vmail
Jul 01 20:34:29 auth: Error: BUG: Authentication client sent unknown handshake command: REQUEST?3926261761?21503?1?0567bbcd189d6d6bea6458346680aa53
Jul 01 20:34:29 imap: Error: Authentication server didn't send valid SPID as expected: MECH     PLAIN   plaintext
Jul 01 20:34:29 imap: Error: Disconnected from auth server, aborting (client-pid=21503 client-id=1)
Jul 01 20:34:29 imap-login: Info: Internal login failure (pid=21503 id=1) (internal failure, 1 succesful auths): user=<leland.wee@knowsg.com>, method=PLAIN, rip=222.164.198.3, lip=203.175.171.53, mpid=21506, TLS, session=<0qBKi88ZQADepMYD>
Jul 01 20:34:29 auth: Error: BUG: Authentication client sent unknown handshake command: REQUEST?2685272065?21507?1?f4bff1b3b5fdf9246b4aaec1c1d44ff3
Jul 01 20:34:29 imap: Error: Authentication server didn't send valid SPID as expected: MECH     PLAIN   plaintext
Jul 01 20:34:29 imap: Error: Disconnected from auth server, aborting (client-pid=21507 client-id=1)
Jul 01 20:34:29 imap-login: Info: Internal login failure (pid=21507 id=1) (internal failure, 1 succesful auths): user=<leland.wee@knowsg.com>, method=PLAIN, rip=222.164.198.3, lip=203.175.171.53, mpid=21508, TLS, session=<aLZQi88ZRADepMYD>
Jul 01 20:34:54 auth: Error: BUG: Authentication client sent unknown handshake command: REQUEST?3372220417?21509?1?4a1e9a38835f74784eb77cfb9925f889
Jul 01 20:34:54 imap: Error: Authentication server didn't send valid SPID as expected: MECH     PLAIN   plaintext
Jul 01 20:34:54 imap: Error: Disconnected from auth server, aborting (client-pid=21509 client-id=1)
Jul 01 20:34:54 imap-login: Info: Internal login failure (pid=21509 id=1) (internal failure, 1 succesful auths): user=<leland.wee@knowsg.com>, method=PLAIN, rip=222.164.198.3, lip=203.175.171.53, mpid=21510, TLS, session=<LwfPjM8ZVgDepMYD>


ZhangHuangbin wrote:

Any related error message in /var/log/dovecot*?
Please turn on debug mode in Dovecot and try again, paste related debug message in /var/log/dovecot* here so that others can help troubleshoot.

Reference: http://www.iredmail.org/docs/debug.dovecot.html

8 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,770

Re: login failed

loudking wrote:

Jul 01 20:34:54 auth: Error: BUG: Authentication client sent unknown handshake command: REQUEST?3372220417?21509?1?4a1e9a38835f74784eb77cfb9925f889

It looks like a MUA issue, not server.

Which iPhone app do you use to send email? The builtin Mail.app?

9 Reply by loudking

  • loudking
  • Member
  • Offline
  • Registered: 2015-04-22
  • Posts: 41

Re: login failed

Yes the builtin app. But web interface failed as well ...


ZhangHuangbin wrote:
loudking wrote:

Jul 01 20:34:54 auth: Error: BUG: Authentication client sent unknown handshake command: REQUEST?3372220417?21509?1?4a1e9a38835f74784eb77cfb9925f889

It looks like a MUA issue, not server.

Which iPhone app do you use to send email? The builtin Mail.app?

10 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 30,770

Re: login failed

Please try steps below, let's get log with roundcube and iPhone Mail.app:

1) Run command 'tail -f /var/log/maillog', then login to webmail and send one testing email to reproduce this issue. Copy full terminal output and paste here.

2) Exit 'tail' command first, then run 'tail -f /var/log/maillog' again. Now open iPhone Mail.app to send email to reproduce this issue. Copy full terminal output and paste here.

3) Extract log in /var/log/dovecot* related to these 2 testing email, paste here.

4) Run command 'dovecot -n' and paste full terminal output here.

5) Copy full content of file /etc/dovecot/dovecot-mysql.conf and paste here. WARNING: please remove password in this file before pasting.

11 Reply by slavia6

  • slavia6
  • Member
  • Offline
  • Registered: 2016-12-11
  • Posts: 5

Re: login failed

Thanks a lot for your help Zhang,
at the end the issue was with my postfix certificate definitions as I have mixed up CA and cert entries.
I am surprised why the old way could have been working though.

Anyway now all works just fine and I am not going to touch it unless I am forced to.

Thanks again

Slavia6