Skip to content

Weird Dovecot login failures for emails arriving to a virtual alias #2091

@andrewlow

Description

@andrewlow

Subject

Understanding Dovecot login failures when email for an alias arrives. Email is working, just trying to understand the log messages.

Description

I've finally taken the leap and moved my email server over to docker-mailserver. Thank you to all of the contributors to this project.

It's still early days for me - but I've run a postfix based mail server for years (just installed directly on the OS). I'm seeing something odd in the mail.log from my new installation of docker-mailserver.

An email comes in for [email protected] - this is an alias in my config/postfix-virtual.cf file that is mapped to this user (casing is different, but that shouldn't matter)

Snippet of the virtual alias file

Now if we look at the mail.log for that email arriving - we see a weird thing.

Jul 19 15:01:03 mail dovecot: auth: passwd-file([email protected]): unknown user 

Now the email does get delivered to the right account (the alias is working fine). My concern is about why dovecot is trying to log in as the alias user? What's up with that? I can turn on more debug - but this feels like a pretty plain deployment.

I'd like to avoid fail2ban catching too many alias emails arriving, and banning someone.

Here is the more complete log.

Jul 19 15:01:02 mail postfix/postscreen[28103]: CONNECT from [136.147.130.236]:57937 to [172.17.0.5]:25
Jul 19 15:01:02 mail postfix/dnsblog[28122]: addr 136.147.130.236 listed by domain list.dnswl.org as 127.0.15.0
Jul 19 15:01:02 mail postfix/postscreen[28103]: PASS NEW [136.147.130.236]:57937
Jul 19 15:01:03 mail postfix/smtpd[29759]: connect from mta.mail.arbonnemail.com[136.147.130.236]
Jul 19 15:01:03 mail postfix/smtpd[29759]: Anonymous TLS connection established from mta.mail.arbonnemail.com[136.147.130.236]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jul 19 15:01:03 mail policyd-spf[29769]: prepend Received-SPF: Pass (mailfrom) identity=mailfrom; client-ip=136.147.130.236; helo=mta.mail.arbonnemail.com; envelope-from=bounce-344_html-18444
[email protected]; receiver=<UNKNOWN> 
Jul 19 15:01:03 mail dovecot: auth: passwd-file([email protected]): unknown user 
Jul 19 15:01:03 mail postfix/smtpd[29759]: CF302148566: client=mta.mail.arbonnemail.com[136.147.130.236]
Jul 19 15:01:03 mail postfix/cleanup[29773]: CF302148566: message-id=<[email protected]>
Jul 19 15:01:04 mail opendkim[2920]: CF302148566: mta.mail.arbonnemail.com [136.147.130.236] not internal
Jul 19 15:01:04 mail opendkim[2920]: CF302148566: not authenticated
Jul 19 15:01:04 mail opendkim[2920]: CF302148566: DKIM verification successful
Jul 19 15:01:04 mail opendkim[2920]: CF302148566: s=200608 d=mail.arbonnemail.com SSL 
Jul 19 15:01:04 mail opendmarc[2927]: CF302148566 ignoring Authentication-Results at 1 from mail.mydomain.com
Jul 19 15:01:04 mail opendmarc[2927]: CF302148566: mail.arbonnemail.com none
Jul 19 15:01:04 mail postfix/qmgr[3643]: CF302148566: from=<bounce-344_HTML-18444363-1683099-7207065-3001@bounce.mail.arbonnemail.com>, size=108763, nrcpt=1 (queue active)
Jul 19 15:01:04 mail postfix/smtpd[29759]: disconnect from mta.mail.arbonnemail.com[136.147.130.236] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
Jul 19 15:01:09 mail postfix/smtpd[29808]: connect from localhost[127.0.0.1]
Jul 19 15:01:09 mail postfix/smtpd[29808]: DE6F2148568: client=localhost[127.0.0.1]
Jul 19 15:01:09 mail postfix/cleanup[29773]: DE6F2148568: message-id=<[email protected]>
Jul 19 15:01:09 mail postfix/smtpd[29808]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Jul 19 15:01:09 mail amavis[3650]: (03650-04) Passed CLEAN {RelayedInbound}, [136.147.130.236]:57937 [136.147.130.236] <bounce-344_HTML-18444363-1683099-7207065-3001@bounce.mail.arbonnemail.com> -> <[email protected]>, Queue-ID: CF302148566, Message-ID: <[email protected]>, mail_id: czLde8GqdWpn, Hits: -0.089, size: 108816, queued_as: DE6F2148568, 5545 ms
Jul 19 15:01:09 mail postfix/qmgr[3643]: DE6F2148568: from=<bounce-344_HTML-18444363-1683099-7207065-3001@bounce.mail.arbonnemail.com>, size=109246, nrcpt=1 (queue active)
Jul 19 15:01:09 mail dovecot: lmtp(29810): Connect from local
Jul 19 15:01:09 mail postfix/smtp[29780]: CF302148566: to=<[email protected]>, orig_to=<[email protected]>, relay=127.0.0.1[127.0.0.1]:10024, delay=6.4, delays=0.85/0/0/5.5, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as DE6F2148568)
Jul 19 15:01:09 mail postfix/qmgr[3643]: CF302148566: removed
Jul 19 15:01:10 mail dovecot: lmtp([email protected])<29810><iDgSN/XL9WBydAAAJmGFMg>: sieve: msgid=<[email protected]>: stored mail into mailbox 'INBOX'
Jul 19 15:01:10 mail postfix/lmtp[29809]: DE6F2148568: to=<[email protected]>, relay=mail.mydomain.com[/var/run/dovecot/lmtp], delay=0.09, delays=0.01/0/0/0.08, dsn=2.0.0, status=sent (250 2.0.0 <[email protected]> iDgSN/XL9WBydAAAJmGFMg Saved)
Jul 19 15:01:10 mail postfix/qmgr[3643]: DE6F2148568: removed
Jul 19 15:01:10 mail dovecot: lmtp(29810): Disconnect from local: Client has quit the connection (state=READY)

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions