Why is Postfix trying to connect to other machines SMTP port 25

postfixsmtp

I get these errors:

Jul  5 11:09:25 relay postfix/smtp[3084]: connect to ab.xyz.com[10.41.0.101]:25: Connection refused
Jul  5 11:09:25 relay postfix/smtp[3087]: connect to ab.xyz.com[10.41.0.247]:25: Connection refused
Jul  5 11:09:25 relay postfix/smtp[3088]: connect to ab.xyz.com[10.41.0.101]:25: Connection refused
Jul  5 11:09:25 relay postfix/smtp[3084]: connect to ab.xyz.com[10.41.0.247]:25: Connection refused
Jul  5 11:09:25 relay postfix/smtp[3087]: connect to ab.xyz.com[10.41.0.110]:25: Connection refused
Jul  5 11:09:25 relay postfix/smtp[3088]: connect to ab.xyz.com[10.41.0.110]:25: Connection refused
Jul  5 11:09:25 relay postfix/smtp[3084]: connect to ab.xyz.com[10.41.0.102]:25: Connection refused
Jul  5 11:09:30 relay postfix/smtp[3085]: connect to ab.xyz.com[10.41.0.102]:25: Connection refused
Jul  5 11:09:30 relay postfix/smtp[3086]: connect to ab.xyz.com[10.41.0.247]:25: Connection refused
Jul  5 11:09:30 relay postfix/smtp[3086]: connect to ab.xyz.com[10.41.0.102]:25: Connection refused
Jul  5 11:09:55 relay postfix/smtp[3087]: connect to ab.xyz.com[10.40.40.130]:25: Connection timed out
Jul  5 11:09:55 relay postfix/smtp[3084]: connect to ab.xyz.com[10.40.40.130]:25: Connection timed out
Jul  5 11:09:55 relay postfix/smtp[3088]: connect to ab.xyz.com[10.40.40.130]:25: Connection timed out
Jul  5 11:09:55 relay postfix/smtp[3087]: connect to ab.xyz.com[10.41.0.135]:25: Connection refused
Jul  5 11:09:55 relay postfix/smtp[3084]: connect to ab.xyz.com[10.41.0.110]:25: Connection refused
Jul  5 11:09:55 relay postfix/smtp[3088]: connect to ab.xyz.com[10.41.0.247]:25: Connection refused

Is this a DNS thing, doubtful as I've changed from our local DNS to Google's..still Postfix will occasionally try and connect to ab.xyz.com from a variety of addresses that may or may not have port 25 open and act as mail servers to begin with.

Why is Postfix attempting to connect to other machines as seen in the log?

  • Mail is being sent properly, other than that, it appears all is good.

Occasionally I'll also see:

relay postfix/error[3090]: 3F1AB42132: to=,
relay=none, delay=32754, delays=32724/30/0/0, dsn=4.4.1,
status=deferred (delivery temporarily suspended: connect to
ab.xyz.com[10.41.0.102]:25: Connection refused)

I have Postfix setup with very little restrictions:

mynetworks = 127.0.0.0/8, 10.0.0.0/8

only. Like I said it appears all mail is getting passed through, but I hate seeing errors and it is confusing me as to why it would be attempting to connect to other machines as seen in the log.

Some Output of cat /var/log/mail.log|grep 3F1AB42132

Jul 5 02:04:01 relay postfix/smtpd[1653]: 3F1AB42132:
client=unknown[10.41.0.109]

Jul 5 02:04:01 relay postfix/cleanup[1655]: 3F1AB42132:
message-id=

Jul 5 02:04:01 relay postfix/qmgr[1588]: 3F1AB42132:
from=, size=3404, nrcpt=1 (queue active)

Jul 5 02:04:31 relay postfix/smtp[1634]: 3F1AB42132:
to=, relay=none, delay=30,
delays=0.02/0/30/0, dsn=4.4.1, status=deferred (connect to
ab.xyz.com[10.41.0.110]:25: Connection refused)

Jul 5 02:13:58 relay postfix/qmgr[1588]: 3F1AB42132:
from=, size=3404, nrcpt=1 (queue active)

Jul 5 02:14:28 relay postfix/smtp[1681]: 3F1AB42132:
to=, relay=none, delay=628,
delays=598/0.01/30/0, dsn=4.4.1, status=deferred (connect to
ab.xyz.com[10.41.0.247]:25: Connection refused)

Jul 5 02:28:58 relay postfix/qmgr[1588]: 3F1AB42132:
from=, size=3404, nrcpt=1 (queue active)

Jul 5 02:29:28 relay postfix/smtp[1684]: 3F1AB42132:
to=, relay=none, delay=1527,
delays=1497/0/30/0, dsn=4.4.1, status=deferred (connect to
ab.xyz.com[10.41.0.135]:25: Connection refused)

Jul 5 02:58:58 relay postfix/qmgr[1588]: 3F1AB42132:
from=, size=3404, nrcpt=1 (queue active)

Jul 5 02:59:28 relay postfix/smtp[1739]: 3F1AB42132:
to=, relay=none, delay=3327,
delays=3297/0/30/0, dsn=4.4.1, status=deferred (connect to
ab.xyz.com[10.40.40.130]:25: Connection timed out)

Jul 5 03:58:58 relay postfix/qmgr[1588]: 3F1AB42132:
from=, size=3404, nrcpt=1 (queue active)

Jul 5 03:59:28 relay postfix/smtp[1839]: 3F1AB42132:
to=, relay=none, delay=6928,
delays=6897/0.03/30/0, dsn=4.4.1, status=deferred (connect to
ab.xyz.com[10.41.0.101]:25: Connection refused)

Jul 5 04:11:03 relay postfix/qmgr[2039]: 3F1AB42132:
from=, size=3404, nrcpt=1 (queue active)

Jul 5 04:11:33 relay postfix/error[2093]: 3F1AB42132:
to=, relay=none, delay=7653,
delays=7622/30/0/0, dsn=4.4.1, status=deferred (delivery temporarily
suspended: connect to ab.xyz.com[10.41.0.101]:25: Connection refused)

Jul 5 05:21:03 relay postfix/qmgr[2039]: 3F1AB42132:
from=, size=3404, nrcpt=1 (queue active)

Jul 5 05:21:33 relay postfix/error[2217]: 3F1AB42132:
to=, relay=none, delay=11853,
delays=11822/30/0/0, dsn=4.4.1, status=deferred (delivery temporarily
suspended: connect to ab.xyz.com[10.41.0.101]:25: Connection refused)

Jul 5 06:29:25 relay postfix/qmgr[2420]: 3F1AB42132:
from=, size=3404, nrcpt=1 (queue active)

Jul 5 06:29:55 relay postfix/error[2428]: 3F1AB42132:
to=, relay=none, delay=15954,
delays=15924/30/0/0.08, dsn=4.4.1, status=deferred (delivery
temporarily suspended: connect to ab.xyz.com[10.41.0.101]:25:
Connection refused)

Jul 5 07:39:24 relay postfix/qmgr[2885]: 3F1AB42132:
from=, size=3404, nrcpt=1 (queue active)

Jul 5 07:39:54 relay postfix/error[2936]: 3F1AB42132:
to=, relay=none, delay=20153,
delays=20123/30/0/0, dsn=4.4.1, status=deferred (delivery temporarily
suspended: connect to ab.xyz.com[10.40.40.130]:25: Connection timed
out)

Best Answer

Most likely they are wrong email addresses or your DNS resolution is failing.

Postfix will try to connect to the SMTP server according to the MX record of the ab.xyz.com domain to deliver the email, but if Postfix cannot find a MX record, it will attempt to deliver to the IP of the A record. (That's the expected behavior).

But if the email address domain is wrong (miss-typed, for example) the domain may exist but maybe does not have a MX record and the IP from the A record is a host without a SMTP server.

As an example, some people around here type myaddress@hotmail.com.mx (the correct address is myaddress@hotmail.com), however the hotmail.com.mx domain indeed exists but does not have an MX record, so Postfix tries, and tries, and tries to deliver to an A record host who will never answer at port 25, causing log entries like:

Jul  5 17:03:37 www postfix/smtp[3149]: 6608A108FD2: to=<xyz@hotmail.com.mx>, relay=none, delay=197971, delays=197971/0.02/0.18/0, dsn=4.4.1, status=deferred (connect to hotmail.com.mx[200.94.181.9]:25: Connection refused)