Page 1 of 1

incoming queue growing

Posted: 26 Feb 2014 11:43
by jotaerre
Hello,
Sorry for my english, but i'm having some problems with the postfix incoming queue.

Feb 26 11:04:14 mailg MailScanner[21309]: Other Checks: Found 3 problems
Feb 26 11:04:14 mailg MailScanner[21309]: Virus and Content Scanning: Starting
Feb 26 11:04:14 mailg postfix/smtpd[24040]: disconnect from sn142.digitalpublicitor.com[94.23.176.243]
Feb 26 11:04:15 mailg MailScanner[21309]: Clamd::ERROR:: COULD NOT CONNECT TO CLAMD, RECOMMEND RESTARTING DAEMON :: .
Feb 26 11:04:16 mailg MailScanner[21309]: Virus Scanning: Clamd found 1 infections
Feb 26 11:04:16 mailg MailScanner[21309]: Virus Scanning: No virus scanners worked, so message batch was abandoned and re-tried!
Feb 26 11:04:19 mailg postfix/postdrop[1952]: warning: mail_queue_enter: create file maildrop/461779.1952: Permission denied
Feb 26 11:04:20 mailg sqlgrey: grey: new: 93.49.21.159(93.49.21.159), a2128fd@kandiyo.com -> a2128fd@altoption.com
Feb 26 11:04:20 mailg postfix/smtpd[22388]: NOQUEUE: reject: RCPT from unknown[93.49.21.159]: 451 4.7.1 <a2128fd@altoption.com>: Recipient address rejected: Greylisted for 5 minutes; from=<a2128fd@kandiyo.com> to=<a2128fd@altoption.com> proto=ESMTP helo=<[93.49.21.159]>
Feb 26 11:04:20 mailg postfix/smtpd[22388]: lost connection after DATA from unknown[93.49.21.159]
Feb 26 11:04:20 mailg postfix/smtpd[22388]: disconnect from unknown[93.49.21.159]
Feb 26 11:04:21 mailg MailScanner[21318]: Virus Scanning: Found 1 viruses
Feb 26 11:04:21 mailg MailScanner[21318]: Spam Checks: Starting
Feb 26 11:04:21 mailg MailScanner[21318]: Deleted 30 messages from processing-database
Feb 26 11:04:21 mailg MailScanner[21318]: Logging message A701A10096D.A7468 to SQL

the only way to fix is restart server and wait.
The part clamd/mailscanner when it finds a virus and can't talk with clamd at the same time is weird.
Any thoughts?

Jota

Re: incoming queue growing

Posted: 26 Feb 2014 19:05
by buzzzo
Something not work with clamd.
Try to copy an eicar.com file in /tmp and run on it clamdscan.
This should detect a virus and see if it correctly talk with clamd.

This is the first step to ensure clamd is running ok.

Re: incoming queue growing

Posted: 26 Feb 2014 22:58
by shawniverson
Hmmm....this is unusual.

What message do you get in /var/log/messages when you try to restart clamd?

Re: incoming queue growing

Posted: 03 Mar 2014 12:39
by jotaerre
Sorry for the delay, i've seen that you had the same problem. The thing is that i only have 2 child process in Mailscanner.
I'm using 3.0.0.2 and esva as a backup.

Re: incoming queue growing

Posted: 04 Mar 2014 00:42
by shawniverson
I am not sure your issue is the same as mine. Do you get an error message when you start clamd, either in the console or in /var/log/messages?

Re: incoming queue growing

Posted: 04 Mar 2014 15:45
by jotaerre
This was today.

Mar 4 15:39:26 mailg MailScanner[27340]: New Batch: Scanning 1 messages, 2328924 bytes
Mar 4 15:39:27 mailg MailScanner[27340]: Virus and Content Scanning: Starting
Mar 4 15:39:27 mailg MailScanner[27340]: Clamd::ERROR:: COULD NOT CONNECT TO CLAMD, RECOMMEND RESTARTING DAEMON :: .
Mar 4 15:39:28 mailg MailScanner[27340]: Virus Scanning: Clamd found 1 infections
Mar 4 15:39:28 mailg MailScanner[27340]: Virus Scanning: No virus scanners worked, so message batch was abandoned and re-tried!
Mar 4 15:39:38 mailg MailScanner[27340]: Virus Scanning: Found 1 viruses
Mar 4 15:39:38 mailg MailScanner[27340]: Spam Checks: Starting
Mar 4 15:39:38 mailg MailScanner[27340]: Deleted 1 messages from processing-database
Mar 4 15:39:38 mailg MailScanner[27340]: Logging message 5345110096A.AA020 to SQL
Mar 4 15:39:38 mailg MailScanner[27343]: 5345110096A.AA020: Logged to MailWatch SQL
Mar 4 15:39:38 mailg MailScanner[27340]: New Batch: Scanning 1 messages, 2328924 bytes
Mar 4 15:39:38 mailg MailScanner[27340]: Virus and Content Scanning: Starting
Mar 4 15:39:40 mailg MailScanner[27340]: Spam Checks: Starting
Mar 4 15:39:40 mailg MailScanner[27340]: Whitelist refresh time reached
Mar 4 15:39:40 mailg MailScanner[27340]: Starting up SQL Whitelist
Mar 4 15:39:40 mailg MailScanner[27340]: Read 1 whitelist entries
Mar 4 15:39:40 mailg MailScanner[27340]: Blacklist refresh time reached
Mar 4 15:39:40 mailg MailScanner[27340]: Starting up SQL Blacklist
Mar 4 15:39:40 mailg MailScanner[27340]: Read 0 blacklist entries
Mar 4 15:39:40 mailg MailScanner[27340]: Message 5345110096A.AA020 from 172.16.2.254 (xxxx@xxxx.pt) to xxxx.com,xxxx.pt is too big for spam checks (2328924 > 200000 bytes)
Mar 4 15:39:42 mailg MailScanner[27340]: Requeue: 5345110096A.AA020 to 81D3510098D
Mar 4 15:39:42 mailg MailScanner[27340]: Uninfected: Delivered 1 messages
Mar 4 15:39:42 mailg MailScanner[27340]: Deleted 1 messages from processing-database
Mar 4 15:39:42 mailg MailScanner[27340]: Logging message 5345110096A.AA020 to SQL
Mar 4 15:39:42 mailg MailScanner[27343]: 5345110096A.AA020: Logged to MailWatch SQL
Mar 4 15:39:42 mailg postfix/qmgr[14953]: 81D3510098D: from=<xxxx@xxxx.pt>, size=2328210, nrcpt=2 (queue active)
Mar 4 15:39:42 mailg postfix/smtp[29142]: certificate verification failed for 172.16.2.254[172.16.2.254]:25: untrusted issuer /CN=mail
Mar 4 15:39:43 mailg postfix/smtp[29142]: 81D3510098D: to=<xxx@xxxx.pt>, relay=172.16.2.254[172.16.2.254]:25, delay=10087, delays=10086/0.1/0.08/0.49, dsn=2.6.0, status=sent (250 2.6.0 <1393929135@Multifuncoes> Queued mail for delivery)
Mar 4 15:39:43 mailg postfix/smtp[29142]: warning: network_biopair_interop: error writing 37 bytes to the network: Connection reset by peer
Mar 4 15:39:48 mailg postfix/smtp[29143]: certificate verification failed for xxxx.xxxx.de[82.192.199.6]:25: untrusted issuer /O=AlphaSSL/CN=AlphaSSL CA - G2
Mar 4 15:39:50 mailg postfix/smtp[29143]: 81D3510098D: to=<xxxx@xxxx.com>, relay=xxxx.xxxx.de[x.x.x.x]:25, delay=10095, delays=10086/0.18/6.2/2.2, dsn=2.0.0, status=sent (250 OK id=1WKrTA-0005pg-QJ)
Mar 4 15:39:50 mailg postfix/qmgr[14953]: 81D3510098D: removed

[ ] 04/03/14
15:39:42 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb 0.00 Clean
[ ] 04/03/14
15:39:38 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb Clean
[ ] 04/03/14
15:39:26 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb Clean
[ ] 04/03/14
15:39:15 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb Clean
[ ] 04/03/14
15:39:03 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb Clean
[ ] 04/03/14
15:38:51 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb Clean
[ ] 04/03/14
15:38:40 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb Clean
[ ] 04/03/14
15:38:28 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb Clean
[ ] 04/03/14
15:38:17 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb Clean
[ ] 04/03/14
15:38:05 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb Clean
[ ] 04/03/14
15:37:54 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb Clean
[ ] 04/03/14
15:37:42 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb Clean
[ ] 04/03/14
15:37:31 info@xxxx.pt contabil@xxxx.pt
xxxx@xxxx.com Scanner 2.2Mb Clean

The last message was released after:
> service clamd restart
Stopping Clam AntiVirus Daemon: [FAILED]
Starting Clam AntiVirus Daemon: [ OK ]

Re: incoming queue growing

Posted: 04 Mar 2014 22:50
by shawniverson
Does clamd stay running for a while after you start it, or is it dying right away?

Re: incoming queue growing

Posted: 07 Mar 2014 17:35
by jotaerre
It stops every day.
Restarts ok, but the next day it is stoped.

Re: incoming queue growing

Posted: 07 Mar 2014 21:12
by shawniverson
Can you capture your messages and maillog and share with me? Feel free to PM me...just looking for clues.

Re: incoming queue growing

Posted: 09 Mar 2014 16:37
by shawniverson
I am also curious about your CPU and memory utilization. Mine was crashing due to memory/CPU exhaustion (from too many threads). I wonder if your system is a busier one, maybe it needs more horsepower assigned to it?

Just a thought....

Re: incoming queue growing

Posted: 26 Mar 2014 20:27
by shawniverson

Re: incoming queue growing

Posted: 04 Dec 2014 13:53
by jotaerre
I think now you can close this.
I've added an extra hd for swaping and CLAM stoped dying.
At least is 3 days alive and getting more and more emails.
Jota

Re: incoming queue growing

Posted: 11 Dec 2014 00:02
by shawniverson
Another update to this issue.

This is a memory exhaustion issue. It typically causes clamd to crash under load.

Solution #1 (recommended)

Increase the memory as follows as this rule of thumb: number of mailscanner children setting * 2048 mb

If you are set to use 2 mailscanner children, increase EFA to 4GB. More children require more memory. The default is 2. Therefore, I recommend all EFA users consider increasing the amount of memory from the 2GB default to at least 4GB. I am pushing to have the next downloads of EFA default to at least 4GB of memory instead of 2GB

Solution #2

Add a swap disk.

Attach a new virtual disk to your EFA, format it as swap, and mount as swap. (typically 1.5x your amount of memory) This method has performance implications for your EFA as it runs low on memory due to disk I/O paging, but it may be a reasonable solution for those that do not have memory to spare for EFA.