BIND non-cached resolution taking 2-4 seconds each time

[Kevin Darcy]

ee99ee at gmail.com wrote:
> I'm having a problem with BIND 9 taking FOREVER to resolve DNS
> requests. Both are fresh installs of CentOS on PIII hardware. Both are
> in a well connected network (2 full DS-3's that aren't very used from
> two providers; we do our own BGP).
>
> Here is my named.conf:
>
> ------------------------------------
> acl recurseallow {
>         208.67.56.0/22;
>         127.0.0.1;
> };
>
> acl trusted {
> };
>
> options {
>         directory "/var/named";
>         allow-transfer { trusted; };
>         allow-recursion { recurseallow; };
>         query-source port 53;
> };
>
> include "/etc/rndc.key";
>
> zone "." {
>        type hint;
>        file "named.root";
> };
> ------------------------------------
>
> Here is my root hints file:
> ------------------------------------
>                        6D  IN      NS      A.ROOT-SERVERS.NET.
>                        6D  IN      NS      B.ROOT-SERVERS.NET.
>                        6D  IN      NS      C.ROOT-SERVERS.NET.
>                        6D  IN      NS      D.ROOT-SERVERS.NET.
>                        6D  IN      NS      E.ROOT-SERVERS.NET.
>                        6D  IN      NS      F.ROOT-SERVERS.NET.
>                        6D  IN      NS      G.ROOT-SERVERS.NET.
>                        6D  IN      NS      H.ROOT-SERVERS.NET.
>                        6D  IN      NS      I.ROOT-SERVERS.NET.
>                        6D  IN      NS      J.ROOT-SERVERS.NET.
>                        6D  IN      NS      K.ROOT-SERVERS.NET.
>                        6D  IN      NS      L.ROOT-SERVERS.NET.
>                        6D  IN      NS      M.ROOT-SERVERS.NET.
> A.ROOT-SERVERS.NET.     6D  IN      A       198.41.0.4
> B.ROOT-SERVERS.NET.     6D  IN      A       128.9.0.107
> C.ROOT-SERVERS.NET.     6D  IN      A       192.33.4.12
> D.ROOT-SERVERS.NET.     6D  IN      A       128.8.10.90
> E.ROOT-SERVERS.NET.     6D  IN      A       192.203.230.10
> F.ROOT-SERVERS.NET.     6D  IN      A       192.5.5.241
> G.ROOT-SERVERS.NET.     6D  IN      A       192.112.36.4
> H.ROOT-SERVERS.NET.     6D  IN      A       128.63.2.53
> I.ROOT-SERVERS.NET.     6D  IN      A       192.36.148.17
> J.ROOT-SERVERS.NET.     6D  IN      A       198.41.0.10
> K.ROOT-SERVERS.NET.     6D  IN      A       193.0.14.129
> L.ROOT-SERVERS.NET.     6D  IN      A       198.32.64.12
> M.ROOT-SERVERS.NET.     6D  IN      A       202.12.27.33
> ------------------------------------
>
> Here is the output of TCP dump doing a sample query after running "rndc
> flush" then "dig @localhost theplanet.com"
>
> ------------------------------------
> 08:50:04.249815 IP 208.67.56.6.domain > 193.0.14.129.domain:  11509%
> [1au] A? theplanet.com. (42)
> 08:50:04.251185 IP 208.67.56.6.domain > 193.0.14.129.domain:  6690%
> [1au] NS? . (28)
> 08:50:04.393408 IP 193.0.14.129.domain > 208.67.56.6.domain:  11509-
> 0/13/16 (530)
> 08:50:04.394688 IP 193.0.14.129.domain > 208.67.56.6.domain:  6690*-
> 13/0/14 NS a.root-servers.net.,[|domain]
> 08:50:06.397444 IP 208.67.56.6.domain > 192.55.83.30.domain:  13032%
> [1au] A? theplanet.com. (42)
> 08:50:06.651124 IP 192.55.83.30.domain > 208.67.56.6.domain:  13032
> FormErr- [0q] 0/0/0 (12)
> 08:50:06.651819 IP 208.67.56.6.domain > 192.55.83.30.domain:  3266 A?
> theplanet.com. (31)
> 08:50:06.909213 IP 192.55.83.30.domain > 208.67.56.6.domain:  3266-
> 0/2/12 (259)
> 08:50:06.910512 IP 208.67.56.6.domain > 207.44.128.230.domain:  17183%
> [1au] A? theplanet.com. (42)
> 08:50:06.956252 IP 207.44.128.230.domain > 208.67.56.6.domain:  17183*-
> 1/2/13 A 70.87.6.11 (286)
> ------------------------------------
>
>
> Notice the 2 second delay between lines 4 and 5? The result took 2.5
> seconds for dig to respond. Once it's cached, it takes only a few ms to
> get the same thing back, it's just that first time query that takes
> FOREVER.
>
>   
Well, you're running on a PIII, and after a flush, named has to 
re-create the whole cache structure -- notice the "priming" queries for 
the root zone which are occurring in parallel with the attempt to 
resolve theplanet.com. Could it just be that your box *normally* takes 2 
seconds to initialize its cache?

Flushes or restarts usually don't happen very frequently, so what's 
really the problem here?

                                                                         
                        - Kevin