7min delay after loading Mail::SpamAssassin::Plugin::Check

[Peter Farrell <pe...@gmail.com>]

Investigating 12 minute/message processing time - SA hangs on
Mail::SpamAssassin::Plugin::Check.

I've commented out / disabled (pyzor / razor / dcc) as well as
everything except 'check main' in v320.pre. I removed all of the
rulesdujour as well.

How can I isolate this to figure it out?

Any ideas / pointers would be greatly appreciated...

-Peter Farrell
-Cardiff, Wales

SpamAssassin version 3.2.0
  running on Perl version 5.8.5
CentOS 4.4
Amavisd 2.5.1

# su vscan -c 'spamassassin -D < sample-nonspam.txt 2>&1' | timestamp


15:57:12.258 41.529 0.002 [1691] dbg: plugin: loading
Mail::SpamAssassin::Plugin::AWL from @INC
15:57:12.289 41.560 0.031 [1691] dbg: plugin: loading
Mail::SpamAssassin::Plugin::AutoLearnThreshold from @INC
15:57:12.300 41.570 0.011 [1691] dbg: plugin: loading
Mail::SpamAssassin::Plugin::WhiteListSubject from @INC
15:57:12.310 41.581 0.010 [1691] dbg: plugin: loading
Mail::SpamAssassin::Plugin::MIMEHeader from @INC
15:57:12.322 41.592 0.012 [1691] dbg: plugin: loading
Mail::SpamAssassin::Plugin::ReplaceTags from @INC
15:57:12.339 41.610 0.017 [1691] dbg: plugin: loading
Mail::SpamAssassin::Plugin::Check from @INC

16:04:22.982 472.252 430.643 [1691] dbg: rules: __MO_OL_9B90B merged
duplicates: __MO_OL_C65FA
16:04:22.983 472.253 0.000 [1691] dbg: rules: __XM_OL_22B61 merged
duplicates: __XM_OL_A842E
16:04:22.983 472.253 0.000 [1691] dbg: rules: __MO_OL_07794 merged
duplicates: __MO_OL_8627E __MO_OL_F3B05
16:04:22.984 472.254 0.001 [1691] dbg: rules: __XM_OL_07794 merged
duplicates: __XM_OL_25340 __XM_OL_3857F __XM_OL_4F240 __XM_OL_58CB5
__XM_OL_6554A __XM_OL_812FF __XM_OL_C65FA __XM_OL_CF0C0 __XM_OL_F475E
__XM_OL_F6D01
16:04:22.984 472.254 0.000 [1691] dbg: rules: FH_MSGID_01C67 merged
duplicates: __MSGID_VGA

Re: 7min delay after loading Mail::SpamAssassin::Plugin::Check

[Matthias Leisi <ma...@leisi.net>]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1



Peter Farrell wrote:
> Investigating 12 minute/message processing time - SA hangs on
> Mail::SpamAssassin::Plugin::Check.

One thing to investigate: Nameservers.

I just had a case where mails were being unexplicably delayed. It turned
out that the BIND caching resolvers were hitting a default limit of
1'000 concurrent queries.

This resulted in multiple retries on the *local* resolver, which caused
the number of waiting spamd processes to considerably increase.

So if you're using BIND as a resolver, look for any weirdness in the logs.

I believe the quota of concurrent recursive queries was reached due to
the recent DoS on DNSBLs, which caused DNS queries to run slower/longer,
and thus more DNS queries to be in processing at the same time.
Obviously, the overall system was hitting an unplanned bottleneck.

Lesson learned: Make sure to have sufficient spare resources in your DNS
setup.

- -- Matthias

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.2 (GNU/Linux)

iD8DBQFGfXILxbHw2nyi/okRAtNIAKCnnyq/mCVxdAt8eOAs4WVuJLZ3kgCgszQ7
YkLnkPmoFfHWrUIEKKmT8c4=
=wTpe
-----END PGP SIGNATURE-----