bind 9.3.1 still causes delays in multiples of 2 seconds

Paul Boven p.boven at chello.nl
Tue Apr 26 15:06:58 UTC 2005


Hi Mark, everyone,

Mark Andrews wrote:

>>When asking a bind-9.3.1 to resolve something that's not in its cache, 
>>it will sit idle for 2 seconds (or multiples thereof) before asking 
>>asking some of the nameservers. But from prior discussions in this 
>>newsgroup, I thought this particular bug was fixed in the 9.3.1-release?

> 	Look at lib/dns/resolver.c:resquery_senddone().  There may
> 	be another error code that needs handling.  Currently we
> 	handle the following with a fast retry.
> 
>                 case ISC_R_HOSTUNREACH:
>                 case ISC_R_NETUNREACH:
>                 case ISC_R_NOPERM:
>                 case ISC_R_ADDRNOTAVAIL:
>                 case ISC_R_CONNREFUSED:

This might be tricky. After adding a few tracers, I found that the 
result code in question is always ISC_R_SUCCESS, see the trace below. 
The trace starts with the first queries being sent out by bind, which 
both go to IPv6 addresses of Dutch TLD servers. This causes 4 seconds of 
delay, once things go IPv4 the request finishes successfully.

These tests are done on a development machine, so the cache of this bind 
is mostly empty though it had already resolved Dutch (.nl) zones before. 
It's a Solaris 9 (Sparc) machine and has no IPv6 interfaces configured 
at all.
Which makes me wonder: why is Bind even trying to send IPv6 packets out, 
and then why do either Solaris or Bind conclude that sending them was 
successful? Time for more digging.

Regards, Paul Boven.

16:17:20.213 fctx 56a898(www.zonnig.nl/A'): query
16:17:20.213 resquery 55da58 (fctx 56a898(www.zonnig.nl/A)): send
16:17:20.213 dispatch 521178 response 55eeb8 2001:660:3005:1::1:2#53: 
attached to task 522668
16:17:20.214 resquery 55da58 (fctx 56a898(www.zonnig.nl/A)): sent
16:17:20.214 resquery 55da58 (fctx 56a898(www.zonnig.nl/A)): senddone
16:17:20.214 resquery 55da58 (fctx 56a898(www.zonnig.nl/A)): XXX 
senddone success
16:17:20.214 sockmgr 4dfd98: watcher got message -3
16:17:20.214 sockmgr 4dfd98: watcher got message -2

* 2 seconds delay

16:17:22.219 fctx 56a898(www.zonnig.nl/A'): timeout
16:17:22.219 fctx 56a898(www.zonnig.nl/A'): try
16:17:22.219 fctx 56a898(www.zonnig.nl/A'): query
16:17:22.219 resquery 5469e0 (fctx 56a898(www.zonnig.nl/A)): send
16:17:22.219 dispatch 521178 response 568cb0 2001:4f8:0:2::13#53: 
attached to task 522668
16:17:22.220 resquery 5469e0 (fctx 56a898(www.zonnig.nl/A)): sent
16:17:22.220 resquery 5469e0 (fctx 56a898(www.zonnig.nl/A)): senddone
16:17:22.220 resquery 5469e0 (fctx 56a898(www.zonnig.nl/A)): XXX 
senddone ISC_R_SUCCESS

* 2 seconds delay

16:17:24.229 fctx 56a898(www.zonnig.nl/A'): timeout
16:17:24.229 fctx 56a898(www.zonnig.nl/A'): try
16:17:24.229 fctx 56a898(www.zonnig.nl/A'): query
16:17:24.229 resquery 56fbf0 (fctx 56a898(www.zonnig.nl/A)): send
16:17:24.229 dispatch 520d80 response 567830 193.0.12.155#53: attached 
to task 522668
16:17:24.230 resquery 56fbf0 (fctx 56a898(www.zonnig.nl/A)): sent
16:17:24.230 resquery 56fbf0 (fctx 56a898(www.zonnig.nl/A)): senddone
16:17:24.230 resquery 56fbf0 (fctx 56a898(www.zonnig.nl/A)): XXX 
senddone ISC_R_SUCCESS
16:17:24.233 socket 520f68: dispatch_recv:  event 561548 -> task 5210c8
16:17:24.233 socket 520f68: internal_recv: task 5210c8 got event 520fbc
16:17:24.233 socket 520f68 193.0.12.155#53: packet received correctly


.



More information about the bind-users mailing list