3

I am running Ubuntu 10.04 with Sendmail in a VMWare VM. In my mail.log file I have thousands of Connection Refused errors, and I'd like to get rid of them. There are multiple errors each second and I'm convinced this problem is causing some of our legit email to not be sent.

Example:

Jul 13 08:20:02 mail sm-msp-queue[28076]: s6C3K6e0008595: to=root, ctladdr=smmsp (115/126), delay=1+08:59:56, xdelay=00:00:00, mailer=relay, pri=8940371, relay=[127.0.0.1] [127.0.0.1], dsn=4.0.0, stat=Deferred: Connection refused by [127.0.0.1]
Jul 13 08:20:02 mail sm-msp-queue[28076]: s6C3K19D008593: to=smmsp, delay=1+08:59:58, xdelay=00:00:00, mailer=relay, pri=8941647, relay=[127.0.0.1] [127.0.0.1], dsn=4.0.0, stat=Deferred: Connection refused by [127.0.0.1]
Jul 13 08:20:02 mail sm-msp-queue[28076]: s6D2K2lX023270: to=postmaster, delay=09:59:56, xdelay=00:00:00, mailer=relay, pri=9331939, relay=[127.0.0.1] [127.0.0.1], dsn=4.0.0, stat=Deferred: Connection refused by [127.0.0.1]
Jul 13 08:20:02 mail sm-msp-queue[28076]: s6C7e3Cp010618: to=postmaster, delay=1+04:39:47, xdelay=00:00:00, mailer=relay, pri=9754324, relay=[127.0.0.1] [127.0.0.1], dsn=4.0.0, stat=Deferred: Connection refused by [127.0.0.1]
Jul 13 08:20:02 mail sm-msp-queue[28076]: s6BNe474006871: to=root, ctladdr=smmsp (115/126), delay=1+12:39:58, xdelay=00:00:00, mailer=relay, pri=9930371, relay=[127.0.0.1] [127.0.0.1], dsn=4.0.0, stat=Deferred: Connection refused by [127.0.0.1]
Jul 13 08:20:02 mail sm-msp-queue[28076]: s6CMK1lb021417: to=root, delay=13:59:57, xdelay=00:00:00, mailer=relay, pri=10410356, relay=[127.0.0.1] [127.0.0.1], dsn=4.0.0, stat=Deferred: Connection refused by [127.0.0.1]
Jul 13 08:20:02 mail sm-msp-queue[28076]: s6BLK2Bk005641: to=postmaster, delay=1+14:59:56, xdelay=00:00:00, mailer=relay, pri=10571717, relay=[127.0.0.1] [127.0.0.1], dsn=4.0.0, stat=Deferred: Connection refused by [127.0.0.1]
Jul 13 08:20:02 mail sm-msp-queue[28076]: s6BK01i9004244: to=postmaster, delay=1+16:20:00, xdelay=00:00:00, mailer=relay, pri=10926911, relay=[127.0.0.1] [127.0.0.1], dsn=4.0.0, stat=Deferred: Connection refused by [127.0.0.1]`

I've read where a potential problem is sendmail is not listening on port 25, so I ran this command

# sudo netstat -a -n -p |grep 0.0.0.0:25
tcp        0      0 0.0.0.0:25                  0.0.0.0:*               LISTEN      1137/sendmail: MTA:`

I have also tried changing the lines:

DAEMON_OPTIONS('Name=MTA, Addr=127.0.0.1, Port=smtp')dnl`
DAEMON_OPTIONS('Name=MSP, Addr=127.0.0.1, Port=submission')dnl`

in my sendmail.mc and rebuilding the sendmail config, but I was unable to send email at all when I did that.

I'm attaching a copy of my hosts file as well, since I am not 100% sure that it is correct.

127.0.0.1 example.org localhost localhost.localdomain mail.example.org.localdomain`
10.1.1.204 example.org mail.example.org mail.example.ci.oh.us mail-server`

Our mail server 'mail.example.org' handles all relayed mail from our web server 'example.org' This part always confuses me, but it was set up this way when I took over managing these servers.

Thanks for any help and let me know if you need me to post anything else. I'll do whatever I have to in order to fix these errors.

user671460
  • 45
  • 1
  • 2
  • 7
  • The error message `Connection refused by [127.0.0.1]` is consistent with sendmail not running. What do you see when you make a telnet connection to port 25? – HBruijn Jul 18 '14 at 15:26
  • @HBruijn `Connected to domain.org` `220 domain.org ESMTP Sendmail 8.14.3/8.14.3/Debian-9.1ubuntu1; Fri, 18 Jul 2014 12:20:29 -0400; (No UCE/UBE) logging access from: domain.org(OK)-domain.org [127.0.0.1]` – user671460 Jul 18 '14 at 16:43

2 Answers2

3

Have you searched sendmail logs for rejecting connections ...?
Sendmail may refuse to accept incoming connections when system load average is too high.

Check number of message in "client queue" (mailq -Ac) - in some cases such problems have been caused by huge number of spam messages in client queue e.g. due to hosted/hacked "spam friendly" web pages.
How to read HUGE clientmqueue in human format?

You may increase "refuse Load Average" from default 12 using the following line in your sendmail.mc file: 

define(`confREFUSE_LA',`20')

"Sendmail Performance Tuning" by Nick Christenson (page 139) talks about setting it between 12 and 20 on dedicated non Linux server and even higher on dedicated Linux server. [Linux calculates Load Average in a different way]

Sendmail-8.14.0 introduced option to set it as DaemonPortOptions parameter. You may use it to set different refuseLA for loopback (127.0.0.1), internal and public IP addresses.

AnFi
  • 6,103
  • 1
  • 14
  • 27
  • Thanks for the suggestion and link. After searching the log, this is displayed: `Jul 17 05:18:02 mail sm-mta[21706]: rejecting connections on daemon MTA: load average: 24` `Jul 17 05:18:17 mail sm-mta[21706]: rejecting connections on daemon MTA: load average: 25` `Jul 17 05:18:34 mail sm-mta[21706]: rejecting connections on daemon MTA: load average: 26` `Jul 17 05:18:49 mail sm-mta[21706]: rejecting connections on daemon MTA: load average: 27` `Jul 17 05:19:04 mail sm-mta[21706]: rejecting connections on daemon MTA: load average: 28` – user671460 Jul 18 '14 at 18:03
  • Have you tried to find out source of the high load? Which sendmail version do you use? [I do not use ubuntu] – AnFi Jul 18 '14 at 20:36
  • 1
    BTW do you trace/log Load Average on your system? Which values do you consider normal? [sendmail's defaults may be too low for SOME systems] – AnFi Jul 18 '14 at 20:43
  • I am running Version 8.14.3 of Sendmail. I do not have any way to view historical information of the load average. I may try installing SAR later today. This VM runs on a fairly powerful server and does very little work, so the load average stays down MOST of the time.. My load averages now are: Load average: `0.01 0.05 0.07` Wordpress makes Apache cause the high server load. I have eliminated most of the load problems by installing caching software for Wordpress, but it still happens occasionally for logged-in users (viewing dynamic content). – user671460 Jul 21 '14 at 12:55
  • Does your server have one non loopback (127.0.0.1) IP address? – AnFi Jul 21 '14 at 15:07
  • Yes, there is only one loopback address. It has a real world IP, and an internal IP also, if that matters. – user671460 Jul 21 '14 at 19:23
  • I have added instruction how to increase "Refuse Load Average" globally of per specific IP interface (listening address). – AnFi Jul 24 '14 at 04:32
0

It appears that the messages are being deferred, so it may be that you have some messages in the queue that are being retried over and over again. Take a look at your queue (mailq) to see if that may be the case.

You can look at individual messages in your queue: Go to the queue directory and you will have two files for every email, one starting with df* and the other with qf*. Combined they compose the entire message (one contains information in regards to the queue details, the other the email content... yes purposely simplified explanation :-) ). If you look at the details and decide you want to remove the message from the queue, you can just delete both files for the same queue ID. Alternatively, you could move all the files to another directory which would remove them from the queue, where you could then look through at your leisure and move back any you actually want to try and resend (I have never run into a queue ID problem doing so.. but naturally you are stepping in the middle of a the normal sendmail process by doing this).

If they are legitimate and need to be retried, perhaps you may need to tweak the retry settings in your sendmail config so that they are tried less often (both frequency and total time retried before giving up and generating an NDR). I will leave that exercise of looking through those settings to you (easy to find in the config itself, or with a basic web search).

Determining what the messages are is the first step of course so you can see if something is filling up your queue, or simply retrying to send bad email, etc.

As for the web server relaying through the mail server that is not that uncommon. Typically having only one egress point for mail makes it easier to manage things like your SPF records, etc. Normal caution to make sure your web server is not compromised and turns you into a spammer (as your mail server will relay anything it sends) are of course warranted.

Lastly, the only way I would normally envision those retries/connections affecting legitimate email is if you are dealing with a queue that is large enough so that legitimate emails are left waiting for retries. This is typically not the case as a new email will be tried first in the queue... however if it is deferred for a normal legitimate reason then it would have to work its way through the normal queue retry.

Addition: In looking at your log entry, it provides the queue ID. So for example if the entry of "s6C3K6e0008595" is still in your queue, you will have a qfs6C3K6e0008595 and dfs6C3K6e0008595 file that you can examine.

SendMail
  • 1
  • 1
  • Nice description of how the sendmail queue works, but this doesn't address primary cause of the ` stat=Deferred: Connection refused by [127.0.0.1]` error messages. – HBruijn Jul 18 '14 at 15:05
  • Agreed whole-heartedly. Analyzing the individual messages (assuming/if they are in the queue) would however show a deferral reason and/or provide more info. The ultimate goal would be to determine that reason, but the log entry by itself will not be enough in this case. – SendMail Jul 18 '14 at 15:08
  • The /var/spool/mqueue directory is usually empty. The majority of the files are stored in the /var/spool/mqueue-client directory, but it's empty at this time. I manually emptied it this morning. I will analyze and post more information from these files as it's available. I appreciate the help so far! – user671460 Jul 18 '14 at 15:18
  • @SendMail - I viewed the files that were sitting in the queue for the past few days and it appears to be large 50+ MB logs from cron. I disabled emails in crontab and will continue to watch the folder. – user671460 Jul 21 '14 at 12:57