Stops processing email and queue builds up

[Heimir]

Hey,

We have 2 EFA boxes.
From time to time they will stop processing email and the queue starts to build up.
Restarting the mailscanner does not fix it. If I reboot the server it seems to start working.

What should I look for to find the reason for this problem?
I am not familiar with Linux so its a bit of a mystery to me

[DaN]

Hi

We have 2 EFA boxes.

Are they in a row/serial or parallel (two locations/domains)?
Internet -- EFA -- EFA -- Mail Server?

OR

Internet -- EFA -- ...
  |-- EFA -- ...?

Do they have enough memory (>4 GB)?

[Heimir]

Just 2 different gateways.
Internet - gate1 - mail server
-gate2 - mail server

One has 4gb of memory and the other one has 8gb.
the one that stopped processing yesterday had 8gb of memory.

[pdwalker]

How much disk space is free?

[Heimir]

18gb free.

Plenty of package is not updated.
Webmin is 1.690 on both.

[shawniverson]

When you look at free space, are you looking at just the VM or in greater detail?

Run this from a console in EFA:

Code: Select all

sudo df -h

[Heimir]

Filesystem Size Used Avail Use% Mounted on
/dev/mapper/vg_00-lv_root
7.9G 1.8G 5.8G 24% /
tmpfs 3.9G 0 3.9G 0% /dev/shm
/dev/sda1 485M 59M 401M 13% /boot
/dev/mapper/vg_00-lv_tmp
1008M 39M 919M 5% /tmp
/dev/mapper/vg_00-lv_var
21G 8.7G 11G 46% /var
none 3.9G 3.2M 3.9G 1% /var/spool/MailScanner/incoming
//192.168.30.60/transfer
25G 10G 15G 41% /mnt/transfer

Box 2
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/vg_00-lv_root
7.9G 1.8G 5.8G 24% /
tmpfs 1.9G 0 1.9G 0% /dev/shm
/dev/sda1 485M 59M 401M 13% /boot
/dev/mapper/vg_00-lv_tmp
1008M 40M 918M 5% /tmp
/dev/mapper/vg_00-lv_var
21G 8.7G 11G 45% /var
none 1.9G 13M 1.9G 1% /var/spool/MailScanner/incoming
//192.168.30.60/transfer
25G 10G 15G 41% /mnt/transfer

[shawniverson]

That looks fine. Now, are you able to see anything happening in /var/log/maillog or /var/log/messages at the time when the failure occurred that could offer some clues?

Code: Select all

sudo less /var/log/messages
sudo less /var/log/maillog

[pdwalker]

More importantly, what shows up in the logs while the problem is actually happening.

[Heimir]

I dont see anything that stands out in those 2 logs.
But I am not exactly sure what to look for.

I can't see anything that indicates an error.

This is from the messages logs just before the reboot.

May 27 18:19:16 efagate1 freshclam[33951]: daily.cld updated (version: 20513, sigs: 1397959, f-level: 63, builder: neo)
May 27 18:19:16 efagate1 freshclam[33951]: bytecode.cld is up to date (version: 256, sigs: 45, f-level: 63, builder: dgoddard)
May 27 18:19:19 efagate1 freshclam[33951]: Database updated (3822229 signatures) from db.us.clamav.net (IP: 128.199.133.36)
May 27 18:19:19 efagate1 freshclam[33951]: Clamd successfully notified about the update.
May 27 18:19:19 efagate1 clamd[1637]: Reading databases from /var/clamav
May 27 18:19:30 efagate1 clamd[1637]: Database correctly reloaded (4602389 signatures)
May 27 18:29:30 efagate1 clamd[1637]: SelfCheck: Database status OK.
May 27 18:39:31 efagate1 clamd[1637]: SelfCheck: Database status OK.
May 27 18:49:31 efagate1 clamd[1637]: SelfCheck: Database status OK.
May 27 18:54:22 efagate1 clamd[1637]: Reading databases from /var/clamav
May 27 18:54:34 efagate1 clamd[1637]: Database correctly reloaded (4602365 signatures)
May 27 19:04:34 efagate1 clamd[1637]: SelfCheck: Database status OK.
May 27 19:14:29 efagate1 freshclam[36395]: ClamAV update process started at Wed May 27 19:14:29 2015
May 27 19:14:30 efagate1 freshclam[36395]: Your ClamAV installation is OUTDATED!
May 27 19:14:30 efagate1 freshclam[36395]: Local version: 0.98.4 Recommended version: 0.98.7
May 27 19:14:30 efagate1 freshclam[36395]: DON'T PANIC! Read http://www.clamav.net/support/faq
May 27 19:14:30 efagate1 freshclam[36395]: main.cld is up to date (version: 55, sigs: 2424225, f-level: 60, builder: neo)
May 27 19:14:30 efagate1 freshclam[36395]: daily.cld is up to date (version: 20513, sigs: 1397959, f-level: 63, builder: neo)
May 27 19:14:30 efagate1 freshclam[36395]: bytecode.cld is up to date (version: 256, sigs: 45, f-level: 63, builder: dgoddard)
May 27 19:14:34 efagate1 clamd[1637]: SelfCheck: Database status OK.
May 27 19:24:34 efagate1 clamd[1637]: SelfCheck: Database status OK.
May 27 19:27:50 efagate1 clamd[1637]: /var/spool/MailScanner/incoming/37258/16666120195.A21A9.message: Sanesecurity.Scam4.782.UNOFFICIAL FOUND
May 27 19:27:55 efagate1 clamd[1637]: /var/spool/MailScanner/incoming/37296/DBBAD1201AF.AC924.message: PhishTank.Phishing.3223335.UNOFFICIAL FOUND
May 27 19:27:56 efagate1 clamd[1637]: /var/spool/MailScanner/incoming/37296/DBBAD1201AF.AC924/nmsg-37296-44.html: PhishTank.Phishing.3223335.UNOFFICIAL FOUND
May 27 19:28:16 efagate1 clamd[1637]: /var/spool/MailScanner/incoming/37465/D0269120225.AD8E6.message: Heuristics.Phishing.Email.SpoofedDomain FOUND
May 27 19:28:17 efagate1 clamd[1637]: /var/spool/MailScanner/incoming/37465/2D2B6120226.ACAF1.message: Heuristics.Phishing.Email.SpoofedDomain FOUND
May 27 19:28:23 efagate1 clamd[1637]: /var/spool/MailScanner/incoming/37510/137CC120248.A1C8F.message: Sanesecurity.Blurl.aed90e.UNOFFICIAL FOUND
May 27 19:28:35 efagate1 init: tty (/dev/tty1) main process (2021) killed by TERM signal
May 27 19:28:35 efagate1 init: tty (/dev/tty2) main process (2023) killed by TERM signal
May 27 19:28:35 efagate1 init: tty (/dev/tty3) main process (2025) killed by TERM signal
May 27 19:28:35 efagate1 init: tty (/dev/tty4) main process (2027) killed by TERM signal

[shawniverson]

I agree, I don't see anything there per se...

Just out of curiosity, was it the incoming or outgoing queues that were stalled?

[Heimir]

Incoming stalls.

we are not sending anything out from those gateways.
So the only thing going out is whatever that gets bounced like full mail box warning to the sender.

[shawniverson]

Okay, that sounds like a mailscanner problem.

Mailscanner logs to /var/log/maillog. Were you able to see anything wrong in there?

[Heimir]

Dont see anything that stands out there either.

Here is some log snippet just before I restarted the server.
it was over 400 msg queued at that time.

May 27 19:27:26 efagate1 sqlgrey: grey: new: 68.64.175.185(68.64.175.185), 25008-10423825103-1876-marianne=itrg.com@bounce.farbrightdynamic.com. -> marianne@itrg.com
May 27 19:27:26 efagate1 postfix/smtpd[36866]: NOQUEUE: reject: RCPT from unknown[68.64.175.185]: 451 4.7.1 <marianne@itrg.com>: Recipient address rejected: Greylisted for 5 minutes; from=<25008-10423825103-1876-marianne=itrg.com@bounce.farbrightdynamic.com> to=<marianne@itrg.com> proto=ESMTP helo=<love.farbrightdynamic.com>
May 27 19:27:28 efagate1 postfix/smtpd[36866]: disconnect from unknown[68.64.175.185]
May 27 19:27:28 efagate1 postfix/smtpd[36868]: connect from 65hmwrhf.fewery.science[66.248.211.144]
May 27 19:27:28 efagate1 postfix/smtpd[36861]: connect from 65hmwrhf.fewery.science[66.248.211.144]
May 27 19:27:28 efagate1 postfix/smtpd[36865]: connect from 65hmwrhf.fewery.science[66.248.211.144]
May 27 19:27:28 efagate1 postfix/smtpd[36862]: connect from 65hmwrhf.fewery.science[66.248.211.144]
May 27 19:27:29 efagate1 sqlgrey: grey: throttling: 66.248.211(66.248.211.144), restorelosthair@fewery.science -> gleonard@houstonoaks.com
May 27 19:27:29 efagate1 sqlgrey: grey: throttling: 66.248.211(66.248.211.144), jerrywilliams@fewery.science -> jay@houstonoaks.com
May 27 19:27:29 efagate1 postfix/smtpd[36861]: NOQUEUE: reject: RCPT from 65hmwrhf.fewery.science[66.248.211.144]: 451 4.7.1 <gleonard@houstonoaks.com>: Recipient address rejected: Throttling too many connections from new source - Try again later.; from=<RestoreLostHair@fewery.science> to=<gleonard@houstonoaks.com> proto=ESMTP helo=<00877d2b.fewery.science>
May 27 19:27:29 efagate1 postfix/smtpd[36865]: NOQUEUE: reject: RCPT from 65hmwrhf.fewery.science[66.248.211.144]: 451 4.7.1 <jay@houstonoaks.com>: Recipient address rejected: Throttling too many connections from new source - Try again later.; from=<JerryWilliams@fewery.science> to=<jay@houstonoaks.com> proto=ESMTP helo=<00877d2c.fewery.science>
May 27 19:27:29 efagate1 sqlgrey: grey: throttling: 66.248.211(66.248.211.144), jerrywilliams@fewery.science -> hip@houstonincomeproperties.com
May 27 19:27:29 efagate1 sqlgrey: grey: throttling: 66.248.211(66.248.211.144), restorelosthair@fewery.science -> zack@houstonincomeproperties.com
May 27 19:27:29 efagate1 postfix/smtpd[36862]: NOQUEUE: reject: RCPT from 65hmwrhf.fewery.science[66.248.211.144]: 451 4.7.1 <zack@houstonincomeproperties.com>: Recipient address rejected: Throttling too many connections from new source - Try again later.; from=<RestoreLostHair@fewery.science> to=<zack@houstonincomeproperties.com> proto=ESMTP helo=<00877d1d.fewery.science>
May 27 19:27:29 efagate1 postfix/smtpd[36868]: NOQUEUE: reject: RCPT from 65hmwrhf.fewery.science[66.248.211.144]: 451 4.7.1 <hip@houstonincomeproperties.com>: Recipient address rejected: Throttling too many connections from new source - Try again later.; from=<JerryWilliams@fewery.science> to=<hip@houstonincomeproperties.com> proto=ESMTP helo=<00877d1c.fewery.science>
May 27 19:27:29 efagate1 postfix/smtpd[36861]: disconnect from 65hmwrhf.fewery.science[66.248.211.144]
May 27 19:27:29 efagate1 postfix/smtpd[36865]: disconnect from 65hmwrhf.fewery.science[66.248.211.144]
May 27 19:27:29 efagate1 postfix/smtpd[36868]: disconnect from 65hmwrhf.fewery.science[66.248.211.144]
May 27 19:27:29 efagate1 postfix/smtpd[36862]: disconnect from 65hmwrhf.fewery.science[66.248.211.144]
May 27 19:27:31 efagate1 MailScanner[60653]: MailScanner child caught a SIGHUP
May 27 19:27:31 efagate1 MailScanner[32018]: MailScanner child caught a SIGHUP
May 27 19:27:31 efagate1 MailScanner[60305]: MailScanner child caught a SIGHUP
May 27 19:27:31 efagate1 MailScanner[59368]: MailScanner child caught a SIGHUP
May 27 19:27:31 efagate1 MailScanner[5555]: MailScanner child caught a SIGHUP
May 27 19:27:31 efagate1 MailScanner[59906]: MailScanner child caught a SIGHUP
May 27 19:27:31 efagate1 MailScanner[60653]: Config: calling custom end function SQLBlacklist

[shawniverson]

I wonder if the problem is evident somewhere else in the logs?

Would you be able to share your /var/log/messages and /var/log/maillog for analysis?

If so, you can email them to me at shawniverson@ovenvsa-project.org

Also, next time this problem happens, before you restart, could you run the following?

Code: Select all

top -n 1

Also, check your filesystems to make sure they didn't drop to read only due to I/O errors...

Code: Select all

sudo touch test.tmp /
sudo touch test.tmp /var
sudo touch test.tmp /tmp
sudo touch test.tmp /var/spool/Mailscanner/incoming

[shawniverson]

Also, you may try to update to 3.0.0.8 on one of your boxes and see if any updates clear your issues...

[pdwalker]

You've a hard problem to diagnose without actual an actual login to the box, and probably trivial to diagnose with.

Is it possible you could give access to someone (*cough* Shawn *cough*) to speed up the process?

[Heimir]

I am sure we can find a way to give someone (Shawn) access.

I should be around tomorrow if that works.

H.

[shawniverson]

I am around. Best way to do this is on irc. Hop into #efa-project on freenode.

I should be available after 5pm EDT today to assist.