11

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)

rubo77
  • 2,469
  • 4
  • 34
  • 66
TryTryAgain
  • 1,152
  • 5
  • 22
  • 41
  • 2
    can you paste more logs - "cat /var/log/mail.log|grep 3F1AB42132" can be helpful – pQd Jul 05 '12 at 18:47
  • 1
    pQd's command will get you the `To:` and `From:` addresses which will probably be enough to answer your question. – Ladadadada Jul 05 '12 at 18:50
  • 1
    Maybe you have an entry in /etc/hosts which overwrite the DNS resolve ? The think is from what I can see that some of the local clients (10.41.0.109) is trying to send some email to ab.xyz.com and your smtp servers resolve that IP to 10.41.0.101. What is the output of `nslookup ab.xyz.com` on your smtp server ? Btw MX records for ab.xyz.com points to gmail. – golja Jul 06 '12 at 02:27
  • @golja exactly right! So I will have to clean up DNS. Thanks for pointing that out...nslokup resolves 10.41.0.109 – TryTryAgain Jul 06 '12 at 14:53

2 Answers2

14

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)
Gryu
  • 499
  • 1
  • 6
  • 14
MV.
  • 766
  • 7
  • 11
2

Additional things to check for when you are seeing logs like this are,

myhostname and mydestination need to be set correctly in /etc/postfix/main.cf

Won Jun Bae
  • 121
  • 3