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 2015/12/10 21:18:58 UTC

[Bug 7275] New: Significant delays with Net::DNS 1.02 and later

https://bz.apache.org/SpamAssassin/show_bug.cgi?id=7275

            Bug ID: 7275
           Summary: Significant delays with Net::DNS 1.02 and later
           Product: Spamassassin
           Version: 3.4.1
          Hardware: PC
                OS: Windows NT
            Status: NEW
          Severity: normal
          Priority: P2
         Component: spamassassin
          Assignee: dev@spamassassin.apache.org
          Reporter: quanah@zimbra.com

Using Net::DNS 0.81, email delivery is quite fast.  After switching to Net::DNS
1.02 or 1.04, a 15 second delay PER email is introduced during SA DNS lookups.

I have applied the patch for bug#7223 and bug#7265 to my SpamAssassin build. 
However, the issue persists despite those fixes.  Logs look like:

Dec 10 14:03:50 zre-ldap002 amavis[27263]: (27263-01) lookup
[banned_namepath_re] => undef,
"P=p003\tL=1\tM=multipart/alternative\nP=p001\tL=1/1\tM=text/plain\tT=asc" does
not match
Dec 10 14:03:56 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns: select timed
out 1.000 s
Dec 10 14:03:56 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: select
found no responses ready (t.o.=1.0)
Dec 10 14:03:56 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
completed: 0, started: 0
Dec 10 14:03:56 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
active: DNSBL-A=1 DNSBL-MX=1 TXT=1 at Thu Dec 10 14:03:56 2015
Dec 10 14:03:56 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns:
harvest_dnsbl_queries - check_tick
Dec 10 14:03:57 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns: select timed
out 1.000 s
Dec 10 14:03:57 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: select
found no responses ready (t.o.=1.0)
Dec 10 14:03:57 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
completed: 0, started: 0
Dec 10 14:03:57 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
active: DNSBL-A=1 DNSBL-MX=1 TXT=1 at Thu Dec 10 14:03:57 2015
Dec 10 14:03:57 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns:
harvest_dnsbl_queries - check_tick
Dec 10 14:03:58 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns: select timed
out 1.000 s
Dec 10 14:03:58 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: select
found no responses ready (t.o.=1.0)
Dec 10 14:03:58 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
completed: 0, started: 0
Dec 10 14:03:58 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
active: DNSBL-A=1 DNSBL-MX=1 TXT=1 at Thu Dec 10 14:03:58 2015
Dec 10 14:03:58 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns:
harvest_dnsbl_queries - check_tick
Dec 10 14:03:59 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns: select timed
out 1.000 s
Dec 10 14:03:59 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: select
found no responses ready (t.o.=1.0)
Dec 10 14:03:59 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
completed: 0, started: 0
Dec 10 14:03:59 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
active: DNSBL-A=1 DNSBL-MX=1 TXT=1 at Thu Dec 10 14:03:59 2015
Dec 10 14:03:59 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns:
harvest_dnsbl_queries - check_tick
Dec 10 14:04:00 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns: select timed
out 1.000 s
Dec 10 14:04:00 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: select
found no responses ready (t.o.=1.0)
Dec 10 14:04:00 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
completed: 0, started: 0
Dec 10 14:04:00 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
active: DNSBL-A=1 DNSBL-MX=1 TXT=1 at Thu Dec 10 14:04:00 2015
Dec 10 14:04:00 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns:
harvest_dnsbl_queries - check_tick
Dec 10 14:04:01 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns: select timed
out 1.000 s
Dec 10 14:04:01 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: select
found no responses ready (t.o.=1.0)
Dec 10 14:04:01 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
completed: 0, started: 0
Dec 10 14:04:01 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
active: DNSBL-A=1 DNSBL-MX=1 TXT=1 at Thu Dec 10 14:04:01 2015
Dec 10 14:04:01 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns:
harvest_dnsbl_queries - check_tick
Dec 10 14:04:02 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns: select timed
out 1.000 s
Dec 10 14:04:02 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: select
found no responses ready (t.o.=1.0)
Dec 10 14:04:02 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
completed: 0, started: 0
Dec 10 14:04:02 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
active: DNSBL-A=1 DNSBL-MX=1 TXT=1 at Thu Dec 10 14:04:02 2015
Dec 10 14:04:02 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns:
harvest_dnsbl_queries - check_tick
Dec 10 14:04:03 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns: select timed
out 1.000 s
Dec 10 14:04:03 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: select
found no responses ready (t.o.=1.0)
Dec 10 14:04:03 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
completed: 0, started: 0
Dec 10 14:04:03 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
active: DNSBL-A=1 DNSBL-MX=1 TXT=1 at Thu Dec 10 14:04:03 2015
Dec 10 14:04:03 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns:
harvest_dnsbl_queries - check_tick
Dec 10 14:04:04 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns: select timed
out 1.000 s
Dec 10 14:04:04 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: select
found no responses ready (t.o.=1.0)
Dec 10 14:04:04 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
completed: 0, started: 0
Dec 10 14:04:04 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
active: DNSBL-A=1 DNSBL-MX=1 TXT=1 at Thu Dec 10 14:04:04 2015
Dec 10 14:04:04 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns:
harvest_dnsbl_queries - check_tick
Dec 10 14:04:04 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: reducing
select timeout from 1.0 to 0.8 s
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: dns: select timed
out 0.831 s
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: select
found no responses ready (t.o.=0.8)
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: queries
completed: 0, started: 0
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: escaping:
lost or timed out requests or responses
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: aborting
after 15.010 s, past original deadline: TXT,
askdns:TXT:_dmarc.zre-ldap002.eng.zimbra.com
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: aborting
after 15.002 s, past original deadline: NO_DNS_FOR_FROM, DNSBL-A,
dns:A:zre-ldap002.eng.zimbra.com
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: aborting
after 15.001 s, past original deadline: NO_DNS_FOR_FROM, DNSBL-MX,
dns:MX:zre-ldap002.eng.zimbra.com
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: calling
callback/abort on key A/zre-ldap002.eng.zimbra.com
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: calling
callback/abort on key TXT/_dmarc.zre-ldap002.eng.zimbra.com
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: calling
callback/abort on key MX/zre-ldap002.eng.zimbra.com
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: aborted 3
remaining lookups
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: timing:
15.001 X dns:MX:zre-ldap002.eng.zimbra.com
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: timing:
15.002 X dns:A:zre-ldap002.eng.zimbra.com
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: async: timing:
15.010 X askdns:TXT:_dmarc.zre-ldap002.eng.zimbra.com
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: rules: running
one_line_body tests; score so far=-1.009
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: rules: running
head tests; score so far=-1.009
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: rules: running
body tests; score so far=-1.009
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: rules: running
uri tests; score so far=-1.009
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: rules: running
rawbody tests; score so far=-1.009
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: rules: running
full tests; score so far=-1.009
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: rules: running
meta tests; score so far=-1.009
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: plugin:
Mail::SpamAssassin::Plugin::AutoLearnThreshold=HASH(0x5f0ce58) implements
'autolearn_discriminator', priority 0
Dec 10 14:04:05 zre-ldap002 amavis[27263]: (27263-01) SA dbg: learn:
auto-learn: currently using scoreset 1

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

[Bug 7275] Significant delays with Net::DNS 1.02 and later

Posted by bu...@bugzilla.spamassassin.org.
https://bz.apache.org/SpamAssassin/show_bug.cgi?id=7275

--- Comment #2 from Quanah Gibson-Mount <qu...@zimbra.com> ---
Worked correctly after updating patch. ;)

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

[Bug 7275] Significant delays with Net::DNS 1.02 and later

Posted by bu...@bugzilla.spamassassin.org.
https://bz.apache.org/SpamAssassin/show_bug.cgi?id=7275

Quanah Gibson-Mount <qu...@zimbra.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |quanah@zimbra.com
         Resolution|---                         |INVALID
             Status|NEW                         |RESOLVED

--- Comment #1 from Quanah Gibson-Mount <qu...@zimbra.com> ---
Bah, never mind... Used an outdated patch.  grr.

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