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/ 

Reply via email to