Page 1 of 1

Postfix/Mysql - [SYS/TEMP] Temporary authentication failure.

Posted: Fri 8. May 2020, 12:10
by benkhouya
After a successful installation of KeyHelp on Ubuntu 18 (64bits), I have the following problem:
I can't authenticate via an email client to retrieve my emails, with Gmail I get the error "[SYS/TEMP] Temporary authentication failure" and at the server level I have the following error : Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 1 seconds before retry

Here is a preview of /var/log/mail.log

Code: Select all

root@vps:~# tail -f /var/log/mail.log
May  8 09:56:52 vps dovecot: auth-worker(17960): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 125 seconds before retry
May  8 09:56:52 vps dovecot: auth-worker(17960): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 125 seconds before retry
May  8 09:57:21 vps dovecot: auth: Error: auth worker: Aborted PASSV request for my@email.address: Lookup timed out
May  8 09:57:21 vps dovecot: auth-worker(17960): Error: mysql: Query timed out (no free connections for 60 secs): SELECT email AS user, password, CONCAT('*:storage=',quota) AS userdb_quota_rule FROM   mail_users WHERE  email='my@email.address' AND login_enabled = 'Y';
May  8 09:57:21 vps dovecot: auth-worker(17960): Error: sql(my@email.address,[IPADDRESS],<BnlnAiClCpnRVdAN>): Password query failed: Not connected to database
May  8 09:57:21 vps dovecot: auth-worker(17960): Warning: Auth master disconnected us while handling request for my@email.address for 60 secs (result=FAIL)
May  8 09:57:21 vps dovecot: auth-worker(19064): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 1 seconds before retry
May  8 09:57:22 vps dovecot: auth-worker(19064): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 5 seconds before retry
May  8 09:57:23 vps dovecot: pop3-login: Disconnected (auth failed, 1 attempts in 62 secs): user=<my@email.address>, method=PLAIN, rip=[IPADDRESS], lip=[IPADDRESS], TLS: Disconnected, session=<BnlnAiClCpnRVdAN>
May  8 09:57:27 vps dovecot: auth-worker(19064): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 25 seconds before retry
May  8 09:57:52 vps dovecot: auth-worker(19064): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 125 seconds before retry
May  8 09:58:20 vps dovecot: auth-worker(19064): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 1 seconds before retry
May  8 09:58:21 vps dovecot: auth-worker(19064): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 5 seconds before retry
May  8 09:58:26 vps dovecot: auth-worker(19064): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 25 seconds before retry
EDIT : Webmail (Roundcube) on KeyHelp also doesn't work to access emails.

Re: Postfix/Mysql - [SYS/TEMP] Temporary authentication failure.

Posted: Fri 8. May 2020, 12:13
by Martin
Hello,

is your mysqld running properly?

Re: Postfix/Mysql - [SYS/TEMP] Temporary authentication failure.

Posted: Fri 8. May 2020, 12:17
by benkhouya
Yes, because my WordPress sites are working properly.

Re: Postfix/Mysql - [SYS/TEMP] Temporary authentication failure.

Posted: Sun 10. May 2020, 02:26
by benkhouya
Isn't there a script or command from KeyHelp, to check and fix Postfix/Dovecot integration with MySQL?
That I can fix this error without having to reinstall everything.

Re: Postfix/Mysql - [SYS/TEMP] Temporary authentication failure.

Posted: Sun 10. May 2020, 03:26
by george
Did you try the obvious, restart mysql and/or reboot server?

Also check /var/log/mysql/error.log for clues.

Re: Postfix/Mysql - [SYS/TEMP] Temporary authentication failure.

Posted: Sun 10. May 2020, 15:29
by benkhouya
I restarted MySQL and Dovecot and Postfix, and also the VPS, without success it doesn't fix my problem.

Below the content of /var/log/mysql/error.log

Code: Select all

root@vps:~# cat /var/log/mysql/error.log
2020-05-10 13:19:40 139786339948288 [Note] /usr/sbin/mysqld: Normal shutdown
2020-05-10 13:19:40 139786339948288 [Note] Event Scheduler: Purging the queue. 0 events
2020-05-10 13:19:41 139785641367296 [Note] InnoDB: FTS optimize thread exiting.
2020-05-10 13:19:41 139786339948288 [Note] InnoDB: Starting shutdown...
2020-05-10 13:19:41 139786339948288 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2020-05-10 13:19:44 139786339948288 [Note] InnoDB: Shutdown completed; log sequence number 11254557
2020-05-10 13:19:44 139786339948288 [Note] /usr/sbin/mysqld: Shutdown complete

2020-05-10 13:20:04 140412671216768 [Note] InnoDB: innodb_empty_free_list_algorithm has been changed to legacy because of small buffer pool size. In order to use backoff, increase buffer pool at least up to 20MB.

2020-05-10 13:20:04 140412671216768 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2020-05-10 13:20:04 140412671216768 [Note] InnoDB: The InnoDB memory heap is disabled
2020-05-10 13:20:04 140412671216768 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2020-05-10 13:20:04 140412671216768 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2020-05-10 13:20:04 140412671216768 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-05-10 13:20:04 140412671216768 [Note] InnoDB: Using Linux native AIO
2020-05-10 13:20:04 140412671216768 [Note] InnoDB: Using SSE crc32 instructions
2020-05-10 13:20:04 140412671216768 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2020-05-10 13:20:04 140412671216768 [Note] InnoDB: Completed initialization of buffer pool
2020-05-10 13:20:04 140412671216768 [Note] InnoDB: Highest supported file format is Barracuda.
2020-05-10 13:20:05 140412671216768 [Note] InnoDB: 128 rollback segment(s) are active.
2020-05-10 13:20:05 140412671216768 [Note] InnoDB: Waiting for purge to start
2020-05-10 13:20:05 140412671216768 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.46-86.2 started; log sequence number 11254557
2020-05-10 13:20:06 140412671216768 [Note] Plugin 'FEEDBACK' is disabled.
2020-05-10 13:20:06 140411880302336 [Note] InnoDB: Dumping buffer pool(s) not yet started
2020-05-10 13:20:07 140412671216768 [Note] Server socket created on IP: '127.0.0.1'.
2020-05-10 13:20:07 140412671216768 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.1.44-MariaDB-0ubuntu0.18.04.1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Ubuntu 18.04

Re: Postfix/Mysql - [SYS/TEMP] Temporary authentication failure.

Posted: Wed 13. May 2020, 04:13
by benkhouya
Will the next KeyHelp update 20.1 fix my error?
Or do I have to reinstall the whole thing from scratch?

This is obviously one of the errors below:
- Dovecot not being able to connect to MySQL
- Dovecot's MySQL privileges are incorrect
- The problem lies in the creation of a mail account on the server, via the KeyHelp interface.

Code: Select all

root@vps:~# tail -f /var/log/mail.log
May 13 02:00:17 vps dovecot: lmtp(31011): Connect from local
May 13 02:00:17 vps dovecot: lmtp(31013): Connect from local
May 13 02:00:17 vps dovecot: auth-worker(31014): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 1 seconds before retry
May 13 02:00:17 vps dovecot: auth-worker(31014): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 1 seconds before retry
May 13 02:00:17 vps dovecot: auth-worker(31015): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 1 seconds before retry
May 13 02:00:17 vps dovecot: auth: Error: auth worker: Aborted USER request for my@email.address: Internal auth worker failure
May 13 02:00:17 vps dovecot: lmtp(my@email.address): Error: user my@email.address: Auth USER lookup failed
May 13 02:00:17 vps dovecot: auth-worker(31015): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 1 seconds before retry
May 13 02:00:17 vps dovecot: auth-worker(31015): Error: sql(my@email.address): User query failed: Not connected to database
May 13 02:00:17 vps dovecot: auth-worker(31016): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 1 seconds before retry
May 13 02:00:17 vps dovecot: auth: Error: auth worker: Aborted USER request for root@myhostname: Internal auth worker failure
May 13 02:00:17 vps dovecot: lda(root@myhostname): Error: user root@myhostname: Auth USER lookup failed
May 13 02:00:17 vps dovecot: lda: Fatal: Internal error occurred. Refer to server log for more information.
May 13 02:00:17 vps postfix/lmtp[31009]: 2DB4E61EC9: to=<my@email.address>, relay=myhostname[private/dovecot-lmtp], delay=431534, delays=431534/0.02/0.03/0.04, dsn=4.3.0, status=deferred (host myhostname[private/dovecot-lmtp] said: 451 4.3.0 <my@email.address> Internal error occurred. Refer to server log for more information. (in reply to RCPT TO command))
May 13 02:00:17 vps dovecot: lmtp(31013): Disconnect from local: Successful quit
May 13 02:00:17 vps dovecot: auth-worker(31016): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 1 seconds before retry
May 13 02:00:17 vps dovecot: auth-worker(31016): Error: sql(root@myhostname): User query failed: Not connected to database
May 13 02:00:17 vps postfix/pipe[31010]: 91FE361E93: to=<root@myhostname>, relay=dovecot, delay=2400, delays=2400/0.01/0/0.09, dsn=4.3.0, status=deferred (temporary failure)
May 13 02:00:18 vps dovecot: auth-worker(31014): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 5 seconds before retry
May 13 02:00:18 vps dovecot: auth-worker(31014): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 5 seconds before retry
May 13 02:00:23 vps dovecot: auth-worker(31014): Error: mysql(localhost): Connect failed to database (keyhelp): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (13) - waiting for 25 seconds before retry
Please help!

Re: Postfix/Mysql - [SYS/TEMP] Temporary authentication failure.

Posted: Wed 13. May 2020, 04:43
by OlliTheDarkness
What does the MySQL log say at the time of the mail error?
What performance data does the server have?

Re: Postfix/Mysql - [SYS/TEMP] Temporary authentication failure.

Posted: Wed 20. May 2020, 01:10
by benkhouya
There are no errors in the MySQL log, either when adding a new email address, or during authentication.

Code: Select all

root@vps:~# tail -f /var/log/mysql/error.log
And as for performance, it's a VPS KVM with Ubuntu 18.04 (64bits), 1Gb RAM and 20Gb SSD disk space.

PS. The 20.1 update didn't solve my problem, unfortunately.

Re: Postfix/Mysql - [SYS/TEMP] Temporary authentication failure.  [SOLVED]

Posted: Mon 25. May 2020, 09:30
by Alexander
I have checked the problem on benkhouya's server.

Although I initially failed to get the connection working via the socket connector (and stopped the attempt after the fix below), I was able to resolve the problem by modifying the following file:

Code: Select all

/etc/dovecot/dovecot-sql.conf
In this file you find the following line:

Code: Select all

connect = "host=localhost dbname=keyhelp user=keyhelp password=<PASSWORD>"
I changed this to:

Code: Select all

connect = "host=127.0.0.1 dbname=keyhelp user=keyhelp password=<PASSWORD>"

Reason why this worked: When using "localhost, the socket connector is used, when using 127.0.0.1 the TCP/IP connector is used.

Re: Postfix/Mysql - [SYS/TEMP] Temporary authentication failure.

Posted: Mon 25. May 2020, 16:07
by benkhouya
Thank you very much Alexander, it's working perfectly.

One last question:
Will this modification be integrated in a fix in the next version? Or do I have to do it manually?

Re: Postfix/Mysql - [SYS/TEMP] Temporary authentication failure.

Posted: Mon 25. May 2020, 16:12
by Alexander
This file gets created during KeyHelp installation and then remains untouched.
So you don't have to do anything.