Vladislav, > I'm trying to find out email delays are abnormally big on my mail host. > It's postfix + amavisd-new. > > I increased amavis log verbosity (log_level=3 in amavisd.conf), and > detailed timings show
Btw, log level 2 suffices to see timing reports. > that most of the time is taken for SpamAssassin > checks. > parts_decode: 0 (0%)2, > check_header: 1 (0%)2, > AV-scan-1: 4 (0%)2, > spam-wb-list: 1 (0%)2, > SA parse: 1 (0%)2, > SA check: 3387 (98%)99, <- SpamAssassin is slow... > update_cache: 3 (0%)100, > decide_mail_destiny: 1 (0%)100, > lookup_ldap: 2 (0%)100, > fwd-connect: 3 (0%)100, > fwd-mail-pip: 4 (0%)100, Few seconds for SpamAssassin is not unusual with anything beyond a baseline set of rules with no networks rules. > Turning off network-based checks in spamassassin solved the problem, and > active queue of 11K messages was delivered in several minutes. Most of the network tests just add to latency (idle wait time) and do not significantly burden CPU. So if your CPU is not yet near 100% busy, the solution is to increase the number of concurrent amavisd processes ($max_servers in amavisd.conf, along with maxproc field in master.cf for a smtp service feeding amavisd). > Now I'm trying to find which check takes too much. > I enabled $sa_debug in amavis log file, but was not able to find > SpamAssassin's logs anywhere in the /var/log? > Where does it go? If it's logged with syslog, what is default > facility/level? Running amavis with debug-sa is not an option: there's > too much traffic on this box. > I was unable to find an answer in amavis/SA docs, source code or this > list archives. With more recent versions of amavisd (2.6.*) the SpamAssassin log messages go to syslog, along with the rest of amavisd logging - see below. Run it for example like: amavisd -d all Btw, if you use SpamAssassin 3.3 (from CVS), you'll also get 'TIMING-SA' log entries at log level 2, i.e. a timing breakdown report on tasks within, like: Mar 16 17:29:56 patsy amavis[47739]: (47739-06) TIMING-SA total 3155 ms - parse: 2 (0.1%), extract_message_metadata: 44 (1.4%), get_uri_detail_list: 1.65 (0.1%), tests_pri_-1000: 11 (0.3%), tests_pri_-950: 0.67 (0.0%), tests_pri_-900: 0.82 (0.0%), tests_pri_-400: 22 (0.7%), check_bayes: 20 (0.6%), tests_pri_0: 1485 (47.1%), check_spf: 712 (22.6%), check_dkim_signature: 1.15 (0.0%), poll_dns_idle: 1602 (50.8%), check_razor2: 514 (16.3%), check_dcc: 169 (5.3%), check_pyzor: 0.03 (0.0%), tests_pri_500: 921 (29.2%), tests_pri_899: 94 (3.0%), check_crm114: 93 (2.9%), tests_pri_1000: 505 (16.0%), total_awl: 503 (15.9%), check_awl: 10 (0.3%), update_awl: 488 (15.5%), learn: 38 (1.2%), get_report: 1.87 (0.1%) (the 3.3 is still compatible with 3.2.5, so you can switch back and forth between versions, just don't forget to run sa-update) amavisd-new-2.6.0 release notes - semantics of a command line option 'debug-sa' has changed due to a merge of SpamAssassin logging with a mainstream amavisd logging mechanism. A command 'amavisd debug-sa' is now equivalent to 'amavisd -d all' with an implied redirection of all logging to stderr. Previously it only rerouted SpamAssassin logging to stderr but did not affect normal amavisd logging, which still followed the usual $DO_SYSLOG and $LOGFILE settings. Also, a SpamAssassin log level 'info' is now turned on by default (as was previously achievable by a command line option '-d info'), and shows merged with a normal amavisd logging at level 1 or higher. The following table shows mapping of SpamAssassin log levels to amavisd log levels, and for completeness also shows mapping of amavisd log levels to syslog priorities (which has not changed since previous version): SA amavisd syslog ----- ------- ----------- -3 LOG_CRIT -2 LOG_ERR error -1 LOG_WARNING warn 0 LOG_NOTICE info 1 LOG_INFO 2 LOG_INFO dbg 3 LOG_DEBUG 4 LOG_DEBUG 5 LOG_DEBUG [...] - capture SpamAssassin logging and integrate it into the usual amavisd log; - when parsing SpamAssassin log areas/facilities, recognize negations (a name prefixed by 'no') and remove duplicates, last entry wins, e.g. amavisd -d rules,noall,norules,dcc,norules,rules debug-sa is equivalent to: amavisd -d noall,dcc,rules debug-sa - a SpamAssassin debug level 'info' is now implicitly prepend to a list of SpamAssassin facilities; it may be overridden by explicitly negating it, e.g. 'amavisd -d noinfo'; - when a command line argument 'debug-sa' is present, or if $sa_debug is true, a SpamAssassin debug level 'all' is prepend to a list of SpamAssassin facilities, which would bring SpamAssassin log level to 'dbg'; it may be overridden by negating it, e.g. 'amavisd -d noall,plugins,rules debug-sa'; Mark ------------------------------------------------------------------------------ Apps built with the Adobe(R) Flex(R) framework and Flex Builder(TM) are powering Web 2.0 with engaging, cross-platform capabilities. Quickly and easily build your RIAs with Flex Builder, the Eclipse(TM)based development software that enables intelligent coding and step-through debugging. Download the free 60 day trial. http://p.sf.net/sfu/www-adobe-com _______________________________________________ AMaViS-user mailing list AMaViS-user@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/amavis-user AMaViS-FAQ:http://www.amavis.org/amavis-faq.php3 AMaViS-HowTos:http://www.amavis.org/howto/