trying to authenticate postfix against Dovecot 2.3.4.1 passwd-file, using lmtp

28 Apr 2020 · _*postfix log*_


      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
<mailto: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

kelly

Peter

tags

participants (2)