<html>
  <head>

    <meta http-equiv="content-type" content="text/html; charset=ISO-8859-1">
  </head>
  <body bgcolor="#FFFFFF" text="#000000">
    Hi,<br>
    <br>
    On 09/19/11 14:08, W.C.A. Wijngaards wrote:
    <blockquote class=" cite" id="mid_4E7730DB_9030506_nlnetlabs_nl"
      cite="mid:4E7730DB.9030506@nlnetlabs.nl" type="cite">
      <pre wrap="">-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Hi Attila,

On 09/19/2011 01:03 PM, Attila Nagy wrote:
</pre>
      <blockquote class=" cite" id="Cite_24" type="cite">
        <pre wrap="">Hi,

There is a problem with resolving names from dipmap.com with unbound.
Currently, the root NSs give back three nameservers, from which only one
works (at least from our network).
And that one has a bad NS RR:
$ dig ns dipmap.com @ns.dipmap.com.

; <<>> DiG 9.6.-ESV-R4-P1 <<>> ns dipmap.com @ns.dipmap.com.
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 25982
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;dipmap.com.                    IN      NS

;; ANSWER SECTION:
dipmap.com.             60      IN      NS      sql2005.

It seems that unbound stores that nameserver and wants to query it, so
either a time out or a SERVFAIL happens to the client.
</pre>
      </blockquote>
      <pre wrap="">Yes it wants to query it, but in my test it quickly finds out that the
bad-name does not exist.  Then it tries the last resort: it falls back
to the parent nameserver NSset.  And this works.  So it works fine for me?</pre>
    </blockquote>
    Well, it works for me too for a while. Then it starts to not
    (SERVFAIL or timed out request, other queries get answered
    correctly). I do the testing with tirparkolo.dipmap.com.<br>
    <blockquote class=" cite" id="mid_4E7730DB_9030506_nlnetlabs_nl"
      cite="mid:4E7730DB.9030506@nlnetlabs.nl" type="cite">
      <pre wrap="">

</pre>
      <blockquote class=" cite" id="Cite_25" type="cite">
        <pre wrap="">I thought that a recursive DNS server shouldn't cache NS records from
the zone's authoritative name server, it should only trust in the upper
servers.
</pre>
      </blockquote>
      <pre wrap="">No, the child's server is the most authoritative for its NS record.  The
upper servers only give hints to reach the child.  But this zone is
misconfigured, yeah.</pre>
    </blockquote>
    Hmm, I thought the opposite is true, which makes more sense to me.
    I've seen a lot of cases where only one NS was working out of the X
    and that NS had totally different other nameservers than in the
    "internet view" (from the root NSes). Of course when the only
    working NS has disappeared, nobody could resolve the domain, no
    matter the domain's administrator set the correct nameservers (at
    least he thought he did) which were accessible.<br>
    Nobody queried them, because the administrator forgot to make the
    changes in the internet infrastrucutre (above his server).<br>
    <br>
    Does unbound re-checks the hints (the upper nameservers) for a given
    zone when the NS TTL expires?<br>
    <br>
    <blockquote class=" cite" id="mid_4E7730DB_9030506_nlnetlabs_nl"
      cite="mid:4E7730DB.9030506@nlnetlabs.nl" type="cite">
      <pre wrap="">

</pre>
      <blockquote class=" cite" id="Cite_26" type="cite">
        <pre wrap="">ISC BIND doesn't have this behaviour -it seems-, so it can resolve names
from this domain.
</pre>
      </blockquote>
      <pre wrap="">Well, so should we really.  Since it works for me, but not for you, can
you tell me what happens when it does not want to work: set verbosity to
4 and do a probe and look at the logs.  It should try the last resort.

This was added in 1.4.5 so if you are running older unbound, that would
explain.

</pre>
    </blockquote>
    No, it's a nearly up to date trunk (I can give exact subversion
    revision).<br>
    Here's the verbose log:<br>
    <tt>Sep 19 15:16:40 cns01d unbound: [61501:2] info: validator
      operate: query tirparkolo.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: validator: pass
      to next module<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      validator module exit state is module_wait_module<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run: python
      module exit state is module_wait_module<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iterator[module
      2] operate: extstate:module_state_initial event:module_event_pass<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: process_request:
      new external request event<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving
      tirparkolo.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: request has
      dependency depth of 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: cache delegation
      returns delegpt<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (3 missing), 2 addrs
      (0 result, 2 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. <br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE (stage 2)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving (init
      part 2):  tirparkolo.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE (stage 3)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving (init
      part 3):  tirparkolo.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: tirparkolo.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (3 missing), 2 addrs
      (0 result, 2 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. <br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 3 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: new target
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: new target
      ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: new target
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: new target
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: Bad choices,
      trying to get more choice<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: no current
      targets -- waiting for 4 targets to resolve.<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      iterator module exit state is module_wait_subquery<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iterator[module
      2] operate: extstate:module_state_initial event:module_event_pass<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: iterator operate:
      query ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving
      ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: request has
      dependency depth of 1<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: cache delegation
      returns delegpt<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (3 missing), 2 addrs
      (0 result, 2 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. <br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE (stage 2)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving (init
      part 2):  ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE (stage 3)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving (init
      part 3):  ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (3 missing), 2 addrs
      (0 result, 2 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. <br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 2 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: skipping target
      due to dependency cycle (harden-glue: no may fix some of the
      cycles) ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: new target
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: new target
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: new target
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: Bad choices,
      trying to get more choice<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: no current
      targets -- waiting for 3 targets to resolve.<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      iterator module exit state is module_wait_subquery<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iterator[module
      2] operate: extstate:module_state_initial event:module_event_pass<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: iterator operate:
      query ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: request has
      dependency depth of 1<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: cache delegation
      returns delegpt<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (3 missing), 2 addrs
      (0 result, 2 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. <br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE (stage 2)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving (init
      part 2):  ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE (stage 3)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving (init
      part 3):  ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (3 missing), 2 addrs
      (0 result, 2 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. <br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 2 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: skipping target
      due to dependency cycle (harden-glue: no may fix some of the
      cycles) ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: skipping target
      due to dependency cycle (harden-glue: no may fix some of the
      cycles) ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: new target
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: Bad choices,
      trying to get more choice<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: no current
      targets -- waiting for 1 targets to resolve.<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      iterator module exit state is module_wait_subquery<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iterator[module
      2] operate: extstate:module_state_initial event:module_event_pass<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: iterator operate:
      query ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: request has
      dependency depth of 1<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: cache delegation
      returns delegpt<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (3 missing), 2 addrs
      (0 result, 2 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. <br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE (stage 2)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving (init
      part 2):  ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE (stage 3)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving (init
      part 3):  ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (3 missing), 2 addrs
      (0 result, 2 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. <br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 2 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: skipping target
      due to dependency cycle (harden-glue: no may fix some of the
      cycles) ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: skipping target
      due to dependency cycle (harden-glue: no may fix some of the
      cycles) ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: skipping target
      due to dependency cycle (harden-glue: no may fix some of the
      cycles) ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: selrtt 120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: chase to
      blacklisted lame server<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: No more query
      targets, attempting last resort<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      NS in cache dipmap.com. NS IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: try parent-side
      glue from cache<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (0 missing), 3 addrs
      (2 result, 1 avail) parentNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com.
      * A PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com.
      * A PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. *
      PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:   ADDR_LAME  ip4
      202.133.227.43 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 2 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: selrtt 120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: chase to
      blacklisted lame server<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: No more query
      targets, attempting last resort<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: out of query
      targets -- returning SERVFAIL<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: store error
      response in message cache<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: return error
      response SERVFAIL<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      iterator module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run: python
      module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: validator[module
      0] operate: extstate:module_state_initial
      event:module_event_moddone<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: validator operate:
      query ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: validator:
      nextmodule returned<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: not validating
      response due to CD bit<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      validator module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: pythonmod: clear,
      id: 1, pq:8027F14B0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iterator[module
      2] operate: extstate:module_wait_subquery event:module_event_pass<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: iterator operate:
      query ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (0 missing), 2 addrs
      (2 result, 0 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com.
      * A AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com.
      * A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. *<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 2 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: selrtt 120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: chase to
      blacklisted lame server<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: No more query
      targets, attempting last resort<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      NS in cache dipmap.com. NS IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: try parent-side
      glue from cache<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (0 missing), 3 addrs
      (2 result, 1 avail) parentNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com.
      * A AAAA PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com.
      * A PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. *
      PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:   ADDR_LAME  ip4
      202.133.227.43 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 2 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: selrtt 120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: chase to
      blacklisted lame server<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: No more query
      targets, attempting last resort<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: out of query
      targets -- returning SERVFAIL<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: store error
      response in message cache<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: return error
      response SERVFAIL<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      iterator module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run: python
      module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: validator[module
      0] operate: extstate:module_state_initial
      event:module_event_moddone<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: validator operate:
      query ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: validator:
      nextmodule returned<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: not validating
      response due to CD bit<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      validator module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: pythonmod: clear,
      id: 1, pq:8027F14B0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iterator[module
      2] operate: extstate:module_wait_subquery event:module_event_pass<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: iterator operate:
      query ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 1, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (0 missing), 2 addrs
      (2 result, 0 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com.
      * A AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com.
      * A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. *
      AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 2 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: Bad choices,
      trying to get more choice<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: no current
      targets -- waiting for 1 targets to resolve.<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      iterator module exit state is module_wait_subquery<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iterator[module
      2] operate: extstate:module_wait_subquery event:module_event_pass<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: iterator operate:
      query tirparkolo.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: tirparkolo.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 2, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (0 missing), 2 addrs
      (2 result, 0 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com.
      * A AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com.
      * A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. *
      AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 3 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: Bad choices,
      trying to get more choice<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: no current
      targets -- waiting for 2 targets to resolve.<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      iterator module exit state is module_wait_subquery<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iterator[module
      2] operate: extstate:module_state_initial event:module_event_pass<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: iterator operate:
      query ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: request has
      dependency depth of 1<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: cache delegation
      returns delegpt<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (2 missing), 2 addrs
      (0 result, 2 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com.
      * A AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. 
      AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE (stage 2)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving (init
      part 2):  ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state INIT REQUEST STATE (stage 3)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: resolving (init
      part 3):  ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (2 missing), 2 addrs
      (0 result, 2 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com.
      * A AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com. 
      A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. 
      AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 2 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: skipping target
      due to dependency cycle (harden-glue: no may fix some of the
      cycles) ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: skipping target
      due to dependency cycle (harden-glue: no may fix some of the
      cycles) ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: selrtt 120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: chase to
      blacklisted lame server<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: No more query
      targets, attempting last resort<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      NS in cache dipmap.com. NS IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: try parent-side
      glue from cache<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (0 missing), 3 addrs
      (2 result, 1 avail) parentNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com.
      * A AAAA PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com.
      * A PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. *
      AAAA PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:   ADDR_LAME  ip4
      202.133.227.43 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 2 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: selrtt 120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: chase to
      blacklisted lame server<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: No more query
      targets, attempting last resort<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: out of query
      targets -- returning SERVFAIL<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: store error
      response in message cache<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: return error
      response SERVFAIL<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      iterator module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run: python
      module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: validator[module
      0] operate: extstate:module_state_initial
      event:module_event_moddone<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: validator operate:
      query ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: validator:
      nextmodule returned<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: not validating
      response due to CD bit<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      validator module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: pythonmod: clear,
      id: 1, pq:8027F14B0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iterator[module
      2] operate: extstate:module_wait_subquery event:module_event_pass<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: iterator operate:
      query ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (0 missing), 2 addrs
      (2 result, 0 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com.
      * A AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com.
      * A<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. *
      A AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 2 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: selrtt 120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: chase to
      blacklisted lame server<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: No more query
      targets, attempting last resort<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      NS in cache dipmap.com. NS IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: try parent-side
      glue from cache<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (0 missing), 3 addrs
      (2 result, 1 avail) parentNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com.
      * A AAAA PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com.
      * A PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. *
      A AAAA PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:   ADDR_LAME  ip4
      202.133.227.43 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 2 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: selrtt 120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: chase to
      blacklisted lame server<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: No more query
      targets, attempting last resort<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: out of query
      targets -- returning SERVFAIL<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: store error
      response in message cache<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: return error
      response SERVFAIL<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      iterator module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run: python
      module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: validator[module
      0] operate: extstate:module_state_initial
      event:module_event_moddone<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: validator operate:
      query ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: validator:
      nextmodule returned<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: not validating
      response due to CD bit<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      validator module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: pythonmod: clear,
      id: 1, pq:8027F14B0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iterator[module
      2] operate: extstate:module_wait_subquery event:module_event_pass<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: iterator operate:
      query tirparkolo.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: tirparkolo.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (0 missing), 2 addrs
      (2 result, 0 avail) cacheNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com.
      * A AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com.
      * A AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. *
      A AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 3 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: selrtt 120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: chase to
      blacklisted lame server<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: No more query
      targets, attempting last resort<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      NS in cache dipmap.com. NS IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: try parent-side
      glue from cache<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: iter_handle
      processing q with state QUERY TARGETS STATE<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      processQueryTargets: tirparkolo.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:
      processQueryTargets: targetqueries 0, currentqueries 0<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:
      DelegationPoint<dipmap.com.>: 3 names (0 missing), 3 addrs
      (2 result, 1 avail) parentNS<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns2.dipmap.com.
      * A AAAA PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns1.dipmap.com.
      * A AAAA PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info:   ns.dipmap.com. *
      A AAAA PSIDE_A PSIDE_AAAA<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:   ADDR_LAME  ip4
      202.133.227.43 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: attempt to get
      extra 3 targets<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.11 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: servselect ip4
      202.133.254.12 port 53 (len 16)<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug:    rtt=120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: selrtt 120000<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: chase to
      blacklisted lame server<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: No more query
      targets, attempting last resort<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found in cache
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns2.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns1.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: found parent-side
      ns.dipmap.com. AAAA IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: out of query
      targets -- returning SERVFAIL<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: store error
      response in message cache<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: return error
      response SERVFAIL<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      iterator module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run: python
      module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: validator[module
      0] operate: extstate:module_wait_module event:module_event_moddone<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] info: validator operate:
      query tirparkolo.dipmap.com. A IN<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: validator:
      nextmodule returned<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: cannot validate
      non-answer, rcode SERVFAIL<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: mesh_run:
      validator module exit state is module_finished<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: query took
      0.000000 sec<br>
      Sep 19 15:16:40 cns01d unbound: [61501:2] debug: pythonmod: clear,
      id: 1, pq:8027F1410</tt><br>
    <br>
    Only ns.dipmap.com is accessible, the others don't answer.<br>
  </body>
</html>