Why does Dovecot fails to auth passwd-file when sending external emails?

Question

I have a Postfix-Dovecot-Spamassassin-RoundCube setup where I have virtual domains and users that accept mail in Maildir style. However, recent change I made (cannot pinpoint what I did though), allows me to receive emails from local and external sources (other virtual domains or Gmail), but allows me to send emails only to the local domains. When I try to send an email to Gmail, I see in /var/log/dovecot.info/:

Nov 10 14:19:52 auth: Info: passwd-file(some.email@gmail.com): unknown user

Running dovecot -n | grep passwd returns with:

driver = passwd-file

I am able to login to any and all my RoundCube emails, and as said, able to locally send emails. What should I be looking for (or into) to investigate this further.

As a note, when I send email from the command like i.e.

mail some.email@gmail.com

enter the subject, the body and then send with ctrl+d it successfully sends the email.

#

UPDATE 1:

After I made the following change in /etc/postfix/master.cf from:

spamassassin unix -     n   n   -   -   pipe
    flags=DROhu user=vmail:vmail argv=/usr/bin/spamc -f -e
    /usr/lib/dovecot/deliver -f ${sender} -d ${user}@${nexthop}

to:

spamassassin unix -     n   n   -   -   pipe
    flags=DROhu user=vmail:vmail argv=/usr/bin/spamc -f -e
    /usr/sbin/sendmail -oi -f ${sender} ${recipient}

The output of dovecot -n and postconf -n is:

dovecot -n

# 2.2.13: /etc/dovecot/dovecot.conf
# OS: Linux 3.16.0-4-amd64 x86_64 Debian 8.5
auth_verbose = yes
base_dir = /var/run/dovecot/
info_log_path = /var/log/dovecot.info
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
log_path = /var/log/dovecot
mail_home = /home/vmail/%d/%n
mail_location = maildir:~/
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character vacati
on subaddress comparator-i;ascii-numeric relational regex imap4flags copy includ
e variables body enotify environment mailbox date ihave
namespace inbox {
  hidden = no
  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 =
  subscriptions = yes
}
passdb {
  args = scheme=PLAIN username_format=%u /etc/dovecot/users
  driver = passwd-file
}
plugin {
  sieve = /etc/dovecot/sieve/default.sieve
  sieve_dir = ~/sieve
}
pop3_uidl_format = %g
postmaster_address = postmaster@${DOMAIN}
protocols = imap pop3
service auth {
  unix_listener /var/spool/postfix/private/auth {
    group = postfix
    mode = 0660
    user = postfix
  }
}
service imap-login {
  inet_listener imaps {
    port = 0
  }
}
ssl = no
ssl_cert = /etc/ssl/dovecot.crt
ssl_key = /etc/ssl/dovecot.key
ssl_parameters_regenerate = 1 days
userdb {
  args = uid=vmail gid=vmail home=/home/vmail/%d/%n
  driver = static
}
userdb {
  args = uid=vmail gid=vmail home=/home/vmail/%d/%n
  driver = static
}
valid_chroot_dirs = /home/vmail/
verbose_ssl = yes
protocol lmtp {
  mail_plugins = " sieve"
}
protocol lda {
  mail_plugins = " sieve"
}

postconf -n

alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
append_dot_mydomain = no
biff = no
broken_sasl_auth_clients = yes
config_directory = /etc/postfix
home_mailbox = Maildir/
inet_interfaces = all
mailbox_command =
mailbox_size_limit = 0
milter_default_action = accept
milter_protocol = 2
mydestination = fqdn.mydomain.com, mercury, localhost.localdomain, localhost
myhostname = fqdn.mydomain.com
mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128
myorigin = /etc/mailname
non_smtpd_milters = inet:localhost:12301
queue_directory = /var/spool/postfix
readme_directory = no
recipient_delimiter = +
relayhost =
smtp_sasl_auth_enable = yes
smtp_sasl_password_maps = hash:/etc/postfix/sasl/sasl_passwd
smtp_sasl_security_options = noanonymous
smtp_tls_CApath = /etc/ssl/certs
smtp_tls_cert_file = /etc/ssl/dovecot.crt
smtp_tls_key_file = /etc/ssl/dovecot.key
smtp_tls_loglevel = 1
smtp_tls_security_level = may
smtp_use_tls = yes
smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)
smtpd_milters = inet:localhost:12301
smtpd_relay_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_
unauth_destination
smtpd_sasl_auth_enable = yes
smtpd_sasl_authenticated_header = yes
smtpd_sasl_path = private/auth
smtpd_sasl_type = dovecot
smtpd_tls_CApath = /etc/ssl/certs
smtpd_tls_cert_file = /etc/ssl/dovecot.crt
smtpd_tls_key_file = /etc/ssl/dovecot.key
smtpd_tls_loglevel = 1
smtpd_tls_protocols = !SSLv2, !SSLv3
smtpd_tls_security_level = may
smtpd_use_tls = yes
spamassassin_destination_recipient_limit = 1
virtual_alias_maps = hash:/etc/postfix/virtual
virtual_gid_maps = static:5000
virtual_mailbox_base = /home/vmail
virtual_mailbox_domains = /etc/postfix/vhosts
virtual_mailbox_maps = hash:/etc/postfix/vmaps
virtual_minimum_uid = 1000
virtual_uid_maps = static:5000

#

UPDATE 2

Sending an email from info@mydomain.com to some.email@gmail.com has the following in /var/log/dovecot.info:

Nov 12 11:22:36 imap-login: Info: Login: user=<info@mydomain.com>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=4959, secured, session=<PC/CAx$
Nov 12 11:22:36 imap(info@mydomain.com): Info: Disconnected: Logged out in=294 out=2088
Nov 12 11:22:42 auth: Info: passwd-file(some.email@gmail.com): unknown user
Nov 12 11:22:42 auth: Info: passwd-file(some.email@gmail.com): unknown user

The relevant information in /var/log/syslog`:

Nov 12 11:22:34 mercury postfix/smtpd[4945]: connect from localhost[127.0.0.1]
Nov 12 11:22:34 mercury postfix/smtpd[4945]: DE1B681B65: client=localhost[127.0.0.1]
Nov 12 11:22:34 mercury postfix/cleanup[4949]: DE1B681B65: message-id=<2a63f407760165a7d9f17526f9c17d23@mydomain.com>
Nov 12 11:22:34 mercury opendkim[24011]: DE1B681B65: DKIM-Signature field added (s=mail, d=mydomain.com)
Nov 12 11:22:34 mercury postfix/qmgr[4835]: DE1B681B65: from=<info@mydomain.com>, size=6710, nrcpt=1 (queue active)
Nov 12 11:22:34 mercury spamd[21658]: spamd: connection from ip6-localhost [::1]:36324 to port 783, fd 6
Nov 12 11:22:35 mercury spamd[21658]: spamd: setuid to vmail succeeded
Nov 12 11:22:35 mercury spamd[21658]: spamd: processing message <2a63f407760165a7d9f17526f9c17d23@mydomain.com> for vmail:5000
Nov 12 11:22:35 mercury postfix/smtpd[4945]: disconnect from localhost[127.0.0.1]
Nov 12 11:22:42 mercury spamd[21658]: spamd: clean message (-1.1/5.5) for vmail:5000 in 7.1 seconds, 7016 bytes.
Nov 12 11:22:42 mercury spamd[21658]: spamd: result: . -1 - ALL_TRUSTED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,HTML_MESSAGE,T_REMOTE_IMAGE scantime=7.1,size=7016,user=vmail,uid=5000,required_score=5.5,rhost=ip6-localhost,raddr=::1,rport=36324,mid=<2a63f407760165a7d9f17526f9c17d23@mydomain.com>,autolearn=ham autolearn_force=no
Nov 12 11:22:42 mercury postfix/pipe[4950]: DE1B681B65: to=<some.email@gmail.com>, relay=spamassassin, delay=7.3, delays=0.08/0.01/0/7.2, dsn=5.1.1, status=bounced (user unknown)
Nov 12 11:22:42 mercury postfix/cleanup[4949]: 2F53381B67: message-id=<20161112162242.2F53381B67@fqdn.mydomain.com>
Nov 12 11:22:42 mercury postfix/qmgr[4835]: 2F53381B67: from=<>, size=8909, nrcpt=1 (queue active)
Nov 12 11:22:42 mercury postfix/bounce[4961]: DE1B681B65: sender non-delivery notification: 2F53381B67
Nov 12 11:22:42 mercury postfix/qmgr[4835]: DE1B681B65: removed
Nov 12 11:22:42 mercury postfix/virtual[4962]: 2F53381B67: to=<info@mydomain.com>, relay=virtual, delay=0.03, delays=0/0.02/0/0, dsn=2.0.0, status=sent (delivered to maildir)
Nov 12 11:22:42 mercury postfix/qmgr[4835]: 2F53381B67: removed
Nov 12 11:22:42 mercury spamd[9376]: prefork: child states: II

Also, /var/log/mail.info has the following in relation to the test email:

Nov 12 11:22:26 mercury postfix/smtpd[4945]: warning: unknown[80.82.64.109]: SASL LOGIN authentication failed: Invalid authentication mechanism
Nov 12 11:22:26 mercury postfix/smtpd[4945]: disconnect from unknown[80.82.64.109]
Nov 12 11:22:34 mercury postfix/smtpd[4945]: connect from localhost[127.0.0.1]
Nov 12 11:22:34 mercury postfix/smtpd[4945]: DE1B681B65: client=localhost[127.0.0.1]
Nov 12 11:22:34 mercury postfix/cleanup[4949]: DE1B681B65: message-id=<2a63f407760165a7d9f17526f9c17d23@mydomain.com>
Nov 12 11:22:34 mercury opendkim[24011]: DE1B681B65: DKIM-Signature field added (s=mail, d=mydomain.com)
Nov 12 11:22:34 mercury postfix/qmgr[4835]: DE1B681B65: from=<info@mydomain.com>, size=6710, nrcpt=1 (queue active)
Nov 12 11:22:34 mercury spamd[21658]: spamd: connection from ip6-localhost [::1]:36324 to port 783, fd 6
Nov 12 11:22:35 mercury spamd[21658]: spamd: setuid to vmail succeeded
Nov 12 11:22:35 mercury spamd[21658]: spamd: processing message <2a63f407760165a7d9f17526f9c17d23@mydomain.com> for vmail:5000
Nov 12 11:22:35 mercury postfix/smtpd[4945]: disconnect from localhost[127.0.0.1]
Nov 12 11:22:42 mercury spamd[21658]: spamd: clean message (-1.1/5.5) for vmail:5000 in 7.1 seconds, 7016 bytes.
Nov 12 11:22:42 mercury spamd[21658]: spamd: result: . -1 - ALL_TRUSTED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,HTML_MESSAGE,T_REMOTE_IMAGE scantime=7.1,size=7016,user=vma
il,uid=5000,required_score=5.5,rhost=ip6-localhost,raddr=::1,rport=36324,mid=<2a63f407760165a7d9f17526f9c17d23@mydomain.com>,autolearn=ham autolearn_force=no
Nov 12 11:22:42 mercury postfix/pipe[4950]: DE1B681B65: to=<some.email@gmail.com>, relay=spamassassin, delay=7.3, delays=0.08/0.01/0/7.2, dsn=5.1.1, status=bounced (user unknown)
Nov 12 11:22:42 mercury postfix/cleanup[4949]: 2F53381B67: message-id=<20161112162242.2F53381B67@fqdn.mydomain.com>
Nov 12 11:22:42 mercury postfix/qmgr[4835]: 2F53381B67: from=<>, size=8909, nrcpt=1 (queue active)
Nov 12 11:22:42 mercury postfix/bounce[4961]: DE1B681B65: sender non-delivery notification: 2F53381B67
Nov 12 11:22:42 mercury postfix/qmgr[4835]: DE1B681B65: removed
Nov 12 11:22:42 mercury postfix/virtual[4962]: 2F53381B67: to=<info@mydomain.com>, relay=virtual, delay=0.03, delays=0/0.02/0/0, dsn=2.0.0, status=sent (delivered to maildir)
Nov 12 11:22:42 mercury postfix/qmgr[4835]: 2F53381B67: removed
Nov 12 11:22:42 mercury spamd[9376]: prefork: child states: II

Please provide the full output of `doveconf -n` and `postconf -n`. — Jens Erat, Nov 11 '16 at 21:20
Could you please add more log details for a single message you're trying to send? Starting with authentication until the delivery failed, both the logs of Dovecot and Postfix. — Jens Erat, Nov 12 '16 at 08:49
I have added the related output from `dovecot.info`, `syslog`, and `mail.info`. Thanks — KingsInnerSoul, Nov 12 '16 at 16:46
It seems outgoing mail is sent through SpamAssassin, which then again injects it back to Postfix. Do you want to scan outgoing mail? Where did you configure mail being forwarded to SpamAssasin (I'd guess somewhere in `master.cf`). — Jens Erat, Nov 12 '16 at 20:12
I believe you are right. `/etc/postfix/master.cf` has `smtp inet n - - - - smtpd -o content_filter=spamassassin` and then later I have `spamassassin unix - n n - - pipe flags=DROhu user=vmail:vmail argv=/usr/bin/spamc -f -e /usr/lib/dovecot/deliver -f ${sender} -d ${user}@${nexthop}` — KingsInnerSoul, Nov 12 '16 at 21:14
Now I think I understood what you have configured, and what the issue is. You already realized delivering mail is working when you change SpamAssassin's delivery command to sendmail, but then junk mail is not moved to the spam folder any more. Usually, SpamAssassin should provide some kind of header, which you can use within Sieve scripts to filter out spam (while SpamAssassin does not do anything but annotate mails).. — Jens Erat, Nov 12 '16 at 21:30

score 0 · Answer 1 · answered Nov 11 '16 at 03:11

Well, might be simple enough, but for me, I had the following in /etc/postfix/master.cf:

spamassassin unix -     n   n   -   -   pipe
    flags=DROhu user=vmail:vmail argv=/usr/bin/spamc -f -e
    /usr/lib/dovecot/deliver -f ${sender} -d ${user}@${nexthop}

after I changed it to:

spamassassin unix -     n   n   -   -   pipe
    flags=DROhu user=vmail:vmail argv=/usr/bin/spamc -f -e
    /usr/sbin/sendmail -oi -f ${sender} ${recipient}

and restarted postfix using service postfix restart it started working :-)

This actually does not work well for me. I am able to send outgoing emails, but now, spam emails are not being sent to the Junk folder. Any ideas? — KingsInnerSoul, Nov 11 '16 at 18:13

Why does Dovecot fails to auth passwd-file when sending external emails?

#

#

1 Answers1