On 2016-07-15 10:22, Reindl Harald wrote:
Am 15.07.2016 um 16:06 schrieb Olivier Coutu:
I am trying to figure out what part of SA is taking the most time on
certain e-mails, e.g
time spamassassin ham-1468528393442166.eml
[...]
real 0m34.531s
user 0m33.958s
sys 0m0.452s
I have installed HitFreqsRuleTiming and the timing result file has
specific rules that takes long, but the total is about 21 seconds:
awk '{print $3}' timing.log | awk '{s+=$1}END{print s}'
21.4295
I was wondering if there was a way to find out what the extra 13 seconds
were used for. Also, would there be a better benchmarking strategy?
I have attempted to look at the debug, but the timing seems to skip
multiple seconds at random intervals that are not indicative of what
rule ran
just use spamassassin -D which gives you some timing informations,
most likely DNS - DNSBL/DNSWL/URIBL
I have looked at -D:
spamassassin -D 2>&1 < ham-1468528393442166.eml
I am still getting multi-second hops in the debug outputs:
[...]
jui 15 11:47:28.527 [29298] dbg: rules: Z_HAMMY_SPF (pri -60) requires
__ENV_FROM_4SQUARE (pri 0): fixed
jui 15 11:47:34.402 [29298] dbg: rules: Z_HAMMY_SPF (pri -60) requires
__ENV_FROM_DIGG (pri 0): fixed
[...]
jui 15 11:47:36.723 [29298] dbg: dns: dns reply 5194 is OK, 1 answer records
jui 15 11:47:46.829 [29298] dbg: async: calling callback on key
A:ns1.dnsmadeeasy.com
[...]
jui 15 11:47:46.853 [29298] dbg: async: calling callback on key
DNSBL:2.126.80.208:zen.spamhaus.org, rule URIBL_SBL
jui 15 11:52:07.569 [29298] dbg: uridnsbl: complete_dnsbl_lookup
URIBL_SBL DNSBL:2.126.80.208:zen.spamhaus.org
[...]
jui 15 11:52:07.594 [29298] dbg: rules: flush_evalstr
(run_generic_tests) compiling 469 chars of
Mail::SpamAssassin::Plugin::Check::_uri_tests_neg950_1
jui 15 11:52:19.274 [29298] dbg: rules: run_generic_tests - compiling
eval code: uri, priority -950
[...]
Some DNS lookups indeed seem to take a certain amount of time, but the
first 4-second hop cannot be explained that way. Is there a way that I
could limit the number of DNS lookups being made, say to max 50?
