On 3/9/2020 9:09 PM, Jay wrote:
Hi folks,
I’m having a strange situation on one of my macOS X Servers
(10.13.6) running postfix 3.1.1.
The server is configured to only use virtual_domains and virtual.
When an email is received externally on port 25 for one of those
domains, it’s accepted and handed off to Dovecot happily. All such
received mail works perfectly. Here is a log excerpt of a successful
receipt:
2020-03-10 11:53:47.417928+1000 0x3afa0e Info 0x0
96460 smtpd: connect from office.externaldomain.com.au
<http://office.externaldomain.com.au>[203.1.1.1]
2020-03-10 11:53:47.985328+1000 0x3afa0e Info 0x0
96460 smtpd: F075E1803D04:
client=office.externaldomain.com.au
<http://office.externaldomain.com.au>[203.1.1.1]
2020-03-10 11:53:48.001337+1000 0x3afdd7 Info 0x0
96498 cleanup: F075E1803D04:
message-id=<968781c4-1a74-42be-b4ce-141ea65e9...@externaldomain.com.au
<mailto:968781c4-1a74-42be-b4ce-141ea65e9...@externaldomain.com.au>>
2020-03-10 11:53:48.005938+1000 0x35759a Info 0x0
74101 qmgr: F075E1803D04: from=<j...@externaldomain.com.au
<mailto:j...@externaldomain.com.au>>, size=859, nrcpt=1 (queue active)
2020-03-10 11:53:48.032335+1000 0x3afa0e Info 0x0
96460 smtpd: disconnect from office.externaldomain.com.au
<http://office.externaldomain.com.au>[203.1.1.1] ehlo=2 starttls=1
mail=1 rcpt=1 data=1 quit=1 commands=7
2020-03-10 11:53:49.699136+1000 0x3b00c5 Info 0x0
96565 smtpd: connect from localhost[127.0.0.1]
2020-03-10 11:53:49.702840+1000 0x3b00c5 Info 0x0
96565 smtpd: AB8771803D0F: client=localhost[127.0.0.1]
2020-03-10 11:53:49.705075+1000 0x3afdd7 Info 0x0
96498 cleanup: AB8771803D0F:
message-id=<968781c4-1a74-42be-b4ce-141ea65e9...@externaldomain.com.au
<mailto:968781c4-1a74-42be-b4ce-141ea65e9...@externaldomain.com.au>>
2020-03-10 11:53:49.705801+1000 0x3b00c5 Info 0x0
96565 smtpd: disconnect from localhost[127.0.0.1] ehlo=1
mail=1 rcpt=1 data=1 quit=1 commands=5
2020-03-10 11:53:49.706072+1000 0x35759a Info 0x0
74101 qmgr: AB8771803D0F: from=<j...@externaldomain.com.au
<mailto:j...@externaldomain.com.au>>, size=1555, nrcpt=1 (queue active)
2020-03-10 11:53:49.719987+1000 0x3b006e Info 0x0
96562 smtp: F075E1803D04: to=<j...@home.myvirtualdomain.com
<mailto:j...@home.myvirtualdomain.com>>,
orig_to=<j...@myvirtualdomain.com
<mailto:j...@myvirtualdomain.com>>, relay=127.0.0.1[127.0.0.1]:10024,
delay=2.1, delays=0.36/0/0/1.7, 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 AB8771803D0F)
2020-03-10 11:53:49.720777+1000 0x35759a Info 0x0
74101 qmgr: F075E1803D04: removed
2020-03-10 11:53:49.825969+1000 0x35759a Info 0x0
74101 qmgr: AB8771803D0F: removed
However, when I use the `mail` command on the server, specifically
`mail j...@myvirtualdomain.com <mailto:j...@myvirtualdomain.com>`, I
get a mail loops back to itself error:
2020-03-10 11:55:43.060996+1000 0x3b04ce Info 0x0
96627 cleanup: 061A21803DE0:
message-id=<20200310015543.061a21803...@home.myvirtualdomain.com
<mailto:20200310015543.061a21803...@home.myvirtualdomain.com>>
2020-03-10 11:55:43.062048+1000 0x3b04cb Info 0x0
96626 qmgr: 061A21803DE0:
from=<r...@home.myvirtualdomain.com
<mailto:r...@home.myvirtualdomain.com>>, size=338, nrcpt=1 (queue
active)
2020-03-10 11:55:43.972784+1000 0x3afa0e Info 0x0
96460 smtpd: connect from home.myvirtualdomain.com
<http://home.myvirtualdomain.com>[10.0.5.201]
2020-03-10 11:55:43.973557+1000 0x3b04d3 Default 0x0
96629 smtp: warning: host home.myvirtualdomain.com
<http://home.myvirtualdomain.com>[10.0.5.201]:25 greeted me with my
own hostname home.myvirtualdomain.com <http://home.myvirtualdomain.com>
2020-03-10 11:55:43.974021+1000 0x3b04d3 Default 0x0
96629 smtp: warning: host home.myvirtualdomain.com
<http://home.myvirtualdomain.com>[10.0.5.201]:25 replied to
HELO/EHLO with my own hostname home.myvirtualdomain.com
<http://home.myvirtualdomain.com>
2020-03-10 11:55:44.013568+1000 0x3b04d3 Info 0x0
96629 smtp: 061A21803DE0: to=<j...@myvirtualdomain.com
<mailto:j...@myvirtualdomain.com>>, relay=home.myvirtualdomain.com
<http://home.myvirtualdomain.com>[10.0.5.201]:25, delay=1.5,
delays=0.59/0.04/0.87/0, dsn=5.4.6, status=bounced (mail for
myvirtualdomain.com <http://myvirtualdomain.com> loops back to myself)
2020-03-10 11:55:44.013989+1000 0x3afa0e Info 0x0
96460 smtpd: disconnect from home.myvirtualdomain.com
<http://home.myvirtualdomain.com>[10.0.5.201] ehlo=1 quit=1 commands=2
2020-03-10 11:55:44.015809+1000 0x3b04ce Info 0x0
96627 cleanup: 039A91803DE7:
message-id=<20200310015544.039a91803...@home.myvirtualdomain.com
<mailto:20200310015544.039a91803...@home.myvirtualdomain.com>>
2020-03-10 11:55:44.016665+1000 0x3b04cb Info 0x0
96626 qmgr: 039A91803DE7: from=<>, size=2383, nrcpt=1
(queue active)
2020-03-10 11:55:44.017420+1000 0x3b04cb Info 0x0
96626 qmgr: 061A21803DE0: removed
This is preventing all automated system emails from being delivered.
The DNS is seemingly correct. The relevant myvirtualdomain.com
<http://myvirtualdomain.com> is defined in virtual_domains. I’m
assuming that the fact that everything works via smtp indicates that
the configuration is correct?
Is this even a postfix config issue? Or is it possibly a problem
somewhere else, i.e. with the `mail` command? Where can I begin to
look to troubleshoot this further? What configuration info can I
provide that might help? A full dump of `postconf -n`? All of master.cf?
Thank you,
Jay
Turn off debug logging and start here:
http://www.postfix.org/DEBUG_README.html#mail
-- Noel Jones
