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, techli...@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 :
ke...@keiththewebguy.com and password that is in
/etc/dovecot/dovecot-users

SMTP port 25 / STARTTLS / Normal Password / username :
ke...@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(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
Performing passdb lookup
Jul  5 18:58:35 soho dovecot: auth: Debug:
passwd-file(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
lookup: user=ke...@keiththewebguy.com file=/etc/dovecot/dovecot-users
Jul  5 18:58:35 soho dovecot: auth:
passwd-file(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
unknown user
Jul  5 18:58:35 soho dovecot: auth: Debug:
passwd-file(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
Finished passdb lookup
Jul  5 18:58:35 soho dovecot: auth: Debug:
auth(ke...@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=ke...@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(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
Performing passdb lookup
Jul  5 18:58:41 soho dovecot: auth: Debug:
passwd-file(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
lookup: user=ke...@keiththewebguy.com file=/etc/dovecot/dovecot-users
Jul  5 18:58:41 soho dovecot: auth:
passwd-file(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
unknown user
Jul  5 18:58:41 soho dovecot: auth: Debug:
passwd-file(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
Finished passdb lookup
Jul  5 18:58:41 soho dovecot: auth: Debug:
auth(ke...@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=ke...@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(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
Performing passdb lookup
Jul  5 18:58:47 soho dovecot: auth: Debug:
passwd-file(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
lookup: user=ke...@keiththewebguy.com file=/etc/dovecot/dovecot-users
Jul  5 18:58:47 soho dovecot: auth:
passwd-file(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
unknown user
Jul  5 18:58:47 soho dovecot: auth: Debug:
passwd-file(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
Finished passdb lookup
Jul  5 18:58:47 soho dovecot: auth: Debug:
auth(ke...@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=ke...@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=<ke...@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(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
Performing passdb lookup

passwd-file(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
lookup: user=ke...@keiththewebguy.com file=/etc/dovecot/dovecot-users

file(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>): unknown user

passwd-file(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>):
Finished passdb lookup

auth(ke...@keiththewebguy.com,98.191.108.149,<wVJ55GTGvspiv2yV>): Auth
request finished

client passdb out: FAIL#0111#011user=ke...@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!!

Reply via email to