A very slow MS 4.62.2-3 & SA 3.2.1 & ClamAV 0.91 machine - some results of -sa-debug

[Quentin Campbell]

When I do 'MailScanner -debug -sa-debug' there is no obvious big pause but a hesitation when it starts to '... dbg: rules: running body tests; score so far...'.

A more obvious thing is that lookup times for uridnsbl sites is very variable and that responses are not cached: 

...
...
[25023] dbg: uridnsbl: query for carquiet.com took 5 seconds to look up (sbl.spamhaus.org.:236.81.138.89)
[25023] dbg: uridnsbl: query for carquiet.com took 5 seconds to look up (sbl.spamhaus.org.:14.241.178.80)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (multi.uribl.com.:aegean.gr)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (bl.open-whois.org.:aegean.gr)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (multi.surbl.org.:aegean.gr)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (dob.sibl.support-intelligence.net:aegean.gr)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (sbl.spamhaus.org.:1.130.251.195)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (sbl.spamhaus.org.:3.148.251.195)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (sbl.spamhaus.org.:8.130.251.195)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (sbl.spamhaus.org.:19.168.251.195)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (sbl.spamhaus.org.:9.177.251.195)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (sbl.spamhaus.org.:5.160.251.195)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (sbl.spamhaus.org.:3.144.251.195)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (sbl.spamhaus.org.:210.210.177.194)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (sbl.spamhaus.org.:5.128.251.195)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (sbl.spamhaus.org.:1.128.251.195)
[25046] dbg: uridnsbl: query for aegean.gr took 7 seconds to look up (sbl.spamhaus.org.:5.184.251.195)
[25047] dbg: uridnsbl: query for poemboy.hk took 6 seconds to look up (multi.surbl.org.:poemboy.hk)
[25047] dbg: uridnsbl: query for carquiet.com took 6 seconds to look up (multi.surbl.org.:carquiet.com)
[25047] dbg: uridnsbl: query for carquiet.com took 6 seconds to look up (dob.sibl.support-intelligence.net:carquiet.com)
[25047] dbg: uridnsbl: query for poemboy.hk took 6 seconds to look up (multi.uribl.com.:poemboy.hk)
[25047] dbg: uridnsbl: query for poemboy.hk took 6 seconds to look up (bl.open-whois.org.:poemboy.hk)
[25047] dbg: uridnsbl: query for carquiet.com took 6 seconds to look up (bl.open-whois.org.:carquiet.com)
[25047] dbg: uridnsbl: query for carquiet.com took 6 seconds to look up (multi.uribl.com.:carquiet.com)
[25047] dbg: uridnsbl: query for poemboy.hk took 6 seconds to look up (dob.sibl.support-intelligence.net:poemboy.hk)
[25047] dbg: uridnsbl: query for carquiet.com took 6 seconds to look up (sbl.spamhaus.org.:236.81.138.89)
[25047] dbg: uridnsbl: query for carquiet.com took 6 seconds to look up (sbl.spamhaus.org.:14.241.178.80)
[25050] dbg: uridnsbl: query for sciencedirect.com took 13 seconds to look up (dob.sibl.support-intelligence.net:sciencedirect.com)
[25050] dbg: uridnsbl: query for sciencedirect.com took 13 seconds to look up (bl.open-whois.org.:sciencedirect.com)
[25050] dbg: uridnsbl: query for sciencedirect.com took 13 seconds to look up (multi.surbl.org.:sciencedirect.com)
[25050] dbg: uridnsbl: query for sciencedirect.com took 13 seconds to look up (multi.uribl.com.:sciencedirect.com)
[25050] dbg: uridnsbl: query for sciencedirect.com took 13 seconds to look up (sbl.spamhaus.org.:3.4.12.138)
[25050] dbg: uridnsbl: query for sciencedirect.com took 13 seconds to look up (sbl.spamhaus.org.:2.4.12.138)
[25050] dbg: uridnsbl: query for sciencedirect.com took 13 seconds to look up (sbl.spamhaus.org.:11.200.81.198)
[25050] dbg: uridnsbl: query for sciencedirect.com took 13 seconds to look up (sbl.spamhaus.org.:2.180.25.207)
[25023] dbg: uridnsbl: query for carquiet.com took 5 seconds to look up (multi.uribl.com.:carquiet.com)
[25023] dbg: uridnsbl: query for carquiet.com took 5 seconds to look up (multi.surbl.org.:carquiet.com)
[25023] dbg: uridnsbl: query for poemboy.hk took 5 seconds to look up (multi.uribl.com.:poemboy.hk)
[25023] dbg: uridnsbl: query for poemboy.hk took 5 seconds to look up (bl.open-whois.org.:poemboy.hk)
[25023] dbg: uridnsbl: query for poemboy.hk took 5 seconds to look up (multi.surbl.org.:poemboy.hk)
[25023] dbg: uridnsbl: query for poemboy.hk took 5 seconds to look up (dob.sibl.support-intelligence.net:poemboy.hk)
[25023] dbg: uridnsbl: query for carquiet.com took 5 seconds to look up (bl.open-whois.org.:carquiet.com)
[25023] dbg: uridnsbl: query for carquiet.com took 5 seconds to look up (dob.sibl.support-intelligence.net:carquiet.com)
...
...


Quentin

>-----Original Message-----
>From: mailscanner-bounces at lists.mailscanner.info [mailto:mailscanner-
>bounces at lists.mailscanner.info] On Behalf Of Quentin Campbell
>Sent: 12 July 2007 16:37
>To: MailScanner discussion
>Subject: A very slow MS 4.62.2-3 & SA 3.2.1 & ClamAV 0.91 machine
>
>I have a very slow mail gateway among the 4 that I have just upgraded.
>
>They all run MS 4.62.2-3, SA 3.2.1 and ClamAV 0.91 and should have
>identical configurations for MS and SA. MCP processing is done and it is
>the same on all 4.
>
>There were 211 batches of 30 messages each processed on the slow
>machine. Overall the average time to process each message is 15 seconds!
>
>The last two of these batches were processed by running MailScanner in
>debug mode. The average processing time for each message then dropped to
>between 2 and 3 seconds!
>
>I am trying to get a handle on why this machine is so slow. Any
>suggestions to help further my investigation are welcome.
>
>Quentin
>---
>PHONE: +44 191 222 8209    Information Systems and Services (ISS),
>                           Newcastle University,
>                           Newcastle upon Tyne,
>FAX:   +44 191 222 8765    United Kingdom, NE1 7RU.
>------------------------------------------------------------------------
>
>
>
>--
>MailScanner mailing list
>mailscanner at lists.mailscanner.info
>http://lists.mailscanner.info/mailman/listinfo/mailscanner
>
>Before posting, read http://wiki.mailscanner.info/posting
>
>Support MailScanner development - buy the book off the website!