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.