Having an issue messages delayed running SA 3.1 with postfix 2.2.7 and amavis 2.3.3 on FreeBSD 5.4 dual proc xeon 2.4's with 1GB RAM. Messages come in as queue active and don't get picked up by amavis for an hour sometimes. I am trying to be sure that is is not a slow process in amavis that is causing the backup. I have amavis max_servers and postfix master.cf set to 2 processes and if I increase to 10, my CPU spikes.
So, looking over the logs, what is a general good length of timing for SA. I am seeing a range of about 5000-15000 ms: Dec 14 17:10:25 esmtp amavis[40840]: (40840-01-10) TIMING [total 15047 ms] - SMTP pre-DATA-flush: 4 (0%)0, SMTP DATA: 191 (1%)1, body_digest: 1 (0%)1, gen_mail_id: 1 (0%)1, mime_decode: 27 (0%)1, get-file-type2: 110 (1%)2, decompose_part: 2 (0%)2, parts_decode: 1 (0%)2, AV-scan-1: 37 (0%)2, spam-wb-list: 6 (0%)3, SA msg read: 5 (0%)3, SA parse: 9 (0%)3, SA check: 14522 (97%)99, update_cache: 2 (0%)99, fwd-connect: 8 (0%)99, fwd-mail-from: 2 (0%)99, fwd-rcpt-to: 2 (0%)99, write-header: 2 (0%)99, fwd-data: 2 (0%)99, fwd-data-end: 95 (1%)100, fwd-rundown: 2 (0%)100, main_log_entry: 14 (0%)100, update_snmp: 1 (0%)100, unlink-2-files: 2 (0%)100, rundown: 1 (0%)100 Dec 14 17:10:26 esmtp amavis[40840]: (40840-01-11) TIMING [total 1051 ms] - SMTP pre-DATA-flush: 4 (0%)0, SMTP DATA: 184 (18%)18, body_digest: 11 (1%)19, gen_mail_id: 1 (0%)19, mime_decode: 91 (9%)28, get-file-type3: 108 (10%)38, decompose_part: 2 (0%)38, parts_decode: 1 (0%)38, AV-scan-1: 436 (41%)80, spam-wb-list: 5 (0%)80, update_cache: 4 (0%)81, fwd-connect: 12 (1%)82, fwd-mail-from: 2 (0%)82, fwd-rcpt-to: 2 (0%)82, write-header: 2 (0%)82, fwd-data: 59 (6%)88, fwd-data-end: 103 (10%)98, fwd-rundown: 2 (0%)98, main_log_entry: 17 (2%)100, update_snmp: 2 (0%)100, unlink-3-files: 2 (0%)100, rundown: 1 (0%)100 Dec 14 17:10:27 esmtp amavis[40880]: TIMING [total 11 ms] - bdb-open: 11 (100%)100, rundown: 0 (0%)100 Dec 14 17:10:29 esmtp amavis[40863]: (40863-01-7) TIMING [total 5993 ms] - SMTP pre-DATA-flush: 3 (0%)0, SMTP DATA: 93 (2%)2, body_digest: 1 (0%)2, gen_mail_id: 1 (0%)2, mime_decode: 19 (0%)2, get-file-type2: 85 (1%)3, decompose_part: 1 (0%)3, parts_decode: 0 (0%)3, AV-scan-1: 19 (0%)4, spam-wb-list: 3 (0%)4, SA msg read: 2 (0%)4, SA parse: 5 (0%)4, SA check: 5737 (96%)100, update_cache: 2 (0%)100, write-header: 7 (0%)100, save-to-local-mailbox: 1 (0%)100, post-do_spam: 1 (0%)100, main_log_entry: 13 (0%)100, update_snmp: 1 (0%)100, unlink-2-files: 2 (0%)100, rundown: 1 (0%)100 Dec 14 17:10:33 esmtp amavis[40880]: (40880-01) TIMING [total 6248 ms] - SMTP EHLO: 12 (0%)0, SMTP pre-MAIL: 1 (0%)0, mkdir tempdir: 1 (0%)0, create email.txt: 1 (0%)0, SMTP pre-DATA-flush: 6 (0%)0, SMTP DATA: 192 (3%)3, body_digest: 2 (0%)3, gen_mail_id: 1 (0%)3, mkdir parts: 1 (0%)3, mime_decode: 19 (0%)4, get-file-type1: 81 (1%)5, decompose_part: 3 (0%)5, parts_decode: 0 (0%)5, AV-scan-1: 14 (0%)5, spam-wb-list: 6 (0%)5, SA msg read: 4 (0%)5, SA parse: 11 (0%)6, SA check: 5751 (92%)98, update_cache: 3 (0%)98, fwd-connect: 10 (0%)98, fwd-mail-from: 1 (0%)98, fwd-rcpt-to: 2 (0%)98, write-header: 2 (0%)98, fwd-data: 1 (0%)98, fwd-data-end: 101 (2%)100, fwd-rundown: 2 (0%)100, main_log_entry: 17 (0%)100, update_snmp: 1 (0%)100, unlink-1-files: 2 (0%)100, rundown: 1 (0%)100 Dec 14 17:10:35 esmtp amavis[40863]: (40863-01-8) TIMING [total 6310 ms] - SMTP pre-DATA-flush: 4 (0%)0, SMTP DATA: 95 (2%)2, body_digest: 1 (0%)2, gen_mail_id: 0 (0%)2, mime_decode: 30 (0%)2, get-file-type3: 108 (2%)4, decompose_part: 1 (0%)4, decompose_part: 1 (0%)4, decompose_part: 1 (0%)4, parts_decode: 0 (0%)4, AV-scan-1: 16 (0%)4, spam-wb-list: 4 (0%)4, SA msg read: 2 (0%)4, SA parse: 6 (0%)4, SA check: 5910 (94%)98, update_cache: 2 (0%)98, fwd-connect: 10 (0%)98, fwd-mail-from: 1 (0%)98, fwd-rcpt-to: 2 (0%)98, write-header: 2 (0%)98, fwd-data: 1 (0%)98, fwd-data-end: 93 (1%)100, fwd-rundown: 2 (0%)100, main_log_entry: 12 (0%)100, update_snmp: 2 (0%)100, unlink-3-files: 2 (0%)100, rundown: 1 (0%)100 Dec 14 17:10:39 esmtp amavis[40880]: (40880-01-2) TIMING [total 5623 ms] - SMTP pre-DATA-flush: 3 (0%)0, SMTP DATA: 100 (2%)2, body_digest: 2 (0%)2, gen_mail_id: 1 (0%)2, mime_decode: 48 (1%)3, get-file-type3: 105 (2%)5, decompose_part: 1 (0%)5, decompose_part: 1 (0%)5, parts_decode: 0 (0%)5, AV-scan-1: 24 (0%)5, spam-wb-list: 5 (0%)5, SA msg read: 2 (0%)5, SA parse: 8 (0%)5, SA check: 5183 (92%)97, update_cache: 3 (0%)98, fwd-connect: 10 (0%)98, fwd-mail-from: 1 (0%)98, fwd-rcpt-to: 2 (0%)98, write-header: 3 (0%)98, fwd-data: 1 (0%)98, fwd-data-end: 101 (2%)100, fwd-rundown: 2 (0%)100, main_log_entry: 13 (0%)100, update_snmp: 1 (0%)100, unlink-3-files: 2 (0%)100, rundown: 1 (0%)100 -- Robert
