Unbound obtains DNS data but fails to report it / return it

Thu Oct 8 22:28:41 UTC 2015

I have a new opensuse 13.2 machine I’ve installed unbound 1.5.4 on.  I installed it from source as I couldn’t get the opensuse rpm to work.  But then, I can’t get this one to work either.  That is, I get a non-response.  Unbound goes and looks but fails to report the answer because apparently it cannot validate.  

I’m completely stumped.  Any ideas?

Here is the relevant portion of the logs – verbosity 4.  I ran

dig yahoo.com                                                                                              

[1444341946] unbound[1812:1] debug: mesh_run: start

[1444341946] unbound[1812:1] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new

[1444341946] unbound[1812:1] info: validator operate: query yahoo.com. A IN

[1444341946] unbound[1812:1] debug: validator: pass to next module

[1444341946] unbound[1812:1] debug: mesh_run: validator module exit state is module_wait_module

[1444341946] unbound[1812:1] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass

[1444341946] unbound[1812:1] debug: process_request: new external request event

[1444341946] unbound[1812:1] debug: iter_handle processing q with state INIT REQUEST STATE

[1444341946] unbound[1812:1] info: resolving yahoo.com. A IN

[1444341946] unbound[1812:1] debug: request has dependency depth of 0

[1444341946] unbound[1812:1] debug: forwarding request

[1444341946] unbound[1812:1] debug: iter_handle processing q with state QUERY TARGETS STATE

[1444341946] unbound[1812:1] info: processQueryTargets: yahoo.com. A IN

[1444341946] unbound[1812:1] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0

[1444341946] unbound[1812:1] info: DelegationPoint<.>: 0 names (0 missing), 3 addrs (0 result, 3 avail) parentNS

[1444341946] unbound[1812:1] debug:    ip4 4.2.2.4 port 53 (len 16)

[1444341946] unbound[1812:1] debug:    ip4 74.82.42.42 port 53 (len 16)

[1444341946] unbound[1812:1] debug:    ip4 8.8.8.8 port 53 (len 16)

[1444341946] unbound[1812:1] debug: attempt to get extra 3 targets

[1444341946] unbound[1812:1] debug: servselect ip4 8.8.8.8 port 53 (len 16)

[1444341946] unbound[1812:1] debug:    rtt=224

[1444341946] unbound[1812:1] debug: servselect ip4 74.82.42.42 port 53 (len 16)

[1444341946] unbound[1812:1] debug:    rtt=224

[1444341946] unbound[1812:1] debug: servselect ip4 4.2.2.4 port 53 (len 16)

[1444341946] unbound[1812:1] debug:    rtt=164

[1444341946] unbound[1812:1] debug: selrtt 164

[1444341946] unbound[1812:1] info: sending query: yahoo.com. A IN

[1444341946] unbound[1812:1] debug: sending to target: <.> 74.82.42.42#53

[1444341946] unbound[1812:1] debug: dnssec status: not expected

[1444341946] unbound[1812:1] debug: EDNS lookup known=1 vs=0

[1444341946] unbound[1812:1] debug: qname perturbed to yAHOO.Com.

[1444341946] unbound[1812:1] debug: serviced query UDP timeout=224 msec

[1444341946] unbound[1812:1] debug: inserted new pending reply id=3e15

[1444341946] unbound[1812:1] debug: opened UDP if=0 port=57677

[1444341946] unbound[1812:1] debug: comm point start listening 16

[1444341946] unbound[1812:1] debug: mesh_run: iterator module exit state is module_wait_reply

[1444341946] unbound[1812:1] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out

[1444341946] unbound[1812:1] info: 0RDd mod1 rep yahoo.com. A IN

[1444341946] unbound[1812:1] debug: cache memory msg=16877 rrset=19724 infra=1367 val=16773

[1444341946] unbound[1812:1] debug: answer cb

[1444341946] unbound[1812:1] debug: Incoming reply id = 3e15

[1444341946] unbound[1812:1] debug: Incoming reply addr = ip4 74.82.42.42 port 53 (len 16)

[1444341946] unbound[1812:1] debug: lookup size is 1 entries

[1444341946] unbound[1812:1] debug: received udp reply.

[1444341946] unbound[1812:1] debug: udp message[494:0] 3E15818000010003000D000D057961686F6F03636F6D0000010001C00C00010001000003240004628BB718C00C00010001000003240004628AFD6DC00C00010001000003240004CEBE242D000002000100059C5C001401640C726F6F742D73657276657273036E657400000002000100059C5C00040167C058000002000100059C5C00040165C058000002000100059C5C00040163C058000002000100059C5C00040162C058000002000100059C5C00040161C058000002000100059C5C0004016AC058000002000100059C5C00040166C058000002000100059C5C0004016BC058000002000100059C5C0004016CC058000002000100059C5C0004016DC058

[1444341946] unbound[1812:1] debug: udp message[494:256] 000002000100059C5C00040168C058000002000100059C5C00040169C058C0560001000100016A4A0004C7075B0DC0750001000100016A4A0004C0702404C0840001000100016A4A0004C0CBE60AC0930001000100016A4A0004C021040CC0A20001000100016A4A0004C0E44FC9C0B100010001000054D20004C6290004C0C00001000100016A4A0004C03A801EC0CF0001000100016A4A0004C00505F1C0DE0001000100016A4A0004C1000E81C0ED0001000100016A4A0004C707532AC0FC00010001000121020004CA0C1B21C10B0001000100016A4A0004803F0235C11A0001000100016A4A0004C0249411

[1444341946] unbound[1812:1] debug: outnet handle udp reply

[1444341946] unbound[1812:1] debug: measured roundtrip at 49 msec

[1444341946] unbound[1812:1] debug: svcd callbacks start

[1444341946] unbound[1812:1] info: wrong 0x20-ID in reply qname

[1444341946] unbound[1812:1] info: from server ip4 74.82.42.42 port 53 (len 16)

[1444341946] unbound[1812:1] info: for packet[494:0] 3E15818000010003000D000D057961686F6F03636F6D0000010001C00C00010001000003240004628BB718C00C00010001000003240004628AFD6DC00C00010001000003240004CEBE242D000002000100059C5C001401640C726F6F742D73657276657273036E657400000002000100059C5C00040167C058000002000100059C5C00040165C058000002000100059C5C00040163C058000002000100059C5C00040162C058000002000100059C5C00040161C058000002000100059C5C0004016AC058000002000100059C5C00040166C058000002000100059C5C0004016BC058000002000100059C5C0004016CC058000002000100059C5C0004016DC058

[1444341946] unbound[1812:1] info: for packet[494:256] 000002000100059C5C00040168C058000002000100059C5C00040169C058C0560001000100016A4A0004C7075B0DC0750001000100016A4A0004C0702404C0840001000100016A4A0004C0CBE60AC0930001000100016A4A0004C021040CC0A20001000100016A4A0004C0E44FC9C0B100010001000054D20004C6290004C0C00001000100016A4A0004C03A801EC0CF0001000100016A4A0004C00505F1C0DE0001000100016A4A0004C1000E81C0ED0001000100016A4A0004C707532AC0FC00010001000121020004CA0C1B21C10B0001000100016A4A0004803F0235C11A0001000100016A4A0004C0249411

[1444341946] unbound[1812:1] debug: worker svcd callback for qstate 0xb65a0198

[1444341946] unbound[1812:1] debug: mesh_run: start

[1444341946] unbound[1812:1] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_capsfail

[1444341946] unbound[1812:1] info: iterator operate: query yahoo.com. A IN

[1444341946] unbound[1812:1] debug: process_response: new external response event

[1444341946] unbound[1812:1] info: scrub for . NS IN

[1444341946] unbound[1812:1] info: response for yahoo.com. A IN

[1444341946] unbound[1812:1] info: reply from <.> 74.82.42.42#53

[1444341946] unbound[1812:1] info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0

;; flags: qr rd ra ; QUERY: 1, ANSWER: 3, AUTHORITY: 13, ADDITIONAL: 13

;; QUESTION SECTION:

yahoo.com.        IN           A

;; ANSWER SECTION:

yahoo.com.        3600       IN           A             98.139.183.24

yahoo.com.        3600       IN           A             98.138.253.109

yahoo.com.        3600       IN           A             206.190.36.45

;; AUTHORITY SECTION:

.               367708  IN           NS          d.root-servers.net.

.               367708  IN           NS          g.root-servers.net.

.               367708  IN           NS          e.root-servers.net.

.               367708  IN           NS          c.root-servers.net.

.               367708  IN           NS          b.root-servers.net.

.               367708  IN           NS          a.root-servers.net.

.               367708  IN           NS          j.root-servers.net.

.               367708  IN           NS          f.root-servers.net.

.               367708  IN           NS          k.root-servers.net.

.               367708  IN           NS          l.root-servers.net.

.               367708  IN           NS          m.root-servers.net.

.               367708  IN           NS          h.root-servers.net.

.               367708  IN           NS          i.root-servers.net.

;; ADDITIONAL SECTION:

d.root-servers.net.         92746    IN           A             199.7.91.13

g.root-servers.net.         92746    IN           A             192.112.36.4

e.root-servers.net.         92746    IN           A             192.203.230.10

c.root-servers.net.          92746    IN           A             192.33.4.12

b.root-servers.net.         92746    IN           A             192.228.79.201

a.root-servers.net.         21714    IN           A             198.41.0.4

j.root-servers.net.          92746    IN           A             192.58.128.30

f.root-servers.net.          92746    IN           A             192.5.5.241

k.root-servers.net.         92746    IN           A             193.0.14.129

l.root-servers.net.           92746    IN           A             199.7.83.42

m.root-servers.net.        73986    IN           A             202.12.27.33

h.root-servers.net.         92746    IN           A             128.63.2.53

i.root-servers.net.           92746    IN           A             192.36.148.17

;; MSG SIZE  rcvd: 494

[1444341946] unbound[1812:1] info: Capsforid: starting fallback

[1444341946] unbound[1812:1] debug: iter_handle processing q with state QUERY TARGETS STATE