incoming queue growing
incoming queue growing
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
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
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.
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.
- shawniverson
- Posts: 3783
- Joined: 13 Jan 2014 23:30
- Location: Indianapolis, Indiana USA
- Contact:
Re: incoming queue growing
Hmmm....this is unusual.
What message do you get in /var/log/messages when you try to restart clamd?
What message do you get in /var/log/messages when you try to restart clamd?
Re: incoming queue growing
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.
I'm using 3.0.0.2 and esva as a backup.
- shawniverson
- Posts: 3783
- Joined: 13 Jan 2014 23:30
- Location: Indianapolis, Indiana USA
- Contact:
Re: incoming queue growing
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
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 ]
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 ]
- shawniverson
- Posts: 3783
- Joined: 13 Jan 2014 23:30
- Location: Indianapolis, Indiana USA
- Contact:
Re: incoming queue growing
Does clamd stay running for a while after you start it, or is it dying right away?
Re: incoming queue growing
It stops every day.
Restarts ok, but the next day it is stoped.
Restarts ok, but the next day it is stoped.
- shawniverson
- Posts: 3783
- Joined: 13 Jan 2014 23:30
- Location: Indianapolis, Indiana USA
- Contact:
Re: incoming queue growing
Can you capture your messages and maillog and share with me? Feel free to PM me...just looking for clues.
- shawniverson
- Posts: 3783
- Joined: 13 Jan 2014 23:30
- Location: Indianapolis, Indiana USA
- Contact:
Re: incoming queue growing
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....
Just a thought....
- shawniverson
- Posts: 3783
- Joined: 13 Jan 2014 23:30
- Location: Indianapolis, Indiana USA
- Contact:
Re: incoming queue growing
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
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
- shawniverson
- Posts: 3783
- Joined: 13 Jan 2014 23:30
- Location: Indianapolis, Indiana USA
- Contact:
Re: incoming queue growing
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.
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.