[Unbound-users] Problems with reverse lookup of RFC1918 zones

Dag-Erling Smørgrav des at des.no
Mon May 26 21:48:09 UTC 2014 

I'm testing a version of the unblock-lan-zones patch backported to
1.4.22 (thanks Wouter!).

unbound.conf used for testing:

| server:
|         username: unbound
|         directory: "/var/unbound"
|         chroot: "/var/unbound"
|         pidfile: "/var/run/local_unbound.pid"
|         auto-trust-anchor-file: "/var/unbound/root.key"
|         unblock-lan-zones: yes
|         use-syslog: no
| 
| forward-zone:
|         name: .
|         forward-addr: 192.168.144.1

192.168.144.1 runs unbound with a few private zones:

% drill @192.168.144.1 nine.des.no A | grep '^[^;]'
nine.des.no.	3600	IN	A	192.168.144.9
% drill @192.168.144.1 9.144.168.192.in-addr.arpa. PTR | grep '^[^;]'
9.144.168.192.in-addr.arpa.	3600	IN	PTR	nine.des.no.

Querying through local unbound without unblock-lan-zones, I get
NXDOMAIN:

% host 192.168.144.9
Host 9.144.168.192.in-addr.arpa not found: 3(NXDOMAIN)

With unblock-lan-zones, I get SERVFAIL after a brief delay:

% host 192.168.144.9
Host 9.144.168.192.in-addr.arpa not found: 2(SERVFAIL)

(the local unbound instance is running in debug mode, log beneath my
signature)

What I think is happening is that unbound rejects the answer as
fraudulent because a higher level in the domain hierarchy is signed and
has NSEC3 data indicating that it is empty.

BTW, when I try to check whether 168.192.in-addr.arpa. is signed (using
dig this time on a completely different computer) sometimes it is and
sometimes it isn't:

% dig +noall +answer 168.192.in-addr.arpa. any
168.192.in-addr.arpa.	9431	IN	RRSIG	NSEC 5 4 10800 20140605200133 20140526200133 22802 192.in-addr.arpa. ebIt5zFsTTQU9QltAZN3KfIIJX245QjwqdMaFOSyGTwdMV4DsZKtQZxU ssQ67K4agzs4raXvdayHALwzBmmxg4VXTnKBulTGwQRpxuB7eJgtlgn8 eJaIo+FcUAUYJMhZ6m8CWQqft93YQCgREFLxVeMiTAjSY3o5yurKraee ylU=
168.192.in-addr.arpa.	9431	IN	NSEC	0.169.192.in-addr.arpa. NS RRSIG NSEC
168.192.in-addr.arpa.	85031	IN	NS	blackhole-2.iana.org.
168.192.in-addr.arpa.	85031	IN	NS	blackhole-1.iana.org.
168.192.in-addr.arpa.	135164	IN	SOA	prisoner.iana.org. hostmaster.neva.ru. 1 604800 60 604800 604800
% dig +noall +answer 168.192.in-addr.arpa. any
168.192.in-addr.arpa.	84736	IN	NS	blackhole-2.iana.org.
168.192.in-addr.arpa.	84736	IN	NS	blackhole-1.iana.org.
168.192.in-addr.arpa.	134869	IN	SOA	prisoner.iana.org. hostmaster.neva.ru. 1 604800 60 604800 604800

How do I work around this (short of asking ICANN politely to get their
shit together and allow 168.192.in-addr.arpa. to be non-empty)?

DES
-- 
Dag-Erling Smørgrav - des at des.no

[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new
[1401138082] unbound[3850:0] info: validator operate: query 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: resolving 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] info: processQueryTargets: 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] info: sending query: 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] debug: sending to target: <.> 192.168.144.1#53
[1401138082] unbound[3850:0] debug: cache memory msg=67783 rrset=71899 infra=2849 val=70704
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply
[1401138082] unbound[3850:0] info: iterator operate: query 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] info: response for 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] info: reply from <.> 192.168.144.1#53
[1401138082] unbound[3850:0] info: query response was ANSWER
[1401138082] unbound[3850:0] info: finishing processing for 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1401138082] unbound[3850:0] info: validator operate: query 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: validator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: resolving 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: finishing processing for 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1401138082] unbound[3850:0] info: validator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_subquery event:module_event_pass
[1401138082] unbound[3850:0] info: validator operate: query 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: validator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: resolving 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: processQueryTargets: 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: sending query: 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: sending to target: <.> 192.168.144.1#53
[1401138082] unbound[3850:0] debug: cache memory msg=67783 rrset=71899 infra=2849 val=70704
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply
[1401138082] unbound[3850:0] info: iterator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: response for 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: reply from <.> 192.168.144.1#53
[1401138082] unbound[3850:0] info: query response was nodata ANSWER
[1401138082] unbound[3850:0] info: finishing processing for 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1401138082] unbound[3850:0] info: validator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_subquery event:module_event_pass
[1401138082] unbound[3850:0] info: validator operate: query 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: validator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: resolving 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: processQueryTargets: 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: sending query: 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: sending to target: <.> 192.168.144.1#53
[1401138082] unbound[3850:0] debug: cache memory msg=67783 rrset=71902 infra=2849 val=70704
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply
[1401138082] unbound[3850:0] info: iterator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: response for 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: reply from <.> 192.168.144.1#53
[1401138082] unbound[3850:0] info: query response was nodata ANSWER
[1401138082] unbound[3850:0] info: finishing processing for 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1401138082] unbound[3850:0] info: validator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_subquery event:module_event_pass
[1401138082] unbound[3850:0] info: validator operate: query 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: validator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: resolving 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: processQueryTargets: 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: sending query: 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: sending to target: <.> 192.168.144.1#53
[1401138082] unbound[3850:0] debug: cache memory msg=67783 rrset=71902 infra=2849 val=70704
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply
[1401138082] unbound[3850:0] info: iterator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: response for 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: reply from <.> 192.168.144.1#53
[1401138082] unbound[3850:0] info: query response was nodata ANSWER
[1401138082] unbound[3850:0] info: finishing processing for 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1401138082] unbound[3850:0] info: validator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_subquery event:module_event_pass
[1401138082] unbound[3850:0] info: validator operate: query 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: validator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: resolving 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: processQueryTargets: 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: sending query: 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: sending to target: <.> 192.168.144.1#53
[1401138082] unbound[3850:0] debug: cache memory msg=67783 rrset=71902 infra=2849 val=70704
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply
[1401138082] unbound[3850:0] info: iterator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: response for 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: reply from <.> 192.168.144.1#53
[1401138082] unbound[3850:0] info: query response was nodata ANSWER
[1401138082] unbound[3850:0] info: finishing processing for 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1401138082] unbound[3850:0] info: validator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_subquery event:module_event_pass
[1401138082] unbound[3850:0] info: validator operate: query 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: validator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
[1401138082] unbound[3850:0] info: resolving 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: processQueryTargets: 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: sending query: 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: sending to target: <.> 192.168.144.1#53
[1401138082] unbound[3850:0] debug: cache memory msg=67783 rrset=71902 infra=2849 val=70704
[1401138082] unbound[3850:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply
[1401138082] unbound[3850:0] info: iterator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: response for 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] info: reply from <.> 192.168.144.1#53
[1401138082] unbound[3850:0] info: query response was nodata ANSWER
[1401138082] unbound[3850:0] info: finishing processing for 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone
[1401138082] unbound[3850:0] info: validator operate: query 168.192.in-addr.arpa. DS IN
[1401138082] unbound[3850:0] debug: validator[module 0] operate: extstate:module_wait_subquery event:module_event_pass
[1401138082] unbound[3850:0] info: validator operate: query 9.144.168.192.in-addr.arpa. PTR IN
[1401138082] unbound[3850:0] info: Could not establish a chain of trust to keys for 168.192.in-addr.arpa. DNSKEY IN
[1401138082] unbound[3850:0] debug: cache memory msg=67783 rrset=71902 infra=2849 val=70704

More information about the Unbound-users mailing list