docker-mailserver: Weird Dovecot login failures for emails arriving to a virtual alias
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 skincare@mydomain.com - 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
Skincare@mydomain.com myuser@mydomain.com
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(skincare@mydomain.com): 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
363-1683099-7207065-3001@bounce.mail.arbonnemail.com; receiver=<UNKNOWN>
Jul 19 15:01:03 mail dovecot: auth: passwd-file(skincare@mydomain.com): 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=<69969198-6397-472c-ac73-609566daee5a@atl1s07mta2081.xt.local>
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=<69969198-6397-472c-ac73-609566daee5a@atl1s07mta2081.xt.local>
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> -> <myuser@mydomain.com>, Queue-ID: CF302148566, Message-ID: <69969198-6397-472c-ac73-609566daee5a@atl1s07mta2081.xt.local>, 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=<myuser@mydomain.com>, orig_to=<Skincare@mydomain.com>, 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(myuser@mydomain.com)<29810><iDgSN/XL9WBydAAAJmGFMg>: sieve: msgid=<69969198-6397-472c-ac73-609566daee5a@atl1s07mta2081.xt.local>: stored mail into mailbox 'INBOX'
Jul 19 15:01:10 mail postfix/lmtp[29809]: DE6F2148568: to=<myuser@mydomain.com>, 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 <myuser@mydomain.com> 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)
About this issue
- Original URL
- State: closed
- Created 3 years ago
- Reactions: 1
- Comments: 82 (81 by maintainers)
@Bluejanis could you please open another issue? This way we might be able to spot the issue faster (by looking at your configuration). They may have been in a regression somewhere (although I cannot think of a PR that may have introduced the regression). Nevertheless, worth investigating.
@casperklein
Disagree. Different distros suggest a single label hostname, while others suggest the full FQDN.
hostname -swill provide you the single label (short hostname) should you need it,hostnamethe value of/proc/sys/kernel/hostname, andhostname -fthe response from querying the hostname to/etc/hostsor if failing external DNS.Where it matters is how any software may interact with such. I know Postfix can use this implicitly (along with domainname I think), but it can also be explicitly configured instead.
Do you have any resource that says that’s not how it should be used? I’ve got resources that say the hostname can effectively be an FQDN, and that domainname is intended for legacy NIS domain usage, not DNS domain.
/etc/hostswill be given an entry (provided not using host network mode), that concatenates/proc/sys/kernel/{hostname,domainname}together (if domainname isn’t(none)), and thehostname -s(1st label) from hostname as an alias. In most cases that should result in an FQDN that you’d expect andhostname -fwill return that,hostname -dwill also return that same value minus the 1st label. See response below to @georglauterbach for more details.While that FQDN in
/etc/hostsmay not change, it does change behaviour in hostname used to query. This can cause problems when hostname is multi-label but a domainname also exists, and especially weird in the case ofexample.combeing assigned to both. Both of those kinds of config are unlikely used in practice though (with the earlier mentioned exception).@andrewlow
While I don’t disagree, if you have a mail-server that uses
mail.mydomain.cabut sends emails with headersmydomain.ca(maillabel stripped), coulddocker-mailserverupon interacting with either handle them differently, even if it’s responsible for both?mailandmail.mydomain.cawill resolve as the local container IP, and services should therefore know in the container that it’s local. But anymydomain.caquery will fail to match in/etc/hostswithout that alias, thus query public DNS for IP. Is that the expected outcome or could that be a potential issue?@georglauterbach they both reflect the
domainnamethat the Docker CLI ordocker-compose.ymlcan set. @andrewlow has this set as our docs generally advise this setup, but I’m also of the understanding that it’s probably not what we want.Regarding
hostname,dnsdomainnameanddomainnamecommands. Each has specific default output, but the-s,-d,-foptions for all of them will output the same value.domainnamedefault output is not the same as any-doutput, it maps to/proc/sys/kernel/domainname.dnsdomainnamehas nothing of value to offer to my knowledge.hostname -sat least on Debian actually can differ vs the other two commands, and output the 1st label from/proc/sys/kernel/hostnamedirectly instead, not the 1st label of the returned entry (after IP) from a match in/etc/hostswhich the other two commands do.-dand-foptions on all three commands also operate on/etc/hostslike this (with the value of/proc/sys/kernel/hostname), unless they fail to match and instead attempt to do an external DNS query./etc/hoststo be completely unrelated to your actual FQDN, you’ll find-doutputs that value minus the first label, and-foutputs that FQDN, all that was required was a match on the hostname via alias (if you only set hostname and not domainname however, this isn’t likely to match now as the FQDN is missing, add it to the/etc/hostsline as a separate alias and you’ll see it return/operate on that 1st unrelated FQDN).This was all covered in findings noted here. Of which maintainers have probably read me repeat multiple variations of 😅 (just repeating in this issue for context)
yes
I don’t know, I’ve never tried that. That’s not how it should be used (technical possible, of course). I did a quick test, and there is no difference in the generated
/etc/hostsfile, when using a FQDN as hostname and omitting domainname. Howeverhostnameand/proc/sys/kernel/hostnameare returning a FQDN then.That makes no sense.
Nice Blogpost! - I see you encountered issues whilst setting up relay with SES. Feel free to provide a documentation update! @docker-mailserver/maintainers what about a section in docs linking blog posts and tutorials?
I’m still poking at this - no conclusions yet.
I modified my setup to have additional dovecot logging
I added to
/etc/dovecot/dovecot.confThis results in additional dovecot logging - it’s not really a different story than previously, but it does provide some insight into where dovecot is triggered. Maybe I need more debug logs from
smtpdThe first log from dovecot
The bad lookup starts here
The first time we see the alias mapped
Mails are delivered, so this seems only a small cosmetic issue. Possibly, it’s just an option wrongly set somewhere. Before knowing the cause, I can’t decide if the code is not clean (and needs a re-write). In best case, only a small bugfix is needed 😉
I can confirm the problem. I see the same
Jul 21 11:41:40 mail dovecot: auth: passwd-file(foo@exmaple): unknown usermessage in my setup, when receiving an email for an alias.I never noticed that before 😕
Interesting. you’re right indeed. The file is processed:
https://github.com/docker-mailserver/docker-mailserver/blob/fb77d3f7210ff4501f454020809a72704a350d48/target/scripts/startup/setup-stack.sh#L728-L734
But I’m uncertain as to how we proceed later with it. As you said, the e-mail bounced. I’d go with
postfix-virtual.cfunderconfig/instead.I really don’t think so, because I’m going through
postfix-virtual.cf, notpostfix-aliases.cf. This just goes to show that our code-base could use some improvements in this regard:)You’re welcome 😃
Might be a slight misunderstanding in what I was saying there.
Some services like Postfix to my knowledge can treat a local host differently than an external one. I don’t know when that is the case, so it’s just an assumption that when this applies, if an external DNS request is made when it would have been intended to match
/etc/hosts, then that local host (notlocalhost) behaviour would not occur and it may instead treat it as if handling an external connection (imagine two separate servers you control).Yeah probably, so it might only apply to niche features that most users don’t use or niche / invalid configurations.
From @georglauterbach:
There is certainly something about the
postfix-aliases.cf- I map a./configfile into the/tmp/docker-mailserveras part of the container deployment. That file was created on my behalf by docker-mailserver. It is normally empty.I thought, why not add a ‘local’ alias there? So I did. Changing that file to look like this:
This resulted in this appearing in
/etc/aliasesCool I thought - but tried to send email from gmail -> mydomain.ca and it bounced…
The bounce makes me think that the patch you’re putting together @georglauterbach will probably fix this - but it also means that you’re right that this is a bit of a mess.
I do appreciate you pointing me (and others) at the location to start investigating how we might improve upon the alias handling in docker-mailsever. I will try to take a look, but this is probably a bit beyond my current email knowledge.
From @polarathene :
This is certainly something to consider. I would think that many users of docker-mailserver would have the same issue. From an external DNS point of view - both
mail.mydomain.caandmydomain.caneed to resolve to the external IP you have. Thus if this is a potential issue, I think it’s something many people will have.I haven’t found anything on that considering our documentation on extra configuration files. AFAIK
/etc/aliasesreally actually is a mess, not by default, just in the way we use it I guess, because it is sometimes used, sometimes not. This section would actually need cleanup. We had issues addressing this problem in the past.But from I can read here:
It seems we should do a proper cleanup of the scripts and make use of
/etc/aliasesis a proper way. This would be very much fine with me. The confusion at the moment stems from the fact that aliases are scattered all over the place, and my PR does not do a very good job at improving on the situation other than curing symptoms. But at the same time, I simply don’t have the time anymore to go through the scripts and solve this problem of cleaning up the code. Until someone addresses this issue, my PR could be a solution for the time being.@andrewlow I would love to see some work being done on the aliases. All users would profit from these changes. If you wan’t to try it, I’d suggest having a look here:
https://github.com/docker-mailserver/docker-mailserver/blob/fb77d3f7210ff4501f454020809a72704a350d48/target/scripts/startup/setup-stack.sh#L683-L736
and here
https://github.com/docker-mailserver/docker-mailserver/blob/fb77d3f7210ff4501f454020809a72704a350d48/target/scripts/check-for-changes.sh#L81-L87
On the topic of Dovecot issues:
/etc/dovecot/userdbI don’t understand WHY we would add anything for virtual aliases into this file - unless there is something ‘not quite virtual’ about an alias that is specified as
alias@example.com user@example.combecause they both share the same domain and thus should be local.All along it’s felt like dovecot shouldn’t get a shot at looking at the email until we’ve decided who the email is supposed to be for. My logic says that the alias mappings should happen before we attempt local delivery.
I also question why
config/postfix_aliases.cfis empty, shouldn’t we be specifying local aliases there? My setup uses virtual aliases because that’s what the doc points me at.Of course – this suggest I should try adding some new aliases to my configuration in
config/postfix_aliases.cfto see if this helps remedy the problem for those new aliases.If the tone of this is wrong - please forgive me. I just am eager to understand how this is supposed to work.
DNS First
I would like to provide my DNS setup here too, just to give a K8s example that works.
Now Dovecot’s Issues
The Dovecot issue has (at least to my knowledge) nothing to do with DNS / hostnames. The issue is rather simple: Dovecot tries to look up users in
/etc/dovecot/userdb, and because we never add aliases there, Dovecot cannot find them and showsdovecot: auth: passwd-file(...): unknown user. I’m currently working towards adding these users to the Dovecot userdb with the correct directories of the account the alias points to. Tests seem to indicate that there are still some problems. I foundtarget/dovecot/auth-passwdfile.incto be misconfigured as well. I will fix this too.Dear lord I think I’m up to something… will post soon again.False alarm, damn it.So, I can finally present a solution. I’ll have something to eat beforehand, and provide a PR so all of you can have a look.
@polarathene I will try to adjust my K8s setup too to see whether this helps! I currently have an old value under
/etc/hostnamewhich, as you said, may contribute to the problem.run repeat_until_success_or_timeout 20 sh -c "docker logs mail_alisa | grep 'THIS WILL FAIL'"There is a typo.
mail_alisashould bemail_alias.Time certainly seems to be zooming along here.
I am also not that familiar as I want with postfix & dovecot. That’s why I chose initially this project as my mail setup (to get it working, without knowing each configuration detail in advance) 😄
The good thing however with that issue is, beside the log entrys, there seems no other negative impact.
At least, the newest dovecot version which I am running does not fix it. Or did you mean postfix? I couldn’t find big changes in the changelog, between the postfix versions in debian buster (3.4.14) and bullseye (3.5.6) . Most of them are TLS fixes.
My particular configuration has always exhibited this problem - reference the top post in this issue
I also documented my setup here: https://lowtek.ca/roo/2021/installing-docker-mailserver/
A single container should work - I have not tried to create a test bed environment, but that would be a very good idea.
What is weird - from my (naive) digging into this - is that is appears dovecot is invoked too early in the process. Like - why does the mail system try ‘local’ mail delivery of the email, before mapping the email via the aliases?
It is also a little suspicious - that while I’m hosting a single domain - (mydomain.ca) I am using virtual aliases to configure email aliases (foo@mydomain.ca -> reallyme@mydomain.ca). In my past setups (not using this project) - I used the
/etc/aliasesfile and didn’t need to specify the domains in my alias file. I’m not sure that this isn’t a factor.As of yet, no.
No, it seems to appear with Docker, Docker Compose and K8s, platform independent. One container suffices. You’ll need to have aliases set up.
I thought about this too. But then, maybe Dovecot has aliases like Postfix too? We’re not generating them if they’re needed… which could be the problem.
Unfortunately not. But I am also very interested to track that down / fix that issue. If there is anything I can test etc., just let me know.
Actually @georglauterbach please assign #2108 to me, this one - I still don’t know how to solve.
However - once more people have correctly configured logwatch – they will start seeing the alias/dovecot login failures every day.
I think I figured out what is wrong with
logwatchhttps://github.com/docker-mailserver/docker-mailserver/issues/2108I just recently started using aliases (three days ago) and haven’t since looked back at the logs. I will raise the priority of this issue. Since it does not seem to affect operation, medium priority suffices.
However, this goes to show that the alias code is not as clean as we‘d like, and a re-write is actually necessary. @andrewlow would you be willing to help us tackle this? @casperklein @wernerfred @polarathene do you agree that aliases need a code overhaul / rewrite?