Maintained by: NLnet Labs

unbound fetches DNS record from nsd but does not return it to client

Sonic
Sat Aug 1 04:36:34 CEST 2015


I doubt that
       local-zone: "1.168.192.in-addr.arpa" nodefault
is necessary since you're defining it as a stub-zone.

Possibly you're missing a
      domain-insecure: "datanet.home"
or a
      private-domain: "datanet.home"
statement that may resolve your problem.

Chris


On Fri, Jul 31, 2015 at 9:34 PM, Micah Yoder via Unbound-users
<unbound-users at unbound.net> wrote:
> Hi,
> First posted this to ServerFault without luck. Looks like it might be an
> unbound bug, or am I doing something wrong?
> ***
>
> This is a follow-up to
> http://serverfault.com/questions/699094/unbound-nsd-returning-servfail-resolving-local-lan-dns-nsd-alone-works-fine/699124?noredirect=1#comment864282_699124
>
> This *should* be a fairly simple DNS setup for my local home network.
> unbound is a caching DNS server for normal use, and I'm using nsd for
> systems specific to my network.  I've set up unbound to proxy requests for
> datanet.home to nsd, following what I've seen others do.
>
> When I query nsd directly, it works fine.
>
>     $ dig @192.168.1.50 -p 53530 data1.datanet.home
>     [...]
>     ;; ANSWER SECTION:
>     data1.datanet.home.     600     IN      A       192.168.1.61
>
> Querying via unbound (default port) yields a SERVFAIL.
>
>     $ dig @192.168.1.50 data1.datanet.home
>     [...]
>     ;; ->>HEADER<<- opcode: QUERY, status: SERVFAIL, id: 36182
>     ;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1
>
> But the kicker is - going through the unbound logs with verbosity = 4, and
> looking at the cache, it is clear that it *is* actually fetching the result
> from nsd.
>
>     # unbound-control dump_cache | grep datanet
>     data1.datanet.home.     457     IN      A       192.168.1.61
>     data2.datanet.home.     93      IN      A       192.168.1.62
>     datanet.home.   93      IN      NS      ns1.datanet.home.
>
> As far as unbound logs, there is a lot with verbosity=4, but this is what
> appears directly under the part of the log where you can clearly see that it
> got the correct answer from the upstream nsd:
>
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> iter_handle processing q with state QUERY RESPONSE STATE
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] info: query
> response was ANSWER
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> iter_handle processing q with state FINISHED RESPONSE STATE
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] info:
> finishing processing for data1.datanet.home. A IN
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> mesh_run: iterator module exit state is module_finished
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> validator[module 0] operate: extstate:module_wait_module event
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] info:
> validator operate: query data1.datanet.home. A IN
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> validator: nextmodule returned
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug: val
> handle processing q with state VAL_INIT_STATE
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> validator classification positive
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] info: no
> signer, using data1.datanet.home. TYPE0 CLASS0
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] info: prime
> trust anchor
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] info:
> generate request . DNSKEY IN
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> mesh_run: validator module exit state is module_wait_subquery
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> validator[module 0] operate: extstate:module_state_initial eve
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] info:
> validator operate: query . DNSKEY IN
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> validator: pass to next module
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> mesh_run: validator module exit state is module_wait_module
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> iterator[module 1] operate: extstate:module_state_initial even
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> process_request: new external request event
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> iter_handle processing q with state INIT REQUEST STATE
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] info:
> resolving . DNSKEY IN
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> request has dependency depth of 0
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] info:
> priming . IN NS
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> mesh_run: iterator module exit state is module_wait_subquery
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> iterator[module 1] operate: extstate:module_state_initial even
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] info:
> iterator operate: query . NS IN
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> iter_handle processing q with state QUERY TARGETS STATE
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] info:
> processQueryTargets: . NS IN
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] debug:
> processQueryTargets: targetqueries 0, currentqueries 0 sentcou
>     Jul 24 20:45:31 pizza.yoderdev.com unbound[18236]: [18236:0] info:
> DelegationPoint<.>: 13 names (2 missing), 24 addrs (0 result, 2
>
>
> After this it looks like it's going to upstream root DNS servers, but I'm
> not 100% clear what's going on here from the logs.
>
> Here is my entire unbound.conf.  I don't think nsd.conf is relevant since
> that clearly is working.
>
>     server:
>       interface: 127.0.0.1
>       interface: 192.168.1.50
>       use-syslog: yes
>       username: "unbound"
>       directory: "/etc/unbound"
>       trust-anchor-file: trusted-key.key
>       access-control: 192.168.1.0/24 allow
>       #verbosity: 4
>       local-zone: "1.168.192.in-addr.arpa" nodefault
>       do-not-query-localhost: no
>     remote-control:
>       control-enable: yes
>       control-interface: 127.0.0.1
>       control-port: 8953
>       server-key-file: "/etc/unbound/unbound_server.key"
>       server-cert-file: "/etc/unbound/unbound_server.pem"
>       control-key-file: "/etc/unbound/unbound_control.key"
>       control-cert-file: "/etc/unbound/unbound_control.pem"
>
>     stub-zone:
>       name: "datanet.home"
>       stub-addr: 192.168.1.50 at 53530
>     stub-zone:
>       name: "1.168.192.in-addr.arpa"
>       stub-addr: 192.168.1.50 at 53530
>
>
> Any pointers would be awesome. This is driving me nuts.  Thanks!
>