RE: spamd takes a long time to scan

2004-12-08 Thread Jon Dossey

> > On Mon, Dec 06, 2004 at 10:27:29AM -0600, Jon Dossey wrote:
> > > Wow!  0.1 seconds, now that's fast!
> > >
> > > Then I saw this: "tests=none"
> > >
> > > I guess it would be fast if it doesn't have to really *do*
anything!
> >
> > tests=none just mean that it didn't hit any rules, not that it
didn't
> run
> > any
> > rules.  You can try sending a GTUBE through.
> >
> > > So have we really narrowed it down at all?  We know that spamd is
> taking
> > > a long time during some test it performs, but we don't really know
> if
> > > its related to RBL checks.
> >
> > Well, we've proven it's network related, but haven't narrowed it
down
> to
> > which
> > network check.
> >
> > -D may help, I would probably try slowly reenabling things.  ie:
> remove -L
> > but
> > disable razor, dcc, pyzor, URIBL, etc.
> >
> > Also, check to see if you have any timeouts set to 15s.  The default
> RBL
> > timeout is 15s, so it could be that, but most of the queries would
> have to
> > fail to actually get to 15s (as queries return, the timeout gets
> lower).
> 
> First off, I'd like to thank you again for your and others help, Theo.
> I would have been completely lost without your help and suggestions,
and
> I really appreciate your patience.
> 
> I finally got a chance to take a look at this with debugging enabled
> (been very busy here), and noticed the following output:
> 
> Dec  8 10:08:13 dhgsrv17 spamd[1880]: debug: DNS: timeout for
> rfci_envfrom after 15 seconds
> Dec  8 10:08:13 dhgsrv17 spamd[1880]: debug: DNS: timeout for
> NO_DNS_FOR_FROM after 15 seconds
> Dec  8 10:08:13 dhgsrv17 spamd[1880]: debug: DNS: timeout for ahbl
after
> 15 seconds
> Dec  8 10:08:13 dhgsrv17 spamd[1880]: debug: DNS: timeout for
> NO_DNS_FOR_FROM after 15 seconds
> 
> Also worth noting:
> Dec  8 10:07:58 dhgsrv17 spamd[1880]: debug: URIDNSBL: domains to
query:
> Dec  8 10:07:58 dhgsrv17 spamd[1880]: debug: is Net::DNS::Resolver
> available? yes
> Dec  8 10:07:58 dhgsrv17 spamd[1880]: debug: Net::DNS version: 0.45
> 
> Now, I believe the problem *may* be due to the fact that I'm relaying
> off this host by connecting from my workstation on the SMTP port, with
> no reverse DNS entry.  Is it possible the resolver is timing trying to
> reverse my private IP address to a valid host name?

I think I just answered my own question.  I relayed from a host that it
easily resolved, and still had the same timeout issues running the RBL
tests:

Dec  8 10:28:35 dhgsrv17 spamd[1883]: debug: RBL: success for 0 of 4
queries
Dec  8 10:28:35 dhgsrv17 spamd[1883]: debug: DNS: timeout for
rfci_envfrom after 15 seconds
Dec  8 10:28:35 dhgsrv17 spamd[1883]: debug: DNS: timeout for
NO_DNS_FOR_FROM after 15 seconds
Dec  8 10:28:35 dhgsrv17 spamd[1883]: debug: DNS: timeout for ahbl after
15 seconds
Dec  8 10:28:35 dhgsrv17 spamd[1883]: debug: DNS: timeout for
NO_DNS_FOR_FROM after 15 seconds

Any idea where I should go from here?

Thanks,
.jon


__

"The information transmitted is intended only for the person or entity to 
which it is addressed and may contain confidential, proprietary, and/or 
privileged material.  Any review, retransmission, dissemination or other 
use of, or taking of any action in reliance upon, this information by 
persons or entities other than the intended recipient is prohibited.  
If you received this in error, please contact the sender and delete 
the material from all computers."


RE: spamd takes a long time to scan

2004-12-08 Thread Jon Dossey

> On Mon, Dec 06, 2004 at 10:27:29AM -0600, Jon Dossey wrote:
> > Wow!  0.1 seconds, now that's fast!
> >
> > Then I saw this: "tests=none"
> >
> > I guess it would be fast if it doesn't have to really *do* anything!
> 
> tests=none just mean that it didn't hit any rules, not that it didn't
run
> any
> rules.  You can try sending a GTUBE through.
> 
> > So have we really narrowed it down at all?  We know that spamd is
taking
> > a long time during some test it performs, but we don't really know
if
> > its related to RBL checks.
> 
> Well, we've proven it's network related, but haven't narrowed it down
to
> which
> network check.
> 
> -D may help, I would probably try slowly reenabling things.  ie:
remove -L
> but
> disable razor, dcc, pyzor, URIBL, etc.
> 
> Also, check to see if you have any timeouts set to 15s.  The default
RBL
> timeout is 15s, so it could be that, but most of the queries would
have to
> fail to actually get to 15s (as queries return, the timeout gets
lower).

First off, I'd like to thank you again for your and others help, Theo.
I would have been completely lost without your help and suggestions, and
I really appreciate your patience.

I finally got a chance to take a look at this with debugging enabled
(been very busy here), and noticed the following output:

Dec  8 10:08:13 dhgsrv17 spamd[1880]: debug: DNS: timeout for
rfci_envfrom after 15 seconds
Dec  8 10:08:13 dhgsrv17 spamd[1880]: debug: DNS: timeout for
NO_DNS_FOR_FROM after 15 seconds
Dec  8 10:08:13 dhgsrv17 spamd[1880]: debug: DNS: timeout for ahbl after
15 seconds
Dec  8 10:08:13 dhgsrv17 spamd[1880]: debug: DNS: timeout for
NO_DNS_FOR_FROM after 15 seconds

Also worth noting:
Dec  8 10:07:58 dhgsrv17 spamd[1880]: debug: URIDNSBL: domains to query:
Dec  8 10:07:58 dhgsrv17 spamd[1880]: debug: is Net::DNS::Resolver
available? yes
Dec  8 10:07:58 dhgsrv17 spamd[1880]: debug: Net::DNS version: 0.45

Now, I believe the problem *may* be due to the fact that I'm relaying
off this host by connecting from my workstation on the SMTP port, with
no reverse DNS entry.  Is it possible the resolver is timing trying to
reverse my private IP address to a valid host name?

Thanks,
.jon


__

"The information transmitted is intended only for the person or entity to 
which it is addressed and may contain confidential, proprietary, and/or 
privileged material.  Any review, retransmission, dissemination or other 
use of, or taking of any action in reliance upon, this information by 
persons or entities other than the intended recipient is prohibited.  
If you received this in error, please contact the sender and delete 
the material from all computers."


Re: spamd takes a long time to scan

2004-12-06 Thread Matt Kettler
At 10:47 AM 12/6/2004, Jon Dossey wrote:
Redhat FC2, spamassassin-3.0.1, spamass-milter 0.2.0
This is a Compaq DL360 (Dual 1.3ghz Xeon with 1GB of RAM, 36.4 U320 scsi
raid 0+1).
Dec  6 09:25:30 dhgsrv17 spamd[1781]: clean message (0.1/5.0) for
root:500 in 15.2 seconds, 1531 bytes.
15.2 seconds to scan a message that simply contained:
*shrug*.. does this happen often, or once in a while?
The reason I ask is SA does bayes and AWL database maintenance sometimes.
Otherwise, I'd consider running a similar message through with spamd 
running in debug mode.. see if the RBL timeouts are getting you, or some 
such thing.. (15 seconds sounds suspiciously like razor delays, if you use 
razor)



Re: spamd takes a long time to scan

2004-12-06 Thread Theo Van Dinter
On Mon, Dec 06, 2004 at 10:27:29AM -0600, Jon Dossey wrote:
> Wow!  0.1 seconds, now that's fast!  
> 
> Then I saw this: "tests=none"
> 
> I guess it would be fast if it doesn't have to really *do* anything!

tests=none just mean that it didn't hit any rules, not that it didn't run any
rules.  You can try sending a GTUBE through.

> So have we really narrowed it down at all?  We know that spamd is taking
> a long time during some test it performs, but we don't really know if
> its related to RBL checks.

Well, we've proven it's network related, but haven't narrowed it down to which
network check.

-D may help, I would probably try slowly reenabling things.  ie: remove -L but
disable razor, dcc, pyzor, URIBL, etc.

Also, check to see if you have any timeouts set to 15s.  The default RBL
timeout is 15s, so it could be that, but most of the queries would have to
fail to actually get to 15s (as queries return, the timeout gets lower).

-- 
Randomly Generated Tagline:
: No comment, since this is still hovering (see Larry's reply).
 
 Flutter, flutter.
  -- Larry Wall in <[EMAIL PROTECTED]>


pgpUIIrlGuam1.pgp
Description: PGP signature


RE: spamd takes a long time to scan

2004-12-06 Thread Jon Dossey

> On Mon, Dec 06, 2004 at 10:11:26AM -0600, Jon Dossey wrote:
> > Machine is a nameserver (bind 9.3.0), load average 0.00 0.00 0.00
(test
> > machine, not in production).  I tried changing skip_rbl_checks to 1,
and
> > testing again.  Took 15.1 seconds to process.
> 
> Run spamd with -L.  skip_rbl_checks only skips the RBL checks.  Could
be
> Razor, DCC, URIBL (I think it ignores skip_rbl_checks), etc.

We've got a winner!

Dec  6 10:23:29 dhgsrv17 spamd[31064]: got connection over
/var/run/spamd.socket
Dec  6 10:23:29 dhgsrv17 spamd[31064]: processing message (unknown) for
root:500.
Dec  6 10:23:29 dhgsrv17 spamd[31064]: clean message (0.0/5.0) for
root:500 in 0.1 seconds, 344 bytes.
Dec  6 10:23:29 dhgsrv17 spamd[31064]: result: .  0 -
scantime=0.1,size=344,mid=(unknown),autolearn=failed

Wow!  0.1 seconds, now that's fast!  

Then I saw this: "tests=none"

I guess it would be fast if it doesn't have to really *do* anything!

So have we really narrowed it down at all?  We know that spamd is taking
a long time during some test it performs, but we don't really know if
its related to RBL checks.

Thanks for your help so far Theo.

.jon


__

"The information transmitted is intended only for the person or entity to 
which it is addressed and may contain confidential, proprietary, and/or 
privileged material.  Any review, retransmission, dissemination or other 
use of, or taking of any action in reliance upon, this information by 
persons or entities other than the intended recipient is prohibited.  
If you received this in error, please contact the sender and delete 
the material from all computers."


Re: spamd takes a long time to scan

2004-12-06 Thread Theo Van Dinter
On Mon, Dec 06, 2004 at 10:11:26AM -0600, Jon Dossey wrote:
> Machine is a nameserver (bind 9.3.0), load average 0.00 0.00 0.00 (test
> machine, not in production).  I tried changing skip_rbl_checks to 1, and
> testing again.  Took 15.1 seconds to process.

Run spamd with -L.  skip_rbl_checks only skips the RBL checks.  Could be
Razor, DCC, URIBL (I think it ignores skip_rbl_checks), etc.

-- 
Randomly Generated Tagline:
All computers wait at the same speed.


pgpzWURdjv5WA.pgp
Description: PGP signature


RE: spamd takes a long time to scan

2004-12-06 Thread Jon Dossey

> On Mon, Dec 06, 2004 at 09:47:02AM -0600, Jon Dossey wrote:
> > Dec  6 09:25:30 dhgsrv17 spamd[1781]: clean message (0.1/5.0) for
> > root:500 in 15.2 seconds, 1531 bytes.
> >
> > Any idea why its taking so long?  Running an older version of
> > spamassassin on a 233mhz PII scans take only about 5-6 seconds.
> 
> You're very likely having network test timeouts.  Make sure you have
> Net::DNS
> and your nameservers configured correctly.

Machine is a nameserver (bind 9.3.0), load average 0.00 0.00 0.00 (test
machine, not in production).  I tried changing skip_rbl_checks to 1, and
testing again.  Took 15.1 seconds to process.

Dec  6 10:06:40 dhgsrv17 spamd[31008]: got connection over
/var/run/spamd.socket
Dec  6 10:06:40 dhgsrv17 spamd[31008]: processing message (unknown) for
root:500.
Dec  6 10:06:55 dhgsrv17 spamd[31008]: clean message (0.0/5.0) for
root:500 in 15.6 seconds, 362 bytes.
Dec  6 10:06:55 dhgsrv17 spamd[31008]: result: .  0 - MISSING_DATE
scantime=15.6,size=362,mid=(unknown),autolearn=failed

Also, it looks like its not giving up uid 0, and dropping to the
specified user.  From ps:

spamd31000  0.4  2.5 28876 23012 ?   S10:05   0:00
/usr/bin/spamd -d -m5 --username=spamd --pidfile=/home/spamd/spamd.pid
--socketpath=/var/run/spamd.socket

(yes, spamd.pid should be in /var/run, I'll get it in a minute)

.jon


__

"The information transmitted is intended only for the person or entity to 
which it is addressed and may contain confidential, proprietary, and/or 
privileged material.  Any review, retransmission, dissemination or other 
use of, or taking of any action in reliance upon, this information by 
persons or entities other than the intended recipient is prohibited.  
If you received this in error, please contact the sender and delete 
the material from all computers."


Re: spamd takes a long time to scan

2004-12-06 Thread Theo Van Dinter
On Mon, Dec 06, 2004 at 09:47:02AM -0600, Jon Dossey wrote:
> Dec  6 09:25:30 dhgsrv17 spamd[1781]: clean message (0.1/5.0) for
> root:500 in 15.2 seconds, 1531 bytes.
> 
> Any idea why its taking so long?  Running an older version of
> spamassassin on a 233mhz PII scans take only about 5-6 seconds.

You're very likely having network test timeouts.  Make sure you have Net::DNS
and your nameservers configured correctly.

-- 
Randomly Generated Tagline:
But I know what's important to me, and what isn't.  And I think I know what
 people can get used to, and what they can even learn to like.  (It just takes
 some people longer than others. :-)
  -- Larry Wall in <[EMAIL PROTECTED]>


pgp19FJYPnTKB.pgp
Description: PGP signature