[Unbound-users] 1.3: stub zones broken

Wed Jul 22 21:47:51 UTC 2009

Sort of a followup to my previous email about this matter.

Here's an example of debug output on one of my machines.
Querying a 'stub zone' which gets forwarded to a nearby
nsd, while "." is declared as a forward zone to another
unbound server (in DMZ).

# ./unbound-1.3.2 -dvv
[1248298051] unbound[19620:0] notice: Start of unbound 1.3.2.
[1248298051] unbound[19620:0] debug: chdir to /etc/unbound
[1248298051] unbound[19620:0] debug: drop user privileges, run as unbound
[1248298051] unbound[19620:0] debug: switching log to stderr
[1248298051] unbound[19620:0] debug: module config: "validator iterator"
[1248298051] unbound[19620:0] notice: init module 0: validator
[1248298051] unbound[19620:0] notice: init module 1: iterator
[1248298051] unbound[19620:0] debug: target fetch policy for level 0 is 3
[1248298051] unbound[19620:0] debug: target fetch policy for level 1 is 2
[1248298051] unbound[19620:0] debug: target fetch policy for level 2 is 1
[1248298051] unbound[19620:0] debug: target fetch policy for level 3 is 0
[1248298051] unbound[19620:0] debug: target fetch policy for level 4 is 0
[1248298051] unbound[19620:0] info: DelegationPoint<168.192.in-addr.arpa.>: 0 names (0 missing), 1 addrs (0 result, 1 avail)
[1248298051] unbound[19620:0] info: DelegationPoint<tls.msk.ru.>: 0 names (0 missing), 1 addrs (0 result, 1 avail)
[1248298051] unbound[19620:0] debug: Forward zone server list:
[1248298051] unbound[19620:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail)
[1248298051] unbound[19620:0] debug: cache memory msg=33040 rrset=33040 infra=1312 val=41400
[1248298051] unbound[19620:0] info: start of service (unbound 1.3.2).
[1248298055] unbound[19620:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new
[1248298055] unbound[19620:0] info: validator operate: query <paltus.tls.msk.ru. A IN>
[1248298055] unbound[19620:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1248298055] unbound[19620:0] info: resolving <paltus.tls.msk.ru. A IN>
[1248298055] unbound[19620:0] info: priming . IN NS
[1248298055] unbound[19620:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1248298055] unbound[19620:0] info: iterator operate: query <. NS IN>
[1248298055] unbound[19620:0] info: processQueryTargets: <. NS IN>
[1248298055] unbound[19620:0] info: sending query: <. NS IN>
[1248298055] unbound[19620:0] debug: sending to target: <.> 128.8.10.90#53
[1248298055] unbound[19620:0] debug: cache memory msg=33040 rrset=33040 infra=1528 val=41400
[1248298055] unbound[19620:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
[1248298055] unbound[19620:0] info: iterator operate: query <. NS IN>
[1248298055] unbound[19620:0] info: processQueryTargets: <. NS IN>
[1248298055] unbound[19620:0] info: sending query: <. NS IN>
[1248298055] unbound[19620:0] debug: sending to target: <.> 192.5.5.241#53
[1248298055] unbound[19620:0] debug: cache memory msg=33040 rrset=33040 infra=1744 val=41400
[1248298056] unbound[19620:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
[1248298056] unbound[19620:0] info: iterator operate: query <. NS IN>
[1248298056] unbound[19620:0] info: processQueryTargets: <. NS IN>
[1248298056] unbound[19620:0] info: sending query: <. NS IN>
[1248298056] unbound[19620:0] debug: sending to target: <.> 193.0.14.129#53
[1248298056] unbound[19620:0] debug: cache memory msg=33040 rrset=33040 infra=1960 val=41400
[1248298056] unbound[19620:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
...

This is an internal machine which does not have access to external network,
so none of the queries will succeed.  Especially for names like this
(paltus.tls.msk.ru) which does not exist externally.

Here's the config:

forward-zone:
  name: "."
  forward-addr: 192.168.2.18
  forward-addr: 192.168.2.17

stub-zone:
  name: "tls.msk.ru"
  stub-addr: 192.168.1.2

On the other hand, with this same config and this same version,
"other" names are handled correctly:

[1248298485] unbound[19628:0] info: validator operate: query <www.ru. A IN>
[1248298485] unbound[19628:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1248298485] unbound[19628:0] info: resolving <www.ru. A IN>
[1248298485] unbound[19628:0] info: processQueryTargets: <www.ru. A IN>
[1248298485] unbound[19628:0] info: sending query: <www.ru. A IN>
[1248298485] unbound[19628:0] debug: sending to target: <.> 192.168.2.18#53

It is sending query to one of the forwarders for "." zone.

The same is hapenning with 1.3.1.  1.3.0 works, but not correctly:

# ./unbound-1.3.0 -dvv
[1248298777] unbound[19738:0] notice: Start of unbound 1.3.0.
[1248298777] unbound[19738:0] debug: chdir to /etc/unbound
[1248298777] unbound[19738:0] debug: drop user privileges, run as unbound
[1248298777] unbound[19738:0] debug: switching log to stderr
[1248298777] unbound[19738:0] debug: module config: "validator iterator"
[1248298777] unbound[19738:0] notice: init module 0: validator
[1248298777] unbound[19738:0] notice: init module 1: iterator
[1248298777] unbound[19738:0] debug: target fetch policy for level 0 is 3
[1248298777] unbound[19738:0] debug: target fetch policy for level 1 is 2
[1248298777] unbound[19738:0] debug: target fetch policy for level 2 is 1
[1248298777] unbound[19738:0] debug: target fetch policy for level 3 is 0
[1248298777] unbound[19738:0] debug: target fetch policy for level 4 is 0
[1248298777] unbound[19738:0] info: DelegationPoint<168.192.in-addr.arpa.>: 0 names (0 missing), 1 addrs (0 result, 1 avail)
[1248298777] unbound[19738:0] info: DelegationPoint<corpit.ru.>: 0 names (0 missing), 1 addrs (0 result, 1 avail)
[1248298777] unbound[19738:0] info: DelegationPoint<tls.msk.ru.>: 0 names (0 missing), 1 addrs (0 result, 1 avail)
[1248298777] unbound[19738:0] debug: Forward zone server list:
[1248298777] unbound[19738:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail)
[1248298777] unbound[19738:0] debug: cache memory msg=33040 rrset=33040 infra=1312 val=41400
[1248298777] unbound[19738:0] info: start of service (unbound 1.3.0).
[1248298779] unbound[19738:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new
[1248298779] unbound[19738:0] info: validator operate: query <paltus.tls.msk.ru. A IN>
[1248298779] unbound[19738:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1248298779] unbound[19738:0] info: resolving <paltus.tls.msk.ru. A IN>
[1248298779] unbound[19738:0] info: processQueryTargets: <paltus.tls.msk.ru. A IN>
[1248298779] unbound[19738:0] info: sending query: <paltus.tls.msk.ru. A IN>
[1248298779] unbound[19738:0] debug: sending to target: <.> 192.168.2.17#53

Note it is sending to one of the forwarders for "." zone, not to
the stub-address (192.168.1.2) for the "tls.mks.ru" zone.  But since
192.168.2.1[78] also knows where to find that info, I never noticed.

Changing "stub-zone" and "stub-addr" to "forward-zone" and "forward-addr"
fixes both cases.

In my previous emails I were referring to forward zones instead - and
was wrong.  Only stub zones does not work, forward zones seems to be
working correctly.

Thanks

/mjt