Postfix / Dovecot Not Able to Authenticate
techlists at phpcoderusa.com
techlists at phpcoderusa.com
Tue Jul 6 02:49:33 EEST 2021
Ok, figured out the issue. My passwd-file was not configured correctly.
Now I can send however I cannot receive. I find nothing in the logs.
Any insight into how to troubleshoot is much appreciated.
- - -
On 2021-07-05 13:59, techlists at phpcoderusa.com wrote:
> Hi My name is Keith Smith. I am a PHP developer and have been a
> freelance PHP developer since 2006.
>
> I have been working on a PHP web server in the hope of learning more
> about Linux hosting server administration. Over the years I have had
> the opportunity to create many PHP virtual hosts. I have not worked
> with or configured BIND, Postfix, and Dovecot before about 3 weeks
> ago.
>
> My home server is connected to the Internet via my home office
> business cable account. No blocked ports and I am able run one or
> more servers.
>
> I am running Ubuntu 20.04lts / Apache / MySql (or a clone) / PHP /
> BIND9 / Postfix / Dovecot / Let's Encrypt SSL.
>
> My server’s FQDN is : soho.keiththewebguy.com as is my reverse
> lookup on my IP : 98.191.108.149.
>
> The purpose is for learning. I intend to run one such configured
> server out of my home office running one domain or more (virtual
> hosts) and would like to configure Postfix/Dovecot to service one or
> more email addresses per virtual hosting.
>
> I have BIND working. At least enough that a simple web page can be
> displayed. I've installed Postfix and Dovecot and am getting an
> authentication issue that shows up in the logs.
>
> I do not know all that you might need. Please let me know.
>
> I admit I find Postfix and Dovecot difficult to understand. I am at
> the newbie stage. I've scoured the Internet looking for answers.
>
> After I configured Postfix and Dovecot I issued the commend : telnet
> keiththewebguy.com 25 on my web server. It returned:
>
> Trying 98.191.108.149...
> Connected to keiththewebguy.com.
> Escape character is '^]'.
> 220 soho.keiththewebguy.com ESMTP Postfix
>
> I issued : ehlo soho.keiththewebguy.com
>
> 250-soho.keiththewebguy.com
> 250-PIPELINING
> 250-SIZE 10240000
> 250-VRFY
> 250-ETRN
> 250-STARTTLS
> 250-AUTH PLAIN LOGIN
> 250-ENHANCEDSTATUSCODES
> 250-8BITMIME
> 250-DSN
> 250 CHUNKING
>
> I issued : quit
>
> 221 2.0.0 Bye
> Connection closed by foreign host.
>
> ---
>
> I assume this means things are configured correctly.
>
> I am looking at both logs:
>
> 1) /var/log/mail.err which contains no content.
>
> 2) /var/log/mail.log which is verbose.
>
> To /etc/dovecot/dovecot.conf I added the following for debugging:
>
> auth_verbose = yes
> auth_verbose_passwords = no
> auth_debug = yes
> auth_debug_passwords = yes
> mail_debug = yes
> verbose_ssl = yes
>
> I am trying to connect using Thunderbird.
>
> Config:
>
> IMAP port 993 / ssl/TLS / Normal Password / username :
> keith at keiththewebguy.com and password that is in
> /etc/dovecot/dovecot-users
>
> SMTP port 25 / STARTTLS / Normal Password / username :
> keith at keiththewebguy.com and password that is in
> /etc/dovecot/dovecot-users
>
> Thunderbird tests these configurations and reports them as found on the
> server.
>
> When I press the done button to create the email account I get a
> message "Unable to log into the server. Probably wrong
> configuration, username, or password.".
>
> The output when trying to create the Thunderbird account:
>
> /var/log/mail.log
>
> ===============
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x10,
> ret=1: before SSL initialization
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: before SSL initialization
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2002,
> ret=-1: before SSL initialization
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: before SSL initialization
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: SSLv3/TLS read client hello
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: SSLv3/TLS write server hello
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: SSLv3/TLS write certificate
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: SSLv3/TLS write key exchange
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: SSLv3/TLS write server done
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2002,
> ret=-1: SSLv3/TLS write server done
> Jul 5 18:58:35 soho dovecot: message repeated 2 times: [ imap-login:
> Debug: SSL: where=0x2002, ret=-1: SSLv3/TLS write server done]
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: SSLv3/TLS write server done
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: SSLv3/TLS read client key exchange
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: SSLv3/TLS read change cipher spec
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: SSLv3/TLS read finished
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: SSLv3/TLS write session ticket
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: SSLv3/TLS write change cipher spec
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2001,
> ret=1: SSLv3/TLS write finished
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x20,
> ret=1: SSL negotiation finished successfully
> Jul 5 18:58:35 soho dovecot: imap-login: Debug: SSL: where=0x2002,
> ret=1: SSL negotiation finished successfully
> Jul 5 18:58:35 soho dovecot: auth: Debug: Loading modules from
> directory: /usr/lib/dovecot/modules/auth
> Jul 5 18:58:35 soho dovecot: auth: Debug: Module loaded:
> /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
> Jul 5 18:58:35 soho dovecot: auth: Debug: Read auth token secret from
> /var/run/dovecot/auth-token-secret.dat
> Jul 5 18:58:35 soho dovecot: auth: Debug: passwd-file
> /etc/dovecot/dovecot-users: Read 1 users in 0 secs
> Jul 5 18:58:35 soho dovecot: auth: Debug: auth client connected
> (pid=2021)
> Jul 5 18:58:35 soho dovecot: auth: Debug: client in:
> AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=wVJ55GTGvspiv2yV#011lip=192.168.1.10#011rip=98.191.108.149#011lport=993#011rport=51902#011local_name=mail.keiththewebguy.com#011ssl_cipher=ECDHE-RSA-AES128-GCM-SHA256#011ssl_cipher_bits=128#011ssl_pfs=KxECDHE#011ssl_protocol=TLSv1.2
> Jul 5 18:58:35 soho dovecot: auth: Debug: client passdb out:
> CONT#0111#011
> Jul 5 18:58:35 soho dovecot: auth: Debug: client in:
> CONT#0111#011AGtlaXRoQGtlaXRodGhld2ViZ3V5LmNvbQBJY2VjcmVhbS1Db25lXjIx
> (previous base64 data may contain sensitive data)
> Jul 5 18:58:35 soho dovecot: auth: Debug:
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> Performing passdb lookup
> Jul 5 18:58:35 soho dovecot: auth: Debug:
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> lookup: user=keith at keiththewebguy.com file=/etc/dovecot/dovecot-users
> Jul 5 18:58:35 soho dovecot: auth:
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> unknown user
> Jul 5 18:58:35 soho dovecot: auth: Debug:
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> Finished passdb lookup
> Jul 5 18:58:35 soho dovecot: auth: Debug:
> auth(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>): Auth
> request finished
> Jul 5 18:58:37 soho dovecot: auth: Debug: client passdb out:
> FAIL#0111#011user=keith at keiththewebguy.com
> Jul 5 18:58:37 soho dovecot: auth: Debug: client in:
> AUTH#0112#011LOGIN#011service=imap#011secured=tls#011session=wVJ55GTGvspiv2yV#011lip=192.168.1.10#011rip=98.191.108.149#011lport=993#011rport=51902#011local_name=mail.keiththewebguy.com#011ssl_cipher=ECDHE-RSA-AES128-GCM-SHA256#011ssl_cipher_bits=128#011ssl_pfs=KxECDHE#011ssl_protocol=TLSv1.2
> Jul 5 18:58:41 soho dovecot: auth: Debug: client passdb out:
> CONT#0112#011VXNlcm5hbWU6
> Jul 5 18:58:41 soho dovecot: auth: Debug: client in:
> CONT#0112#011a2VpdGhAa2VpdGh0aGV3ZWJndXkuY29t (previous base64 data
> may contain sensitive data)
> Jul 5 18:58:41 soho dovecot: auth: Debug: client passdb out:
> CONT#0112#011UGFzc3dvcmQ6
> Jul 5 18:58:41 soho dovecot: auth: Debug: client in:
> CONT#0112#011SWNlY3JlYW0tQ29uZV4yMQ== (previous base64 data may
> contain sensitive data)
> Jul 5 18:58:41 soho dovecot: auth: Debug:
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> Performing passdb lookup
> Jul 5 18:58:41 soho dovecot: auth: Debug:
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> lookup: user=keith at keiththewebguy.com file=/etc/dovecot/dovecot-users
> Jul 5 18:58:41 soho dovecot: auth:
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> unknown user
> Jul 5 18:58:41 soho dovecot: auth: Debug:
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> Finished passdb lookup
> Jul 5 18:58:41 soho dovecot: auth: Debug:
> auth(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>): Auth
> request finished
> Jul 5 18:58:43 soho dovecot: auth: Debug: client passdb out:
> FAIL#0112#011user=keith at keiththewebguy.com
> Jul 5 18:58:43 soho dovecot: auth: Debug: client in:
> AUTH#0113#011PLAIN#011service=imap#011secured=tls#011session=wVJ55GTGvspiv2yV#011lip=192.168.1.10#011rip=98.191.108.149#011lport=993#011rport=51902#011local_name=mail.keiththewebguy.com#011ssl_cipher=ECDHE-RSA-AES128-GCM-SHA256#011ssl_cipher_bits=128#011ssl_pfs=KxECDHE#011ssl_protocol=TLSv1.2#011resp=AGtlaXRoQGtlaXRodGhld2ViZ3V5LmNvbQBJY2VjcmVhbS1Db25lXjIx
> (previous base64 data may contain sensitive data)
> Jul 5 18:58:47 soho dovecot: auth: Debug:
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> Performing passdb lookup
> Jul 5 18:58:47 soho dovecot: auth: Debug:
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> lookup: user=keith at keiththewebguy.com file=/etc/dovecot/dovecot-users
> Jul 5 18:58:47 soho dovecot: auth:
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> unknown user
> Jul 5 18:58:47 soho dovecot: auth: Debug:
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> Finished passdb lookup
> Jul 5 18:58:47 soho dovecot: auth: Debug:
> auth(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>): Auth
> request finished
> Jul 5 18:58:49 soho dovecot: auth: Debug: client passdb out:
> FAIL#0113#011user=keith at keiththewebguy.com
> Jul 5 18:58:49 soho dovecot: imap-login: Debug: SSL alert: close
> notify
> Jul 5 18:58:49 soho dovecot: imap-login: Disconnected (auth failed, 3
> attempts in 14 secs): user=<keith at keiththewebguy.com>, method=PLAIN,
> rip=98.191.108.149, lip=192.168.1.10, TLS, session=<wVJ55GTGvspiv2yV>
> Jul 5 18:58:49 soho dovecot: imap-login: Debug: SSL alert: close
> notify
> ==================
>
> I see the following lines:
>
> passwd-file /etc/dovecot/dovecot-users: Read 1 users in 0 secs
>
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> Performing passdb lookup
>
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> lookup: user=keith at keiththewebguy.com file=/etc/dovecot/dovecot-users
>
> file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> unknown user
>
> passwd-file(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
> Finished passdb lookup
>
> auth(keith at keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>): Auth
> request finished
>
> client passdb out: FAIL#0111#011user=keith at keiththewebguy.com
>
> - - - -
>
> dovecot -n :
>
> # 2.3.7.2 (3c910f64b): /etc/dovecot/dovecot.conf
> # Pigeonhole version 0.5.7.2 ()
> # OS: Linux 5.4.0-77-generic x86_64 Ubuntu 20.04.2 LTS ext4
> # Hostname: soho.keiththewebguy.com
> auth_debug = yes
> auth_debug_passwords = yes
> auth_mechanisms = plain login
> auth_verbose = yes
> mail_debug = yes
> mail_location = maildir:/var/mail/vhosts/%d/%n
> mail_privileged_group = mail
> 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 = scheme=PLAIN username_format=%u /etc/dovecot/dovecot-users
> driver = passwd-file
> }
> protocols = " imap lmtp pop3"
> service auth {
> unix_listener /var/spool/postfix/private/auth {
> group = postfix
> mode = 0666
> user = postfix
> }
> }
> service imap-login {
> inet_listener imaps {
> port = 993
> ssl = yes
> }
> }
> service lmtp {
> unix_listener /var/spool/postfix/private/dovecot-lmtp {
> group = postfix
> mode = 0600
> user = postfix
> }
> }
> ssl = required
> ssl_cert = </etc/letsencrypt/live/keiththewebguy.com/fullchain.pem
> ssl_client_ca_dir = /etc/ssl/certs
> ssl_dh = # hidden, use -P to show it
> ssl_key = # hidden, use -P to show it
> userdb {
> args = uid=vmail gid=vmail home=/var/mail/vhosts/%d/%n
> driver = static
> }
> verbose_ssl = yes
> - - -
>
> Any thoughts are most welcome!! Thanks in advance!!
More information about the dovecot
mailing list