Link to home
Start Free TrialLog in
Avatar of jinfeld
jinfeldFlag for United States of America

asked on

Postfix Spamassassin Amavisd Clamav: Slow down

We are using Postfix Spamassassin Amavisd ClamAV under Redhat 9 as an email gateway to an Exchange Server.
During heavy loads the system becomes is very slow (many minutes) to respond to a command promt and the mail just stacks up in the Postfix queue. Oftentimes a reboot will help.

The maillog shows an inordinate amount of time is spent during the AMAVIS fwd-data-end stage.
What does "fwd-data-end" indicate?
Where do I go to check/fix whatever controls  "fwd-data-end"?
Is this the cause of the severe slowdowns or should I bark up another tree (I am already howling at the moon)?
Thanks,
Jerry

For example, some TIMING entries:

Nov 10 13:59:25 ISISDSPAM amavis[4563]: (04563-07-19) TIMING [total 14410 ms] - SMTP pre-DATA-flush: 10 (0%)0, SMTP DATA: 107 (1%)1, body_digest: 1 (0%)1, gen_mail_id: 0 (0%)1, mime_decode: 9 (0%)1, get-file-type2: 108 (1%)2, decompose_part: 1 (0%)2, parts_decode: 0 (0%)2, AV-scan-1: 11 (0%)2, spam-wb-list: 1 (0%)2, SA msg read: 1 (0%)2, SA parse: 1 (0%)2, SA check: 4149 (29%)31, SA finish: 2 (0%)31, update_cache: 1 (0%)31, decide_mail_destiny: 1 (0%)31, fwd-connect: 5 (0%)31, fwd-mail-from: 1 (0%)31, fwd-rcpt-to: 1 (0%)31, fwd-data-cmd: 0 (0%)31, write-header: 0 (0%)31, fwd-data-contents: 0 (0%)31, fwd-data-end: 9578 (66%)97, fwd-rundown: 108 (1%)98, prepare-dsn: 68 (0%)98, main_log_entry: 246 (2%)100, unlink-2-files: 1 (0%)100, rundown: 0 (0%)100

Nov 10 13:59:26 ISISDSPAM amavis[4562]: (04562-07-22) TIMING [total 6196 ms] - SMTP pre-DATA-flush: 2 (0%)0, SMTP DATA: 29 (0%)1, body_digest: 1 (0%)1, gen_mail_id: 0 (0%)1, mime_decode: 194 (3%)4, get-file-type1: 10 (0%)4, decompose_part: 1 (0%)4, parts_decode: 0 (0%)4, spam-wb-list: 3 (0%)4, update_cache: 0 (0%)4, decide_mail_destiny: 1 (0%)4, fwd-connect: 399 (6%)10, fwd-mail-from: 1 (0%)10, fwd-rcpt-to: 303 (5%)15, fwd-data-cmd: 0 (0%)15, write-header: 0 (0%)15, fwd-data-contents: 0 (0%)15, fwd-data-end: 5194 (84%)99, fwd-rundown: 21 (0%)99, prepare-dsn: 12 (0%)100, main_log_entry: 23 (0%)100, unlink-1-files: 1 (0%)100, rundown: 0 (0%)100

Nov 10 13:59:37 ISISDSPAM amavis[4562]: (04562-07-23) TIMING [total 10596 ms] - SMTP pre-DATA-flush: 9 (0%)0, SMTP DATA: 32 (0%)0, body_digest: 1 (0%)0, gen_mail_id: 0 (0%)0, mime_decode: 5 (0%)0, get-file-type1: 10 (0%)1, decompose_part: 1 (0%)1, parts_decode: 0 (0%)1, spam-wb-list: 3 (0%)1, update_cache: 0 (0%)1, decide_mail_destiny: 1 (0%)1, fwd-connect: 5 (0%)1, fwd-mail-from: 1 (0%)1, fwd-rcpt-to: 1 (0%)1, fwd-data-cmd: 0 (0%)1, write-header: 1 (0%)1, fwd-data-contents: 0 (0%)1, fwd-data-end: 10520 (99%)100, fwd-rundown: 1 (0%)100, prepare-dsn: 1 (0%)100, main_log_entry: 4 (0%)100, unlink-1-files: 0 (0%)100, rundown: 0 (0%)100

Nov 10 13:59:49 ISISDSPAM amavis[4562]: (04562-07-24) TIMING [total 11917 ms] - SMTP pre-DATA-flush: 2 (0%)0, SMTP DATA: 69 (1%)1, body_digest: 1 (0%)1, gen_mail_id: 0 (0%)1, mime_decode: 438 (4%)4, get-file-type2: 10 (0%)4, parts_decode: 0 (0%)4, AV-scan-1: 11 (0%)4, spam-wb-list: 2 (0%)4, SA msg read: 1 (0%)4, SA parse: 2 (0%)4, SA check: 1988 (17%)21, SA finish: 2 (0%)21, update_cache: 1 (0%)21, decide_mail_destiny: 2 (0%)21, fwd-connect: 5 (0%)21, fwd-mail-from: 1 (0%)21, fwd-rcpt-to: 1 (0%)21, fwd-data-cmd: 0 (0%)21, write-header: 0 (0%)21, fwd-data-contents: 1 (0%)21, fwd-data-end: 9372 (79%)100, fwd-rundown: 1 (0%)100, prepare-dsn: 1 (0%)100, main_log_entry: 6 (0%)100, unlink-2-files: 1 (0%)100, rundown: 0 (0%)100

Nov 10 13:59:50 ISISDSPAM amavis[4563]: (04563-07-20) TIMING [total 24444 ms] - SMTP pre-DATA-flush: 106 (0%)0, SMTP DATA: 133 (1%)1, body_digest: 1 (0%)1, gen_mail_id: 0 (0%)1, mime_decode: 275 (1%)2, get-file-type3: 16 (0%)2, parts_decode: 0 (0%)2, AV-scan-1: 36 (0%)2, spam-wb-list: 1 (0%)2, SA msg read: 3 (0%)2, SA parse: 5 (0%)2, SA check: 3527 (14%)17, SA finish: 2 (0%)17, update_cache: 1 (0%)17, decide_mail_destiny: 1 (0%)17, fwd-connect: 5 (0%)17, fwd-mail-from: 1 (0%)17, fwd-rcpt-to: 1 (0%)17, fwd-data-cmd: 0 (0%)17, write-header: 0 (0%)17, fwd-data-contents: 3 (0%)17, fwd-data-end: 20211 (83%)100, fwd-rundown: 24 (0%)100, prepare-dsn: 0 (0%)100, main_log_entry: 90 (0%)100, unlink-3-files: 1 (0%)100, rundown: 0 (0%)100
Avatar of ircpamanager
ircpamanager

could you give us specs on the machine, the /etc/hosts, /etc/resolv.conf files. Is this machine on a dmz zone? Is it behind a firewall. Can dns resolve this host in a timely manner?
post back the results
Avatar of jinfeld

ASKER

How do I check if DNS (our local Windows 2003 Server is located at 192.168.254.4) resolves the host in a timely manner?

CPU: AMD Sempron 64 3400+ Palermo in
Memory: 1 Gb 400MHz DDR Non-ECC
MBd: ASUS K8V-MX Socket 754 VIA K8M800
HD: Seagate 200GB IDE
No firewall
No DMZ

/etc/hosts
# Do not remove the following line, or various programs
# that require network functionality will fail.
127.0.0.1       ISISDSPAM       localhost.localdomain   localhost

/etc/resolv.conf
; generated by /sbin/dhclient-script
;search isisDSPAM
nameserver 192.168.254.4
nameserver 206.13.28.12

Thanks,
Jerry
what is the ip of the RH machine, is it fixed?
your postfix server needs a hostname. to see if it resolves it, type in command prompt   ping RH Hostname<<< or whatever th ename of the box is. if it returns the ip address of RH box with reply message then it is resolving it in the dns.
Avatar of jinfeld

ASKER

[root@ISISDSPAM root]# ping ISISDSPAM
PING ISISDSPAM (127.0.0.1) 56(84) bytes of data.
64 bytes from ISISDSPAM (127.0.0.1): icmp_seq=1 ttl=64 time=0.021 ms
64 bytes from ISISDSPAM (127.0.0.1): icmp_seq=2 ttl=64 time=0.015 ms
64 bytes from ISISDSPAM (127.0.0.1): icmp_seq=3 ttl=64 time=0.011 ms

The static IP address fo rthe RH box:
 inet addr:192.168.254.3

Thanks,
Jerry
if you ping ISISDSPAM from anohter machine does it return 192.168.254.3
Avatar of jinfeld

ASKER

No
Should I create an HIST record in the Win 2003 DNS server to point ISISDSPAM to 192.168.254.3?
Thanks
ASKER CERTIFIED SOLUTION
Avatar of ircpamanager
ircpamanager

Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial
Avatar of jinfeld

ASKER

/etc/hosts  now looks like this:
# Do not remove the following line, or various programs
# that require network functionality will fail.
127.0.0.1       ISISDSPAM       localhost.localdomain   localhost
192.168.254.3   ISISDSPAM       MotionPro2.local        ISISDSPAM

The DNS "A" record on the Win2003 server now looks like this:
HOST: ISISDSPAM
FQDN: ISISDSPAM.MotionPro2.local
IP: 192.168.254.3

Now I can ping ISISDSPAM from any Windows PC on the network.
How does this affect the Spam box since all the Postfix to AMAVSID to SA to Postfix is handled internally on the solo RH box?

Thanks,
Jerry

/etc/hosts  now looks like this:
# Do not remove the following line, or various programs
# that require network functionality will fail.
127.0.0.1       ISISDSPAM       localhost.localdomain   localhost
192.168.254.3   ISISDSPAM       MotionPro2.local        ISISDSPAM

chnage 192.168.254.3   ISISDSPAM       MotionPro2.local        ISISDSPAM
to 192.168.254.3   ISISDSPAM.MotionPro2.local        ISISDSPAM
you are just using this as a realy correct? so in your main.cf you have exchange server as relay?
If exchange cant resolve RH box it will take forever.
do you have content_filter line in main.cf?
Avatar of jinfeld

ASKER

/etc/postfix/main.cf
content_filter = smtp-amavis:[127.0.0.1]:10024

Should the Win2003 DNS "A" reference the Windows Domain: ISISDSPAM.MotionPro2.local        
Or should it rerence the RH Postfix domain (this is the domain list in the email header):  isisdspam.spam.motionpro.com

Jerry
try commenting out content_filter and check the speed
"Or should it rerence the RH Postfix domain (this is the domain list in the email header):  isisdspam.spam.motionpro.com"
is the RH box under a different domain?If it is why do you have it this way?If they are both(exchange and postfix box)on same subnet then same domain makes more sense.
The "A" record should point to the same domain the Win 2003 box is apart of ISISDSPAM.MotionPro2.local
Avatar of jinfeld

ASKER

Will that stop any email checking by ClamAV and SA?
Jerry
yes and no, it will turn off advanced content filter
have a look here
http://www.postfix.org/FILTER_README.html
Avatar of jinfeld

ASKER

Hi,
A ping on the Exchange server box now resolves to the spam box IP.
In /etc/postfix/main.cf  I commented out
#content_filter = smtp-amavis:[127.0.0.1]:10024

ran postfix reload

Was there anything else to reload or restart?

Timing seems to be unaffected with the bulk going to fwd-data-end:

Nov 13 15:15:52 ISISDSPAM amavis[5126]: (05126-02-3) TIMING [total 28317 ms] - SMTP pre-DATA-flush: 1 (0%)0, SMTP DATA: 39 (0%)0, body_hash: 1 (0%)0, gen_mail_id: 0 (0%)0, mime_decode: 17 (0%)0, get-file-type2: 13 (0%)0, parts_decode: 0 (0%)0, AV-scan-1: 76 (0%)1, spam-wb-list: 1 (0%)1, SA msg read: 1 (0%)1, SA parse: 3 (0%)1, SA check: 5392 (19%)20, update_cache: 1 (0%)20, fwd-connect: 8 (0%)20, fwd-mail-from: 1 (0%)20, fwd-rcpt-to: 83 (0%)20, write-header: 2 (0%)20, fwd-data: 1 (0%)20, fwd-data-end: 22668 (80%)100, fwd-rundown: 1 (0%)100, post-do_spam: 1 (0%)100, main_log_entry: 6 (0%)100, unlink-2-files: 1 (0%)100, rundown: 0 (0%)100

Nov 13 15:16:06 ISISDSPAM amavis[5441]: (05441-01-2) TIMING [total 11530 ms] - SMTP pre-DATA-flush: 1 (0%)0, SMTP DATA: 77 (1%)1, body_hash: 1 (0%)1, gen_mail_id: 0 (0%)1, mime_decode: 12 (0%)1, get-file-type2: 14 (0%)1, parts_decode: 0 (0%)1, AV-scan-1: 16 (0%)1, spam-wb-list: 1 (0%)1, SA msg read: 1 (0%)1, SA parse: 2 (0%)1, SA check: 4174 (36%)37, update_cache: 1 (0%)37, fwd-connect: 4 (0%)37, fwd-mail-from: 1 (0%)37, fwd-rcpt-to: 2 (0%)37, write-header: 2 (0%)37, fwd-data: 0 (0%)37, fwd-data-end: 7214 (63%)100, fwd-rundown: 1 (0%)100, main_log_entry: 6 (0%)100, unlink-2-files: 1 (0%)100, rundown: 0 (0%)100
do a postfix reload
Avatar of jinfeld

ASKER

I believe the DNS issue helped the SPam box throug-put greatly. The true fix for the "fwd-data-end" slowup was what you alluded to earlier: double checking on the second pass-through Postfix.
Using the recommendations on:
http://www.ijs.si/software/amavisd/README.postfix.txt 

I used this settings in /etc/postfix/master.cf
 -o receive_override_options=no_header_body_checks,no_unknown_recipient_checks
to stop the second pass filtering. (see the full web page for this discussion).

Thanks for your thorough consideration and help!
Jerry
no problem I am glad I could help.