Hello list,
Recently I'm having issues with delays due to amavisd-new/spamassassin.
With log level increased to 5 in amavisd.conf I get this out of the logs:
Feb 19 22:55:17 hostname amavis[1215]: (01215-01) p001 1 Content-Type:
text/plain, size: 7 B, name:
*snip*
Feb 19 23:00:17 tilaa1 amavis[1215]: (01215-01) _WARN: bayes:
expire_old_tokens: __alarm__ignore__(79)
Feb 19 23:00:17 tilaa1 amavis[1215]: (01215-01) SA info: check: exceeded time
limit in Mail::SpamAssassin::Plugin::Check::_eval_tests_type11_prineg400_set3,
skipping further tests
Feb 19 23:00:17 tilaa1 amavis[1215]: (01215-01) _WARN: Use of uninitialized
value in concatenation (.) or string at
/usr/local/lib/perl5/site_perl/5.16/Mail/SpamAssassin/PerMsgStatus.pm line 1258.
Feb 19 23:00:17 tilaa1 amavis[1215]: (01215-01) _WARN: Use of uninitialized
value in numeric eq (==) at
/usr/local/lib/perl5/site_perl/5.16/Mail/SpamAssassin/PerMsgStatus.pm line 424.
*snip*
Feb 19 23:00:18 tilaa1 amavis[1215]: (01215-01) TIMING-SA total 300188 ms -
parse: 3 (0.0%), extract_message_metadata: 18 (0.0%), poll_dns_idle: 2 (0.0%),
get_uri_detail_list: 0.60 (0.0%), tests_pri_-1000: 17 (0.0%), tests_pri_
-950: 1.89 (0.0%), tests_pri_-900: 1.91 (0.0%), tests_pri_-400: 300094
(100.0%), check_bayes: 300088 (100.0%), expire_bayes: 298067 (99.3%),
get_report: 0.81 (0.0%)
Feb 19 23:00:18 tilaa1 amavis[1215]: (01215-01) size: 1980, TIMING [total
301147 ms] - SMTP greeting: 7 (0%)0, SMTP EHLO: 3 (0%)0, SMTP pre-MAIL: 1
(0%)0, mkdir tempdir: 2 (0%)0, create email.txt: 1 (0%)0, SMTP pre-DATA-flush:
6 (0%)0, SMTP DATA: 100 (0%)0, check_init: 1 (0%)0, digest_hdr: 6 (0%)0,
digest_body_dkim: 35 (0%)0, mkdir parts: 5 (0%)0, mime_decode: 9 (0%)0,
get-file-type1: 174 (0%)0, parts_decode: 0 (0%)0, check_header: 1 (0%)0,
AV-scan-1
: 32 (0%)0, spam-wb-list: 4 (0%)0, SA msg read: 1 (0%)0, SA parse: 6 (0%)0, SA
check: 300179 (100%)100, decide_mail_destiny: 9 (0%)100, notif-quar: 1 (0%)100,
fwd-connect: 33 (0%)100, fwd-mail-pip: 325 (0%)100, fwd-rcpt-pip: 0
(0%)100, fwd-data-chkpnt: 0 (0%)100, write-header: 1 (0%)100,
fwd-data-contents: 0 (0%)100, fwd-end-chkpnt: 178 (0%)100, prepare-dsn: 2
(0%)100, main_log_entry: 15 (0%)100, update_snmp: 5 (0%)100, SMTP pre-response:
1 (0%)100,
SMTP response: 2 (0%)100, unlink-2-files: 1 (0%)100, rundown: 1 (0%)100
Feb 19 23:00:18 tilaa1 amavis[1215]: (01215-01) extra modules loaded:
unicore/lib/Gc/Nd.pl
Can anyone shed some light into what _eval_tests_type11_prineg400_set3
means and where does it come from?
Not all e-mails get the same treatment, some that reach same 01215-01
process get through without delays and then even a plain text e-mail
induces this delay.
I'm running this postfix/amavisd-new under FreeBSD 9.1-RELEASE.
Thank you,
Andrei
