You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@spamassassin.apache.org by bu...@bugzilla.spamassassin.org on 2007/03/21 01:14:04 UTC

[Bug 5384] New: uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384

           Summary: uridnsbl interaction with skip_rbl_checks in 3.2.0,
                    differing behavior from 3.1.8
           Product: Spamassassin
           Version: SVN Trunk (Latest Devel Version)
          Platform: PC
        OS/Version: Linux
            Status: NEW
          Severity: normal
          Priority: P5
         Component: Plugins
        AssignedTo: dev@spamassassin.apache.org
        ReportedBy: yusufg@outblaze.com


I was playing around with 3.2.0pre3 and I observed a behavior
which at least to me is different from 3.1.8. Was wondering if you are
seeing similar behavior or its just something I might have done

In 3.1.8, the plugin URIDNSBL.pm is dependent on the config variable
dns_available and the value of the variable skip_rbl_checks has no
bearing on whether the plugin fires or not. ie, skip_rbl_checks 1 will also fire
this message as well as skip_rbl_checks 0

However in 3.2.0, the same plugin seems to rely on the variable
skip_rbl_checks as well as dns_available to determine if it fires. ie, this
plugin only fires if skip_rbl_checks = 0 and will not fire if skip_rbl_checks = 1

This is how I tested

compile 3.1.8 from tarball, install in /usr/local/site/sa318
compile 3.2.0pre3 from tarball, install in /usr/local/site/sa320

create a message with a domain in multiple SURBL lists. I used
'http://zzzyf.com/' which as of this writing is in SURBL_JP as well as SURBL_OB

create a file 'user_prefs' in both directory with the following setting

dns_available yes
skip_rbl_checks 1

Invoke SA as follows,

/path/to/appropiate/spamassassin -x -D -p user_prefs < mail-message > output 2>&1

3.1.8 scores the message as hitting 2 rules, 3.2.0 will not score the
message unless skip_rbl_checks is set to '0'

Can anybody else reproduce this behavior ?



------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384





------- Additional Comments From yusufg@outblaze.com  2007-04-09 08:18 -------
This is standard perl Makefile.PL PREFIX=<prefix-dir> install. 

I have the following user_prefs file though. 

use_bayes 0
use_bayes_rules 0
bayes_auto_learn 0
use_auto_whitelist 0

dns_available yes
use_razor2 0
use_dcc 0
use_pyzor 0
skip_rbl_checks 1
use_hashcash 0

report_safe 0
required_hits 5.0

score DNS_FROM_AHBL_RHSBL 0
score DNS_FROM_RFC_ABUSE 0
score DNS_FROM_RFC_BOGUSMX 0
score DNS_FROM_RFC_DSN 0
score DNS_FROM_RFC_POST 0
score DNS_FROM_RFC_WHOIS 0
score NO_DNS_FOR_FROM 0 
score ROUND_THE_WORLD 0

I am going to experiment with a massively reduced user_prefs file and see if I
can reproduce this




------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384





------- Additional Comments From mattheww@nmgi.com  2007-04-11 13:20 -------
Created an attachment (id=3899)
 --> (http://issues.apache.org/SpamAssassin/attachment.cgi?id=3899&action=view)
patch to URIDNSBL.pm; fixes 5384

$scanner->{query_launch_time} was not being set by the async start_lookup
(unlike when normal DNSBL lookups are kicked off), which was causing
harvest_dnsbl_queries to always skip itself.



------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384





------- Additional Comments From mattheww@nmgi.com  2007-04-12 05:26 -------
Created an attachment (id=3900)
 --> (http://issues.apache.org/SpamAssassin/attachment.cgi?id=3900&action=view)
fix some debugging inaccuracies (AsyncLoop.pm and Dns.pm), and add the
rbl_min_time conf setting.  See the change to Conf.pm for the explanation.

While debugging, I ran across some debugging inaccuracies... I would have
submitted this yesterday afternoon, but my ISP has been down.  Also, I
implemented the minimum rbl wait setting that Daryl suggested/requested. 
Please at least use/apply the debugging fixes (from "# URIDNSBL queries were
producing" to "$deadline - $self->{async}->get_last_start_lookup_time();" in
Dns.pm and from "# These should not be reset here" to
"#$self->{queries_completed} = 0;" in AsyncLoop.pm.

Index: AsyncLoop.pm
===================================================================
--- AsyncLoop.pm	(revision 527887)
+++ AsyncLoop.pm	(working copy)
@@ -185,8 +185,10 @@
     return 1;		 # nothing left to do
   }
 
-  $self->{queries_started} = 0;
-  $self->{queries_completed} = 0;
+  # These should not be reset here, if $self->{queries_started}++
+  # in start_lookup means anything.  Fixes imprecise debug output.
+  #$self->{queries_started} = 0;
+  #$self->{queries_completed} = 0;
 
   # trap this loop in an eval { } block, as Net::DNS could throw
   # die()s our way; in particular, process_dnsbl_results() has
Index: Conf.pm
===================================================================
--- Conf.pm	(revision 527887)
+++ Conf.pm	(working copy)
@@ -2436,6 +2436,26 @@
     type => $CONF_TYPE_NUMERIC
   });
 
+=item rbl_min_time n		(default: 3)
+
+Overrides the dynamic RBL timeout algorithm with a minimum RBL timeout, in
+seconds.  If you set this to the same value as rbl_timeout, SpamAssassin 
+will timeout exactly n seconds after the last DNSBL query was initiated, if
+at least of the DNSBL queries has not returned.
+
+If you leave this setting too low, some spam messages may avoid hits on DNSBL
+rules (including URIDNSBL rules) by ensuring that most of their DNS lookups
+return quickly, by configuring the "payload" URI's nameservers (for example)
+to induce lookup delays longer than your rbl_min_time.
+
+=cut
+
+  push (@cmds, {
+    setting => 'rbl_min_time',
+    default => 3,
+    type => $CONF_TYPE_NUMERIC
+  });
+
 =item util_rb_tld tld1 tld2 ...
 
 This option allows the addition of new TLDs to the RegistrarBoundaries code.
Index: Dns.pm
===================================================================
--- Dns.pm	(revision 527887)
+++ Dns.pm	(working copy)
@@ -349,7 +349,11 @@
     my $dynamic = (int($self->{conf}->{rbl_timeout}
		       * (1 - (($total - scalar @left) / $total) ** 2) + 0.5)
		   + $self->{async}->get_last_start_lookup_time());
-    $deadline = $dynamic if ($dynamic < $deadline);
+    # give the queries at least $self->{conf}->{rbl_min_time} seconds
+    # (default to 3) past the time the last query started (a minimum wait time

+    # to override the dynamically calculated one)
+    $deadline = $dynamic if ($dynamic < $deadline && 
+      ($self->{async}->get_last_start_lookup_time() +
$self->{conf}->{rbl_min_time} <= $dynamic) );
     $now = time;
   }
 }
@@ -374,7 +378,11 @@
     my $dynamic = (int($self->{conf}->{rbl_timeout}
		       * (1 - (($total - scalar @left) / $total) ** 2) + 0.5)
		   + $self->{async}->get_last_start_lookup_time());
-    $deadline = $dynamic if ($dynamic < $deadline);
+    # give the queries at least $self->{conf}->{rbl_min_time} seconds
+    # (default to 3) past the time the last query started (a minimum wait time

+    # to override the dynamically calculated one)
+    $deadline = $dynamic if ($dynamic < $deadline && 
+      ($self->{async}->get_last_start_lookup_time() +
$self->{conf}->{rbl_min_time} <= $dynamic) );
     $now = time;    # and loop again
   }
 
@@ -390,7 +398,18 @@
     elsif (defined @{$query->{rules}}) {
       $string = join(",", grep defined, @{$query->{rules}});
     }
-    my $delay = time - $self->{async}->get_last_start_lookup_time();
+    # URIDNSBL queries were producing an empty $string for debug
+    elsif (exists $query->{key} && defined $query->{key}) {
+      $string = $query->{key};
+    }
+    my $delay = (exists $query->{obj} && defined $query->{obj}
+      && defined $query->{obj}->{querystart})?
+      # use $deadline instead of time() because it more accurately represents
+      # what occurred.
+      # It's an URIDNSBL query; use its own start time to be precise.
+      $deadline - $query->{obj}->{querystart}:
+      # Use the start time of the last DNSBL query to start.
+      $deadline - $self->{async}->get_last_start_lookup_time();
     dbg("dns: timeout for $string after $delay seconds");
   }




------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384


jm@jmason.org changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
   Target Milestone|Undefined                   |3.2.0




------- Additional Comments From jm@jmason.org  2007-04-06 02:45 -------
may have time to fix this for 3.2.0



------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384





------- Additional Comments From yusufg@outblaze.com  2007-04-05 18:18 -------
Created an attachment (id=3897)
 --> (http://issues.apache.org/SpamAssassin/attachment.cgi?id=3897&action=view)
debug output with skip_rbl_checks 0




------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384





------- Additional Comments From spamassassin@dostech.ca  2007-04-10 17:32 -------
The effect actually gets worse the faster your DNS is.  This morning I witnessed
the same URIDNSBL test timeout about 49 of 50 times when all of the DNS queries
were being answered directly from a single server on the local LAN.



------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384





------- Additional Comments From felicity@apache.org  2007-04-06 07:49 -------
fwiw, I looked at this when it was mentioned on IRC, and couldn't reproduce the
problem nor see how it would happen in the code.



------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384





------- Additional Comments From yusufg@outblaze.com  2007-04-05 18:22 -------
URIDNSBL.pm invokes register_async_rule_start, I couldn't seem to find any
correlation with async dns lookups being tied to the setting of skip_rbl_check
The debug output I posted earlier was done with 3.2.0-rc1





------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384





------- Additional Comments From jm@jmason.org  2007-04-09 04:03 -------
yeah, I can't reproduce this either:

: jm 219...; cat user_prefs1

dns_available yes
skip_rbl_checks 0

: exit=0 Mon Apr  9 11:59:42 IST 2007; cd /home/jm/ftp/spamassassin
: jm 220...; cat user_prefs2

dns_available yes
skip_rbl_checks 1

: exit=0 Mon Apr  9 11:59:44 IST 2007; cd /home/jm/ftp/spamassassin
: jm 221...; ./spamassassin -p user_prefs1 -t < tst  | grep URIBL
        URIBL_JP_SURBL,URIBL_OB_SURBL autolearn=no version=3.2.0-rc1-r522258
 2.9 URIBL_JP_SURBL         Contains an URL listed in the JP SURBL blocklist
 2.1 URIBL_OB_SURBL         Contains an URL listed in the OB SURBL blocklist
: exit=0 Mon Apr  9 11:59:55 IST 2007; cd /home/jm/ftp/spamassassin
: jm 222...; ./spamassassin -p user_prefs2 -t < tst  | grep URIBL
        URIBL_JP_SURBL,URIBL_OB_SURBL autolearn=no version=3.2.0-rc1-r522258
 2.9 URIBL_JP_SURBL         Contains an URL listed in the JP SURBL blocklist
 2.1 URIBL_OB_SURBL         Contains an URL listed in the OB SURBL blocklist
: exit=0 Mon Apr  9 12:00:04 IST 2007; cd /home/jm/ftp/spamassassin
: jm 223...;   

"tst" is your test message btw.

are you sure you don't have some kind of shortcircuiting-related stuff active?



------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384


spamassassin@dostech.ca changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |RESOLVED
         Resolution|                            |FIXED




------- Additional Comments From spamassassin@dostech.ca  2007-04-11 23:29 -------
Thanks Matthew!  I had figured it was a timeout issue... didn't quite expect that.

Fixed by getting M::SA::AsyncLoop to take care of setting the query start times
so that other plugins (like the ASN plugin) don't have to worry about it.

[dos@cyan trunk]$ svn ci --file comments.txt
Sending        lib/Mail/SpamAssassin/AsyncLoop.pm
Sending        lib/Mail/SpamAssassin/Dns.pm
Sending        lib/Mail/SpamAssassin/Plugin/URIDNSBL.pm
Sending        rules/25_uribl.cf
Sending        t/config.dist
Transmitting file data .....
Committed revision 527786.
[dos@cyan trunk]$ vim t/config.dist
[dos@cyan trunk]$ svn ci -m "bah, twice today"
Sending        t/config.dist
Transmitting file data .
Committed revision 527787.
[dos@cyan trunk]$



------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384





------- Additional Comments From yusufg@outblaze.com  2007-04-05 18:17 -------
Created an attachment (id=3896)
 --> (http://issues.apache.org/SpamAssassin/attachment.cgi?id=3896&action=view)
debug output with skip_rbl_checks 1




------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384





------- Additional Comments From yusufg@outblaze.com  2007-04-10 17:16 -------
FWIW, I have a local copy of multi.surbl.org and the sa install under test was
configured to use a resolver with a split-horizon lookup of that database. Thus
the SURBL lookup was basically in my LAN and there was no WAN latency at all





------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384





------- Additional Comments From spamassassin@dostech.ca  2007-04-10 14:46 -------
Make sure it's still reproducible when you set both rbl_timeout and
uridnsbl_timeout to something really high, like 1000.  I have a feeling that the
URIDNSBL tests are just timing out (the dynamic timeouts really need a lower
limit implemented).  With rbl checks disabled there's even less time for the
URIDNSBL checks.



------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.

[Bug 5384] uridnsbl interaction with skip_rbl_checks in 3.2.0, differing behavior from 3.1.8

Posted by bu...@bugzilla.spamassassin.org.
http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5384





------- Additional Comments From jm@jmason.org  2007-04-10 08:33 -------
hmm, that's interesting.  using that full config file, it fails... so I now have
it repro'd.   this appears to be the minimal file that disables the check:


score NO_DNS_FOR_FROM 0
skip_rbl_checks 1


comment either of those lines, and it'll run the rules fine.  once both are in
place, the rules are inhibited.  "dns_available yes" is optional too btw.



------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.