Unable to authenticate on Dovecot - auth-userdb issue?
Some general information:
Mageia Linux 5.4.6-desktop-2.mga7
2.3.7.2 (3c910f64b)
postfix + dovecot + mysql
192.168.1.105 (shuttle) the email server machine 192.168.1.103 (pvr) the mail client machine
I am unable to authenticate to send email. I've looked at postfix but I can't get past dovecot's authentication. Here is what I'm seeing in logs:
Jan 02 18:46:47 shuttle sshd[6660]: Connection closed by 192.168.1.100 port 48506 [preauth] Jan 02 18:47:05 shuttle postfix/smtpd[6352]: connect from pvr[192.168.1.103] Jan 02 18:47:16 shuttle postfix/smtpd[6352]: lost connection after CONNECT from pvr[192.168.1.103] Jan 02 18:47:16 shuttle postfix/smtpd[6352]: disconnect from pvr[192.168.1.103] commands=0/0 Jan 02 18:47:36 shuttle postfix/smtpd[6352]: connect from pvr[192.168.1.103] Jan 02 18:47:36 shuttle postfix/smtpd[6352]: 6345D4A4A97: client=pvr[192.168.1.103] Jan 02 18:47:37 shuttle postfix/cleanup[6500]: 6345D4A4A97: message-id=<> Jan 02 18:47:37 shuttle postfix/qmgr[1385]: 6345D4A4A97: from=madams@pvr, size=485, nrcpt=1 (queue active) Jan 02 18:47:37 shuttle postfix/smtpd[6352]: disconnect from pvr[192.168.1.103] helo=1 mail=1 rcpt=1 data=1 quit=1 commands=5 Jan 02 18:47:37 shuttle dovecot[6744]: lda(root@shuttle)<6744><>: Error: auth-master: userdb lookup(root@shuttle): connect(/run/dovecot/auth-userdb) failed: Permission denied (euid=8(mail) egid=12(mail) missing +r perm: /run/dovecot/auth-userdb, dir owned by 0:0 mode=0755) Jan 02 18:47:37 shuttle dovecot[6744]: lda: Fatal: Internal error occurred. Refer to server log for more information. Jan 02 18:47:37 shuttle postfix/pipe[6743]: 6345D4A4A97: to=root@shuttle, relay=dovecot, delay=1.1, delays=1.1/0.01/0/0.06, dsn=4.3.0, status=deferred (temporary failure. Command output: lda(root@shuttle): Error: net_connect_unix(/run/dovecot/stats-writer) failed: Permission denied ) ^C
Note: this error references "/run/dovecot/auth-userdb". That isn't even supposed to be the location of that file. I have no idea why that location shows up. The correct location should be "/etc/dovecot/auth-userdb". The file does exist at that location.
There is no "base_dir" configured in /etc/dovecot/dovecot.conf. When I do try an point the configuration at the correct base_dir, I get this when I try to restart dovecot:
-- The unit dovecot.service has entered the 'failed' state with result 'exit-code'. Jan 02 18:51:50 shuttle dovecot[7226]: master: Error: service(aggregator): unlink(/etc/dovecot/replication-notify-fifo) failed: Read-only file system Jan 02 18:51:50 shuttle dovecot[7226]: master: Error: service(pop3): unlink(/etc/dovecot/login/pop3) failed: Read-only file system Jan 02 18:51:50 shuttle dovecot[7226]: master: Error: service(old-stats): unlink(/etc/dovecot/old-stats) failed: Read-only file system Jan 02 18:51:50 shuttle dovecot[7226]: master: Error: service(old-stats): unlink(/etc/dovecot/old-stats-mail) failed: Read-only file system Jan 02 18:51:50 shuttle dovecot[7226]: master: Error: service(old-stats): unlink(/etc/dovecot/old-stats-user) failed: Read-only file system Jan 02 18:51:50 shuttle dovecot[7226]: master: Error: service(log): unlink(/etc/dovecot/log-errors) failed: Read-only file system Jan 02 18:51:50 shuttle dovecot[7226]: master: Error: service(lmtp): unlink(/etc/dovecot/lmtp) failed: Read-only file system Jan 02 18:51:50 shuttle dovecot[7226]: master: Error: service(ipc): unlink(/etc/dovecot/ipc) failed: Read-only file system Jan 02 18:51:50 shuttle dovecot[7226]: master: Error: service(ipc): unlink(/etc/dovecot/login/ipc-proxy) failed: Read-only file system Jan 02 18:51:50 shuttle dovecot[7226]: master: Error: service(indexer-worker): unlink(/etc/dovecot/indexer-worker) failed: Read-only file system
And there are about 30 lines of "read-only file system" errors. I haven't been able to track down the cause of that.
Once the line "base_dir = /etc/dovecot" is commented out in /etc/dovecot/dovecot.conf, I can start dovecot:
# systemctl status dovecot ● dovecot.service - Dovecot IMAP/POP3 email server Loaded: loaded (/usr/lib/systemd/system/dovecot.service; enabled; vendor preset: disabled) Active: active (running) since Thu 2020-01-02 18:54:15 MST; 5s ago Docs: man:dovecot(1) http://wiki2.dovecot.org/ Main PID: 7550 (dovecot) Memory: 3.8M CGroup: /system.slice/dovecot.service ├─7550 /usr/sbin/dovecot -F ├─7554 dovecot/anvil ├─7555 dovecot/log └─7556 dovecot/config
Jan 02 18:54:15 shuttle systemd[1]: Started Dovecot IMAP/POP3 email server. Jan 02 18:54:15 shuttle dovecot[7550]: master: Dovecot v2.3.7.2 (3c910f64b) starting up for imap, pop3, lmtp Jan 02 18:54:15 shuttle dovecot[7550]: master: Error: t_readlink(/etc/dovecot/dovecot.conf) failed: readlink() failed: Invalid argument
I have no idea what's up with the t_readlink error. Might be related to the errors above. I can't really find out much about it.
Trying to send email shows no apparent errors:
[madams@pvr ~]$ mail root@shuttle Subject: testing
test
. EOT [madams@pvr ~]$
Trying to send mail in detail looks like this:
$ openssl s_client -connect shuttle:25 -starttls smtp CONNECTED(00000003) depth=0 C = US, ST = NM, O = Personal, OU = Private verify error:num=18:self signed certificate verify return:1 depth=0 C = US, ST = NM, O = Personal, OU = Private verify return:1
Certificate chain 0 s:/C=US/ST=NM/O=Personal/OU=Private i:/C=US/ST=NM/O=Personal/OU=Private
Server certificate
<It produces all the right certificate information>
-----END CERTIFICATE----- subject=/C=US/ST=NM/O=Personal/OU=Private issuer=/C=US/ST=NM/O=Personal/OU=Private
No client certificate CA names sent Peer signing digest: SHA512 Server Temp Key: ECDH, P-256, 256 bits
SSL handshake has read 1764 bytes and written 467 bytes
New, TLSv1/SSLv3, Cipher is ECDHE-RSA-AES256-GCM-SHA384 Server public key is 2048 bit Secure Renegotiation IS supported Compression: NONE Expansion: NONE No ALPN negotiated SSL-Session:
<and all the SSL information is good>
Start Time: 1578016729
Timeout : 300 (sec)
Verify return code: 18 (self signed certificate)
250 CHUNKING ehlo shuttle 250-shuttle 250-PIPELINING 250-SIZE 10240000 250-VRFY 250-ETRN 250-AUTH PLAIN 250-ENHANCEDSTATUSCODES 250-8BITMIME 250-DSN 250-SMTPUTF8 250 CHUNKING mail from: madams@pvr 250 2.1.0 Ok rcpt to: root@shuttle 250 2.1.5 Ok data 354 End data with <CR><LF>.<CR><LF> subject: testing
test
. 250 2.0.0 Ok: queued as A73A84A4AE4 quit 221 2.0.0 Bye closed
That transaction produces this in journalctl:
an 02 19:04:15 shuttle postfix/smtpd[8856]: connect from pvr[192.168.1.103] Jan 02 19:04:15 shuttle dovecot[7555]: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/modules/auth Jan 02 19:04:15 shuttle dovecot[7555]: auth: Debug: Module loaded: /usr/lib64/dovecot/modules/auth/lib20_auth_var_expand_crypt.so Jan 02 19:04:15 shuttle dovecot[7555]: auth: Debug: Read auth token secret from /run/dovecot/auth-token-secret.dat Jan 02 19:04:15 shuttle dovecot[7555]: auth: Debug: auth client connected (pid=0) Jan 02 19:04:31 shuttle postfix/smtpd[8856]: B621F4A4B0F: client=pvr[192.168.1.103] Jan 02 19:04:39 shuttle postfix/cleanup[8914]: B621F4A4B0F: message-id=<> Jan 02 19:04:40 shuttle postfix/qmgr[1385]: B621F4A4B0F: from=madams@pvr, size=184, nrcpt=1 (queue active) Jan 02 19:04:40 shuttle dovecot[8947]: lda(root@shuttle)<8947><>: Error: auth-master: userdb lookup(root@shuttle): connect(/run/dovecot/auth-userdb) failed: Permission denied (euid=8(mail) egid=12(mail) missing +r perm: /run/dovecot/auth-userdb, dir owned by 0:0 mode=0755) Jan 02 19:04:40 shuttle dovecot[8947]: lda: Fatal: Internal error occurred. Refer to server log for more information. Jan 02 19:04:40 shuttle postfix/pipe[8946]: B621F4A4B0F: to=root@shuttle, relay=dovecot, delay=13, delays=13/0.01/0/0.06, dsn=4.3.0, status=deferred (temporary failure. Command output: lda(root@shuttle): Error: net_connect_unix(/run/dovecot/stats-writer) failed: Permission denied ) Jan 02 19:04:43 shuttle postfix/smtpd[8856]: disconnect from pvr[192.168.1.103] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7 Jan 02 19:04:48 shuttle sshd[8962]: Connection closed by 192.168.1.100 port 48596 [preauth]
I've experimented with ownership and permissions on run/dovecot/auth-userdb. It's running as vmail:dovecot, but the permissions I set on it are not persistent - they keep reverting to srw----- whenever I restart dovecot. This is correct given the configuration in dovecot.conf, but should those permissions be set to 0600? Also, that shouldn't be happening in /run/dovcot, it should all be happening in /etc/dovcot.
Attempting to test authentication over TLS isn't working and I'm so confused at this point I'm not even sure I should be doing it.
250 CHUNKING ehlo shuttle 250-shuttle 250-PIPELINING 250-SIZE 10240000 250-VRFY 250-ETRN 250-AUTH PLAIN 250-ENHANCEDSTATUSCODES 250-8BITMIME 250-DSN 250-SMTPUTF8 250 CHUNKING auth login 535 5.7.8 Error: authentication failed: Invalid authentication mechanism auth login bWFkYW1z bm9uZQ== 501 5.5.4 Syntax: AUTH mechanism auth plain bWFkYW1z bm9uZQ== 501 5.5.4 Syntax: AUTH mechanism
And those are base64 encoded credentials (bWFkYW1z bm9uZQ==).
Here is my config. All I want to do is run from machines on my lan to Thunderbird on my desktop so I can get notices about events and system health from my other servers. Should this be so hard? Is this Postfix's fault? Can anybody help with this?
Thanks.
And now that config:
# dovecot -n # 2.3.7.2 (3c910f64b): /etc/dovecot/dovecot.conf # OS: Linux 5.4.6-desktop-2.mga7 x86_64 Mageia 7 # Hostname: shuttle auth_debug_passwords = yes auth_username_format = %Ln disable_plaintext_auth = no first_valid_uid = 0 last_valid_uid = 10001 mail_gid = 10001 mail_location = mbox:~/mail:INBOX=/var/mail/%u mail_privileged_group = mail mail_uid = 10001 namespace inbox { inbox = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = } passdb { args = %s driver = pam } plugin { sieve = file:~/sieve;active=~/.dovecot.sieve } service auth-worker { user = vmail } service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0666 user = postfix } unix_listener auth-userdb { group = dovecot mode = 0600 user = vmail } user = dovecot } service imap-login { inet_listener imap { port = 143 } } service lmtp { unix_listener /var/spool/postfix/private/dovecot-lmtp { group = postfix mode = 0600 user = postfix } } service pop3-login { inet_listener pop3s { port = 995 ssl = yes } } ssl = required ssl_cert =
Am 03.01.2020 um 03:27 schrieb Mark ADAMS:
Jan 02 18:47:37 shuttle dovecot[6744]: lda(root@shuttle)<6744><>: Error: auth-master: userdb lookup(root@shuttle): connect(/run/dovecot/auth-userdb) failed: Permission denied (euid=8(mail) egid=12(mail) missing +r perm: /run/dovecot/auth-userdb, dir owned by 0:0 mode=0755)
Run "namei -lv /run/dovecot/auth-userdb" to check the permissions of the
complete path. The auth-userdb socket actually is owned mail:mail
according to your error logging. Is dovecot member of the mail group?
Actually it does not match the config details you have pasted:
unix_listener auth-userdb { group = dovecot mode = 0600 user = vmail }
On my side it looks like this and I have not custom configured that
part. The defaults are:
unix_listener auth-userdb { group = mode = 0666 user = $default_internal_user }
So on my system the permissions look like this:
# namei -lv /var/run/dovecot/auth-userdb f: /var/run/dovecot/auth-userdb dr-xr-xr-x root root / drwxr-xr-x root root var drwxr-xr-x root root run drwxr-xr-x root dovecot dovecot srw-rw-rw- dovecot root auth-userdb
Jan 02 18:47:37 shuttle dovecot[6744]: lda: Fatal: Internal error occurred. Refer to server log for more information. Jan 02 18:47:37 shuttle postfix/pipe[6743]: 6345D4A4A97: to=root@shuttle, relay=dovecot, delay=1.1, delays=1.1/0.01/0/0.06, dsn=4.3.0, status=deferred (temporary failure. Command output: lda(root@shuttle): Error: net_connect_unix(/run/dovecot/stats-writer) failed: Permission denied ) ^C
Note: this error references "/run/dovecot/auth-userdb". That isn't even supposed to be the location of that file. I have no idea why that location shows up. The correct location should be "/etc/dovecot/auth-userdb". The file does exist at that location.
Mark,
I have no idea why you expect the dovecot sockets to be located inside
/etc/dovecot/. /etc is the FHS location for configurations. /run or
/var/run (typically a symlink on modern linux distributions) is the
right location for runtime files like service sockets.
You say /etc/dovecot/auth-userdb exists. Am I correct to guess that you
have created that manually with whatever content?
Alexander
participants (2)
-
Alexander Dalloz
-
Mark ADAMS