You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@spamassassin.apache.org by Steve Martin <st...@planomartins.com> on 2005/08/23 04:04:25 UTC
Does this uridnsbl debug output indicate problems?
SA seems unusually slow today and I'm trying to figure out if I've
done something to my configuration that is causing the problem or if
it is just slow rbl lookups or something.
I ran spamassassin with -t and -D and this output looks like it may
be problematic, but I'm not sure what to look into.
The 21 second multi.surbl.org lookup seems pretty long and then what
are the following repeated messages about...
DNS lookups using other utilities seem reasonably fast, but I'm
wondering if SA is flooding the DNS server with more simultaneous
requests than it can handle or something.
[8121] dbg: plugin: Mail::SpamAssassin::Plugin::URIDNSBL=HASH
(0x1acbd14) implements 'check_tick'
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: query for networkforgood.org took 21 seconds to
look up (multi.surbl.org.:networkforgood.org)
[8121] dbg: uridnsbl: queries completed: 1 started: 0
[8121] dbg: uridnsbl: queries active: NS=1 at Mon Aug 22 20:46:44 2005
[8121] dbg: check: running tests for priority: 500
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 1 started: 5
[8121] dbg: uridnsbl: queries active: at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: select found 1 socks ready
[8121] dbg: uridnsbl: queries completed: 0 started: 0
[8121] dbg: uridnsbl: queries active: A=5 at Mon Aug 22 20:46:44 2005
[8121] dbg: uridnsbl: escaping: must have lost requests
[8121] dbg: uridnsbl: aborting remaining lookups
[8121] dbg: dns: success for 46 of 48 queries
[8121] dbg: dns: timeout for iadb-firsttrusted after 20 seconds
[8121] dbg: dns: timeout for sorbs after 20 seconds
--
Steve Martin http://www.cheezmo.com/
Smart Calibration, LLC http://www.smartcalibration.com/
The Widescreen Movie Center http://www.widemovies.com/
Letterboxed Movie TV Schedule http://www.widemovies.com/lbx.html
Re: Does this uridnsbl debug output indicate problems?
Posted by jdow <jd...@earthlink.net>.
That is the same thing I observed here after adding that plugin. I
am not sure if it is in the dnsbl code or the way ClamAV-plugin
uses the dnsbl code. Regardless it would be nifty were it to be
fixed.
{^_-}
----- Original Message -----
From: "Steve Martin" <st...@planomartins.com>
> Yes, in fact and that is part of it. But, in the process of
> investigating, I do think I found a bug (or at least an "issue") in
> the uridnsbl code.
>
> There is a check inside an inner loop there to see if any progress
> has been made reading the results of lookups and if nothing changes
> for 20 iterations, it aborts. Less than a second passes during those
> 20 iterations and I found that those lookups completed normally
> within another second or two if I simply increased that count.
> Details are in the bug report I submitted (search for URIDNSBL).
>
> On Aug 23, 2005, at 12:15 AM, jdow wrote:
>
>> You added ClamAV plugin?
>> {^_^}
>> ----- Original Message ----- From: "Steve Martin"
>> <st...@planomartins.com>
>>
>>
>>
>>> SA seems unusually slow today and I'm trying to figure out if
>>> I've done something to my configuration that is causing the
>>> problem or if it is just slow rbl lookups or something.
>>> I ran spamassassin with -t and -D and this output looks like it
>>> may be problematic, but I'm not sure what to look into.
>>> The 21 second multi.surbl.org lookup seems pretty long and then
>>> what are the following repeated messages about...
>>> DNS lookups using other utilities seem reasonably fast, but I'm
>>> wondering if SA is flooding the DNS server with more simultaneous
>>> requests than it can handle or something.
>>> [8121] dbg: plugin: Mail::SpamAssassin::Plugin::URIDNSBL=HASH
>>> (0x1acbd14) implements 'check_tick'
>>> [8121] dbg: uridnsbl: select found 1 socks ready
>>> [8121] dbg: uridnsbl: query for networkforgood.org took 21 seconds
>>> to look up (multi.surbl.org.:networkforgood.org)
>>> [8121] dbg: uridnsbl: queries completed: 1 started: 0
>>> [8121] dbg: uridnsbl: queries active: NS=1 at Mon Aug 22 20:46:44
>>> 2005
Re: Does this uridnsbl debug output indicate problems?
Posted by Steve Martin <st...@planomartins.com>.
Yes, in fact and that is part of it. But, in the process of
investigating, I do think I found a bug (or at least an "issue") in
the uridnsbl code.
There is a check inside an inner loop there to see if any progress
has been made reading the results of lookups and if nothing changes
for 20 iterations, it aborts. Less than a second passes during those
20 iterations and I found that those lookups completed normally
within another second or two if I simply increased that count.
Details are in the bug report I submitted (search for URIDNSBL).
On Aug 23, 2005, at 12:15 AM, jdow wrote:
> You added ClamAV plugin?
> {^_^}
> ----- Original Message ----- From: "Steve Martin"
> <st...@planomartins.com>
>
>
>
>> SA seems unusually slow today and I'm trying to figure out if
>> I've done something to my configuration that is causing the
>> problem or if it is just slow rbl lookups or something.
>> I ran spamassassin with -t and -D and this output looks like it
>> may be problematic, but I'm not sure what to look into.
>> The 21 second multi.surbl.org lookup seems pretty long and then
>> what are the following repeated messages about...
>> DNS lookups using other utilities seem reasonably fast, but I'm
>> wondering if SA is flooding the DNS server with more simultaneous
>> requests than it can handle or something.
>> [8121] dbg: plugin: Mail::SpamAssassin::Plugin::URIDNSBL=HASH
>> (0x1acbd14) implements 'check_tick'
>> [8121] dbg: uridnsbl: select found 1 socks ready
>> [8121] dbg: uridnsbl: query for networkforgood.org took 21 seconds
>> to look up (multi.surbl.org.:networkforgood.org)
>> [8121] dbg: uridnsbl: queries completed: 1 started: 0
>> [8121] dbg: uridnsbl: queries active: NS=1 at Mon Aug 22 20:46:44
>> 2005
>>
>
>
>
--
Steve Martin http://www.cheezmo.com/
Smart Calibration, LLC http://www.smartcalibration.com/
The Widescreen Movie Center http://www.widemovies.com/
Letterboxed Movie TV Schedule http://www.widemovies.com/lbx.html
Re: Does this uridnsbl debug output indicate problems?
Posted by jdow <jd...@earthlink.net>.
You added ClamAV plugin?
{^_^}
----- Original Message -----
From: "Steve Martin" <st...@planomartins.com>
> SA seems unusually slow today and I'm trying to figure out if I've
> done something to my configuration that is causing the problem or if
> it is just slow rbl lookups or something.
>
> I ran spamassassin with -t and -D and this output looks like it may
> be problematic, but I'm not sure what to look into.
>
> The 21 second multi.surbl.org lookup seems pretty long and then what
> are the following repeated messages about...
>
> DNS lookups using other utilities seem reasonably fast, but I'm
> wondering if SA is flooding the DNS server with more simultaneous
> requests than it can handle or something.
>
> [8121] dbg: plugin: Mail::SpamAssassin::Plugin::URIDNSBL=HASH
> (0x1acbd14) implements 'check_tick'
> [8121] dbg: uridnsbl: select found 1 socks ready
> [8121] dbg: uridnsbl: query for networkforgood.org took 21 seconds to
> look up (multi.surbl.org.:networkforgood.org)
> [8121] dbg: uridnsbl: queries completed: 1 started: 0
> [8121] dbg: uridnsbl: queries active: NS=1 at Mon Aug 22 20:46:44 2005