Sorry for all the notes;

I'm trying to have postfix 3.4.8, trying to authenticate postfix against Dovecot 2.3.4.1 passwd-file, using lmtp.

Not sure if I'm failing because of a smtp failure or I'm not getting authenticated by dovecot.



main.cf

virtual_transport=lmtp:unix:private/dovecot-lmtp



postfix log

connect from unknown[192.168.212.227]

Apr 28 13:42:14 mail3 postfix/smtpd[21859]: lost connection after EHLO from unknown[192.168.212.227]

Apr 28 13:42:14 mail3 postfix/smtpd[21859]: disconnect from unknown[192.168.212.227] ehlo=2 starttls=1 commands=3



I keep getting smtp timed out, it takes a while, but does time out.


Using openssl s_client -connect 192.168.0.242:25 -starttls smtp

subject=/C=US/ST=CA/L=Fullerton/O=xxxx Law Group/CN=mail.xxxxlawgroup.com/emailAddress=postmaster@xxxxlawgroup.com

issuer=/C=US/ST=CA/L=Fullerton/O=xxxx Law Group/CN=mail.xxxxlawgroup.com/emailAddress=postmaster@xxxxlawgroup.com

---

No client certificate CA names sent

Peer signing digest: SHA512

Server Temp Key: ECDH, P-256, 256 bits

---

SSL handshake has read 2717 bytes and written 468 bytes

---

New, TLSv1/SSLv3, Cipher is ECDHE-RSA-AES256-GCM-SHA384

Server public key is 4096 bit

Secure Renegotiation IS supported

Compression: NONE

Expansion: NONE

No ALPN negotiated

SSL-Session:

Protocol : TLSv1.2

Cipher : ECDHE-RSA-AES256-GCM-SHA384

Session-ID: 2F32869DCC5511285AA7D99ABAAD34C1E42EB04A7AA704C5EBC801C2625ECB7A

Session-ID-ctx:

Master-Key: F8D92A918AC14D31B252D981228A0AA3C0BCA379B9D12DD6E795092C8390382DA09D640B2F24AD8F279C13E71DF86434

Key-Arg : None

PSK identity: None

PSK identity hint: None

SRP username: None

TLS session ticket lifetime hint: 7200 (seconds)

TLS session ticket:

0000 - 89 e1 b7 19 14 7b d6 85-88 cc 8d f0 e0 45 6f 23 .....{.......Eo#

0010 - 34 b7 30 ec 99 39 d9 98-3f 5d 70 b3 f3 fe 0a 13 4.0..9..?]p.....

0020 - 77 3c 2c 20 22 b4 62 71-ec 02 b4 ee 4e 35 78 ef w<, ".bq....N5x.

0030 - f2 2c 7d 01 e3 51 7c 2e-c4 78 65 37 d6 ef 60 32 .,}..Q|..xe7..`2

0040 - f6 62 bc e5 ba fc 82 1b-37 0a de c9 b1 82 99 f5 .b......7.......

0050 - de 6c d5 c1 56 25 5a 2a-27 8d a3 6a 8a bd 37 d8 .l..V%Z*'..j..7.

0060 - 11 65 0d fd 89 c3 e2 86-43 89 9e b9 c2 b7 a4 44 .e......C......D

0070 - dc f3 8b 94 8e 41 37 d3-32 ca 2c 4e 65 6b 1c f9 .....A7.2.,Nek..

0080 - 04 d0 45 32 8a 2d 67 8d-36 05 23 4a 58 c2 d8 b7 ..E2.-g.6.#JX...

0090 - 65 ba e0 8d 8b 85 9c c2-45 31 78 33 86 d1 bf 1f e.......E1x3....


Start Time: 1588106358

Timeout : 300 (sec)

Verify return code: 18 (self signed certificate)

---

250 CHUNKING

helo

401 Syntax: HELO hostname

helo mail3.xxxxlawgroup.com

250 mail3.xxxxlawgroup.com



Dovecot Log during client login attempt

Apr 28 13:33:17 auth: Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth

Apr 28 13:33:17 auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so

Apr 28 13:33:17 auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so

Apr 28 13:33:17 auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_pgsql.so

Apr 28 13:33:17 auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat

Apr 28 13:33:17 auth: Debug: passwd-file /etc/dovecot/users: Read 3 users in 0 secs

Apr 28 13:33:17 auth: Debug: auth client connected (pid=21786)

Apr 28 13:33:19 auth: Debug: client in: AUTH 1 PLAIN service=imap secured=tls session=w8T7vV+keNHAqNTj lip=192.168.0.242 rip=192.168.212.227 lport=993 rport=53624 ssl_cipher=ECDHE-RSA-AES256-GCM-SHA384 ssl_cipher_bits=256 ssl_pfs=KxECDHE ssl_protocol=TLSv1.2 resp=<hidden>

Apr 28 13:33:19 auth-worker(21788): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth

Apr 28 13:33:19 auth-worker(21788): Debug: Module loaded: /usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so

Apr 28 13:33:19 auth-worker(21788): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so

Apr 28 13:33:19 auth-worker(21788): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_pgsql.so

Apr 28 13:33:19 auth-worker(21788): Debug: passwd-file /etc/dovecot/users: Read 3 users in 0 secs

Apr 28 13:33:19 auth-worker(21788): Debug: pam(user1@xxxxlawgroup.com,192.168.212.227,<w8T7vV+keNHAqNTj>): lookup service=dovecot

Apr 28 13:33:19 auth-worker(21788): Debug: pam(user1@xxxxlawgroup.com,192.168.212.227,<w8T7vV+keNHAqNTj>): #1/1 style=1 msg=Password:

Apr 28 13:33:21 auth-worker(21788): Info: pam(user1@xxxxlawgroup.com,192.168.212.227,<w8T7vV+keNHAqNTj>): pam_authenticate() failed: Authentication failure (Password mismatch?)

Apr 28 13:33:21 auth: Debug: passwd-file(user1@xxxxlawgroup.com,192.168.212.227,<w8T7vV+keNHAqNTj>): lookup: user=user1@xxxxlawgroup.com file=/etc/dovecot/users

Apr 28 13:33:21 auth: Debug: client passdb out: OK 1 user=user1@xxxxlawgroup.com

Apr 28 13:33:21 auth: Debug: master in: REQUEST 570163201 21786 1 83383e6a14e2c97c394478e56e4e7fd9 session_pid=21789 request_auth_token

Apr 28 13:33:21 auth-worker(21788): Debug: passwd(user1@xxxxlawgroup.com,192.168.212.227,<w8T7vV+keNHAqNTj>): lookup

Apr 28 13:33:21 auth-worker(21788): Info: passwd(user1@xxxxlawgroup.com,192.168.212.227,<w8T7vV+keNHAqNTj>): unknown user

Apr 28 13:33:21 auth: Debug: passwd-file(user1@xxxxlawgroup.com,192.168.212.227,<w8T7vV+keNHAqNTj>): lookup: user=user1@xxxxlawgroup.com file=/etc/dovecot/users

Apr 28 13:33:21 auth: Debug: master userdb out: USER 570163201 user1@xxxxlawgroup.com auth_token=918dceaf840599ad8132ae793a11ab5b9d17bb8c

Apr 28 13:33:21 imap-login: Info: Login: user=<user1@xxxxlawgroup.com>, method=PLAIN, rip=192.168.212.227, lip=192.168.0.242, mpid=21789, TLS, session=<w8T7vV+keNHAqNTj>

Apr 28 13:33:21 imap(user1@xxxxlawgroup.com)<21789><w8T7vV+keNHAqNTj>: Debug: Added userdb setting: plugin/=yes

Apr 28 13:33:21 imap(user1@xxxxlawgroup.com)<21789><w8T7vV+keNHAqNTj>: Debug: Effective uid=1001, gid=1001, home=/srv/vmail/user1@xxxxlawgroup.com

Apr 28 13:33:21 imap(user1@xxxxlawgroup.com)<21789><w8T7vV+keNHAqNTj>: Debug: Home dir not found: /srv/vmail/user1@xxxxlawgroup.com

Apr 28 13:33:21 imap(user1@xxxxlawgroup.com)<21789><w8T7vV+keNHAqNTj>: Debug: Namespace inbox: type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=mbox:~/mail

Apr 28 13:33:21 imap(user1@xxxxlawgroup.com)<21789><w8T7vV+keNHAqNTj>: Debug: mbox: INBOX defaulted to /srv/vmail/user1@xxxxlawgroup.com/mail/inbox

Apr 28 13:33:21 imap(user1@xxxxlawgroup.com)<21789><w8T7vV+keNHAqNTj>: Debug: fs: root=/srv/vmail/user1@xxxxlawgroup.com/mail, index=, indexpvt=, control=, inbox=/srv/vmail/user1@xxxxlawgroup.com/mail/inbox, alt=

Apr 28 13:33:21 imap(user1@xxxxlawgroup.com)<21789><w8T7vV+keNHAqNTj>: Info: Connection closed (IDLE running for 0.001 + waiting input for 0.001 secs, 2 B in + 10+10 B out, state=wait-input) in=11 out=387 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0



The imap client logon looks to be fine;

Apr 27 16:57:02 auth-worker(17516): Debug: pam(user1@xxxxlawgroup.com,192.168.212.227,<5oeueE6k4uvAqNTj>): lookup service=dovecot

Apr 27 16:57:02 auth-worker(17516): Debug: pam(user1@xxxxlawgroup.com,192.168.212.227,<5oeueE6k4uvAqNTj>): #1/1 style=1 msg=Password:

Apr 27 16:57:04 auth-worker(17516): Info: pam(user1@xxxxlawgroup.com,192.168.212.227,<5oeueE6k4uvAqNTj>): pam_authenticate() failed: Authentication failure (Password mismatch?)

Apr 27 16:57:04 auth: Debug: passwd-file(user1@xxxxlawgroup.com,192.168.212.227,<5oeueE6k4uvAqNTj>): lookup: user=user1@xxxxlawgroup.com file=/etc/dovecot/users

Apr 27 16:57:04 auth: Debug: client passdb out: OK 1 user=user1@xxxxlawgroup.com

Apr 27 16:57:04 auth: Debug: master in: REQUEST 3141009409 17512 1 ee216d7c96d9d2faeb794c94747d479a session_pid=17517 request_auth_token

Apr 27 16:57:04 auth-worker(17516): Debug: passwd(user1@xxxxlawgroup.com,192.168.212.227,<5oeueE6k4uvAqNTj>): lookup

Apr 27 16:57:04 auth-worker(17516): Info: passwd(user1@xxxxlawgroup.com,192.168.212.227,<5oeueE6k4uvAqNTj>): unknown user

Apr 27 16:57:04 auth: Debug: passwd-file(user1@xxxxlawgroup.com,192.168.212.227,<5oeueE6k4uvAqNTj>): lookup: user=user1@xxxxlawgroup.com file=/etc/dovecot/users

Apr 27 16:57:04 auth: Debug: master userdb out: USER 3141009409 user1@xxxxlawgroup.com auth_token=3866c7fac33f25e817f9d95c494a13343942f60d

Apr 27 16:57:04 imap-login: Info: Login: user=<user1@xxxxlawgroup.com>, method=PLAIN, rip=192.168.212.227, lip=192.168.0.242, mpid=17517, TLS, session=<5oeueE6k4uvAqNTj>

Apr 27 16:57:04 imap(user1@xxxxlawgroup.com)<17517><5oeueE6k4uvAqNTj>: Debug: Added userdb setting: plugin/=yes

Apr 27 16:57:04 imap(user1@xxxxlawgroup.com)<17517><5oeueE6k4uvAqNTj>: Debug: Effective uid=1001, gid=1001, home=/srv/vmail/user1@xxxxlawgroup.com

Apr 27 16:57:04 imap(user1@xxxxlawgroup.com)<17517><5oeueE6k4uvAqNTj>: Debug: Home dir not found: /srv/vmail/user1@xxxxlawgroup.com

Apr 27 16:57:04 imap(user1@xxxxlawgroup.com)<17517><5oeueE6k4uvAqNTj>: Debug: Namespace inbox: type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=mbox:~/mail

Apr 27 16:57:04 imap(user1@xxxxlawgroup.com)<17517><5oeueE6k4uvAqNTj>: Debug: mbox: INBOX defaulted to /srv/vmail/user1@xxxxlawgroup.com/mail/inbox

Apr 27 16:57:04 imap(user1@xxxxlawgroup.com)<17517><5oeueE6k4uvAqNTj>: Debug: fs: root=/srv/vmail/user1@xxxxlawgroup.com/mail, index=, indexpvt=, control=, inbox=/srv/vmail/user1@xxxxlawgroup.com/mail/inbox, alt=




User test on dovecot

root@mail3:/etc/dovecot# doveadm user user1@xxxxlawgroup.com

field value

uid vmail

gid vmail

home /srv/vmail/user1@xxxxlawgroup.com

mail mbox:~/mail

root@mail3:/etc/dovecot# doveadm user user2@xxxxlawgroup.com

field value

uid vmail

gid vmail

home /srv/vmail/user2@xxxxlawgroup.com

mail mbox:~/mail


log of test

r 28 12:37:53 auth-worker(21333): Debug: passwd(user1@xxxxlawgroup.com): lookup

Apr 28 12:37:53 auth-worker(21333): Info: passwd(user1@xxxxlawgroup.com): unknown user

Apr 28 12:37:53 auth: Debug: passwd-file(user1@xxxxlawgroup.com): lookup: user=user1@xxxxlawgroup.com file=/etc/dovecot/users

Apr 28 12:37:53 auth: Debug: userdb out: USER 1 user1@xxxxlawgroup.com

Apr 28 12:38:04 auth: Debug: master in: USER 1 user2@xxxxlawgroup.com service=doveadm debug

Apr 28 12:38:04 auth-worker(21333): Debug: passwd(user2@xxxxlawgroup.com): lookup

Apr 28 12:38:04 auth-worker(21333): Info: passwd(user2@xxxxlawgroup.com): unknown user

Apr 28 12:38:04 auth: Debug: passwd-file(user2@xxxxlawgroup.com): lookup: user=user2@xxxxlawgroup.com file=/etc/dovecot/users

Apr 28 12:38:04 auth: Debug: userdb out: USER 1 user2@xxxxlawgroup.com



Debian 10.2 Buster


Dovecot 2.3.4.1 (installed using apt)


# 2.3.4.1 (f79e8e7e4): /etc/dovecot/dovecot.conf

# Pigeonhole version 0.5.4 ()

# OS: Linux 4.19.0-6-amd64 x86_64 Debian 10.3

# Hostname: mail3.xxxxlawgroup.com

auth_debug = yes

auth_mechanisms = plain login

auth_verbose = yes

debug_log_path = /var/log/dovecot.log

disable_plaintext_auth = no

info_log_path = /var/log/dovecot.log

log_path = /var/log/dovecot.log

login_greeting = xxxx xxxxx Dovecot ready.

mail_debug = yes

mail_gid = vmail

mail_home = /srv/vmail/%u

mail_location = mbox:~/mail

mail_privileged_group = vmail

mail_uid = vmail

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 =

separator = /

}

passdb {

driver = pam

}

passdb {

args = username_format=%u /etc/dovecot/users

driver = passwd-file

}

plugin {

sieve = file:~/sieve;active=~/.dovecot.sieve

}

protocols = " imap lmtp pop3"

service auth {

unix_listener /var/spool/postfix/private/auth {

group = postfix

mode = 0666

user = postfix

}

}

service lmtp {

unix_listener lmtp {

group = postfix

mode = 0666

user = postfix

}

}

ssl_cert = </etc/ssl/certs/mail.xxxxlawgroup.com.pem

ssl_dh = # hidden, use -P to show it

ssl_key = # hidden, use -P to show it

userdb {

driver = passwd

}

userdb {

args = username_format=%u /etc/dovecot/users

driver = passwd-file

}

verbose_proctitle = yes

protocol lmtp {

postmaster_address = postmaster@xxxxlawgroup.com

}



On the postfix side:

main.cf

ver 3.4.8


smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)

biff = no

append_dot_mydomain = no

readme_directory = no

compatibility_level = 2


smtpd_tls_cert_file=/etc/ssl/certs/mail.xxxxlawgroup.com.pem

smtpd_tls_key_file=/etc/ssl/private/mail.xxxxlawgroup.com.key

smtpd_use_tls=yes

smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache

smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache


smtpd_relay_restrictions =

permit_mynetworks

permit_sasl_authenticated

defer_unauth_destination


myhostname = mail3.xxxxlawgroup.com

myorigin = /etc/mailname

mailbox_size_limit = 0

recipient_delimiter = +

inet_protocols = all


inet_interfaces = 127.0.0.1, 192.168.0.242


mynetworks =

127.0.0.0/8

[::ffff:127.0.0.0]/104

[::1]/128

23.120.233.17

192.168.0.0/24

192.168.39.0/24

192.168.14.0/24

192.168.212.0/24


mydestination =

localhost


smtpd_recipient_restrictions =

permit_sasl_autheticated

permit_mynetworks

reject_unauth_destination


relayhost = [192.168.0.253]:587

soft_bounce=yes


virtual_transport=lmtp:unix:private/dovecot-lmtp

virtual_mailbox_domains = xxxxlawgroup.com

virtual_mailbox_maps=hash:/etc/postfix/vmail_maps

virtual_alias_maps=hash:/etc/postfix/virtual

relay_domains=hash:/etc/postfix/relay_domains


smtp_sasl_auth_enable=yes

smtpd_sasl_type=dovecot

smtpd_sasl_path=private/auth

queue_directory=/var/spool/postfix

broken_sasl_auth_clients=yes


smtp_sasl_password_maps = hash:/etc/postfix/sasl_passwd


debug_peer_level=4

debug_peer_list=192.168.0.242


/etc/postfix/sasl_passwd

xxxxlawgroup.com username:password


/etc/postfix/vmail_maps

user1@xxxxlawgroup.com user1@xxxxlawgroup.com

user2@xxxxlawgroup.com user2@xxxxlawgroup.com

user3@xxxxlawgroup.com user3@xxxxlawgroup.com



master.cf


smtp inet n - y - - smtpd

submission inet n - y - - smtpd

-o syslog_name=postfix/submission

-o smtpd_tls_security_level=encrypt

-o smtpd_sasl_auth_enable=yes

-o smtpd_recipient_restrictions=permit_sasl_authenticated,reject

-o smtpd_relay_restrictions=permit_sasl_authenticated,reject

-o smtpd_sasl_type=dovecot

-o smtpd_sasl_path=private/auth

-o smtpd_sasl_security_options=noanonymous

-o smtpd_sasl_local_domain=$myhostname

-o smtpd_client_restrictions=permit_sasl_authenticated,reject

-o smtpd_sender_login_maps=/etc/postfix/virtual




pickup unix n - y 60 1 pickup

cleanup unix n - y - 0 cleanup

qmgr unix n - n 300 1 qmgr

tlsmgr unix - - y 1000? 1 tlsmgr

rewrite unix - - y - - trivial-rewrite

bounce unix - - y - 0 bounce

defer unix - - y - 0 bounce

trace unix - - y - 0 bounce

verify unix - - y - 1 verify

flush unix n - y 1000? 0 flush

proxymap unix - - n - - proxymap

proxywrite unix - - n - 1 proxymap

smtp unix - - y - - smtp

relay unix - - y - - smtp

-o syslog_name=postfix/$service_name

showq unix n - y - - showq

error unix - - y - - error

retry unix - - y - - error

discard unix - - y - - discard

local unix - n n - - local

virtual unix - n n - - virtual

lmtp unix - - y - - lmtp

anvil unix - - y - 1 anvil

scache unix - - y - 1 scache

postlog unix-dgram n - n - 1 postlogd

maildrop unix - n n - - pipe

flags=DRhu user=vmail argv=/usr/bin/maildrop -d ${recipient}

uucp unix - n n - - pipe

flags=Fqhu user=uucp argv=uux -r -n -z -a$sender - $nexthop!rmail ($recipient)

ifmail unix - n n - - pipe

flags=F user=ftn argv=/usr/lib/ifmail/ifmail -r $nexthop ($recipient)

bsmtp unix - n n - - pipe

flags=Fq. user=bsmtp argv=/usr/lib/bsmtp/bsmtp -t$nexthop -f$sender $recipient

scalemail-backend unix - n n - 2 pipe

flags=R user=scalemail argv=/usr/lib/scalemail/bin/scalemail-store ${nexthop} ${user} ${extension}

mailman unix - n n - - pipe

flags=FR user=list argv=/usr/lib/mailman/bin/postfix-to-mailman.py

${nexthop} ${user}

--
Jon Kelly
CNE

kelly@kel-tek.com
p 714.894.0130
For service calls, please email service@kel-tek.com