On Monday 18 April 2011, david touzeau wrote: > Le lundi 18 avril 2011 à 17:32 +0100, Nuno Fernandes a écrit : > > Hello, > > > > I have a amavisd-new-2.6.4 installed and somewhat this weekend, it > > started to take long time to process emails (drom 2/3 sec to 15/20 sec > > per email). > > > > I've increased amavisd-new loglevel to 5 and see that spamassassin > > takes 97% of the time: > > > > Apr 18 17:32:19 etmx1 amavis[19306]: (19306-10) TIMING [total 13003 > > ms] - SMTP greeting: 2 (0%)0, SMTP EHLO: 1 (0%)0, SMTP pre-MAIL: 2 > > (0%)0, lookup_sql: 5 (0%)0, SMTP pre-DATA-flush: 1 (0%)0, SMTP DATA: > > 31 (0%)0, check_init: 0 (0%)0, digest_hdr: 142 (1%)1, > > digest_body_dkim: 2 (0%)1, sql-enter: 8 (0%)2, mime_decode: 15 (0%)2, > > get-file-type1: 87 (1%)2, decompose_part: 1 (0%)2, parts_decode: 0 > > (0%)2, AV-scan-1: 7 (0%)2, AV-scan-2: 2 (0%)2, lookup_sql: 4 (0%)2, > > lookup_sql: 2 (0%)2, lookup_sql: 3 (0%)2, lookup_sql: 1 (0%)2, > > spam-wb-list: 2 (0%)2, SA parse: 5 (0%)2, SA check: 12607 (97%)99, > > update_cache: 9 (0%)100, decide_mail_destiny: 3 (0%)100, fwd-connect: > > 8 (0%)100, fwd-xforward: 1 (0%)100, fwd-mail-pip: 10 (0%)100, > > fwd-rcpt-pip: 0 (0%)100, fwd-data-chkpnt: 0 (0%)100, write-header: 2 > > (0%)100, fwd-data-contents: 0 (0%)100, fwd-end-chkpnt: 16 (0%)100, > > prepare-dsn: 2 (0%)100, main_log_entry: 6 (0%)100, sql-update: 4 > > (0%)100, update_snmp: 2 (0%)100, SMTP pre-response: 1 (0%)100, SMTP > > response: 1 (0%)100, > > > > How can i increase the loglevel so that i can see what is taking that > > long? > > > > Thanks, > > > > Nuno Fernandes > > Hi > > I have the same issues for men amavisd childs turn to 100% CPU and > exceed the TTL child period ! > You can find here what i have set in spamassassin in order to reduce the > time > perhaps you are more lucky > http://groups.google.com/group/mailing.unix.amavis-user/browse_thread/threa > d/2f41658d956bca51
Hum.. my doesn't turn 100% cpu, but as i have spamassassin >= 3.3.0, i've checked the logs and found: Apr 18 17:32:19 etmx1 amavis[19306]: (19306-10) TIMING-SA total 12614 ms - parse: 3 (0.0%), extract_message_metadata: 145 (1.1%), get_uri_detail_list: 1.24 (0.0%), tests_pri_-1000: 23 (0.2%), tests_pri_-950: 1.51 (0.0%), tests_pri_-900: 3 (0.0%), tests_pri_-400: 26 (0.2%), check_bayes: 23 (0.2%), tests_pri_0: 12357 (98.0%), check_dkim_adsp: 58 (0.5%), check_spf: 261 (2.1%), poll_dns_idle: 240 (1.9%), check_razor2: 907 (7.2%), check_dcc: 478 (3.8%), check_pyzor: 185 (1.5%), tests_pri_500: 18 (0.1%), tests_pri_1000: 6 (0.0%), total_awl: 4 (0.0%), check_awl: 0.97 (0.0%), update_awl: 0.36 (0.0%), tests_pri_2000: 1.62 (0.0%), get_report: 1.21 (0.0%) Aparently is that tests_pri in spamassassin that is taking 98% of the time.. Does anyone know what it is? Thanks, Nuno Fernandes
