Nov 30 11:28:50 NickDeb unbound[108552]: Nov 30 11:28:50 unbound[108552:0] debug: increased limit(open files) from 1024 to 4140
Nov 30 11:28:50 NickDeb unbound[108552]: Nov 30 11:28:50 unbound[108552:0] debug: creating udp4 socket 172.16.198.20 53
Nov 30 11:28:50 NickDeb unbound[108552]: Nov 30 11:28:50 unbound[108552:0] debug: creating tcp4 socket 172.16.198.20 53
Nov 30 11:28:50 NickDeb unbound[108552]: Nov 30 11:28:50 unbound[108552:0] debug: creating tcp4 socket 172.16.198.20 8953
Nov 30 11:28:50 NickDeb unbound[108552]: Nov 30 11:28:50 unbound[108552:0] debug: switching log to syslog
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: setup SSL certificates
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: chdir to /etc/unbound
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: drop user privileges, run as unbound
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: module config: "iterator"
Nov 30 11:28:50 NickDeb unbound: [108552:0] notice: init module 0: iterator
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: target fetch policy for level 0 is 3
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: target fetch policy for level 1 is 2
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: target fetch policy for level 2 is 1
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: target fetch policy for level 3 is 0
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: target fetch policy for level 4 is 0
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: donotq: 127.0.0.0/8
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: total of 59480 outgoing ports available
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: start threads
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: libevent 2.0.21-stable user epoll method.
Nov 30 11:28:50 NickDeb unbound: [108552:0] info: DelegationPoint<mytest.>: 0 names (0 missing), 1 addrs (0 result, 1 avail) parentNS
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug:    ip4 172.20.0.1 port 53 (len 16)
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: no config, using builtin root hints.
Nov 30 11:28:50 NickDeb unbound: [108552:0] debug: cache memory msg=66072 rrset=66072 infra=5224 val=0 subnet=0
Nov 30 11:28:50 NickDeb unbound: [108552:0] info: start of service (unbound 1.6.8).
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: 172.16.198.20 www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp request from ip4 172.16.198.20 port 59541 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_state_initial event:module_event_new
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: process_request: new external request event
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state INIT REQUEST STATE
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: resolving www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: request has dependency depth of 0
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: priming . IN NS
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_subquery
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_state_initial event:module_event_pass
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: iterator operate: query . NS IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: processQueryTargets: . NS IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: DelegationPoint<.>: 13 names (0 missing), 13 addrs (0 result, 13 avail) parentNS
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   A.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   B.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   C.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   D.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   E.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   F.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   G.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   H.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   I.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   J.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   K.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   L.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   M.ROOT-SERVERS.NET. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 198.41.0.4 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 199.9.14.201 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.33.4.12 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 199.7.91.13 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.203.230.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.5.5.241 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.112.36.4 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 198.97.190.53 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.36.148.17 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.58.128.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 193.0.14.129 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 199.7.83.42 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 202.12.27.33 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: attempt to get extra 2 targets
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: selrtt 376
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: sending query: . NS IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: sending to target: <.> 193.0.14.129#53
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: dnssec status: not expected
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=376 msec
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: inserted new pending reply id=8747
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=38937
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: comm point start listening 12
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_reply
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: mesh_run: end 2 recursion states (1 with reply, 0 detached), 1 waiting replies, 0 recursion replies sent, 0 replies dropped, 0 states jostled out
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: 0pvCD mod0  . NS IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: 1RDdc mod0 rep www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: cache memory msg=66072 rrset=66072 infra=5521 val=0 subnet=0
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: answer cb
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: Incoming reply id = 8747
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: Incoming reply addr = ip4 193.0.14.129 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: lookup size is 1 entries
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: received udp reply.
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[1097:0] [payload removed: 512 characters]
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[1097:256] [payload removed: 512 characters]
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[1097:512] [payload removed: 512 characters]
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[1097:768] [payload removed: 512 characters]
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[1097:1024] 000000000001C059001C00010036EE80001020010500009F00000000000000000042C0A4001C00010036EE80001020010DC30000000000000000000000350000291000000080000000
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: outnet handle udp reply
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: serviced query: EDNS works for ip4 193.0.14.129 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: measured roundtrip at 35 msec
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: svcd callbacks start
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: worker svcd callback for qstate 0x555d5edf7880
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_reply
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: iterator operate: query . NS IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: process_response: new external response event
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: scrub for . NS IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: response for . NS IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: reply from <.> 193.0.14.129#53
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0#012;; flags: qr aa ; QUERY: 1, ANSWER: 14, AUTHORITY: 0, ADDITIONAL: 26 #012;; QUESTION SECTION:#012.#011IN#011NS#012#012;; ANSWER SECTION:#012.#011518400#011IN#011NS#011a.root-servers.net.#012.#011518400#011IN#011NS#011e.root-servers.net.#012.#011518400#011IN#011NS#011g.root-servers.net.#012.#011518400#011IN#011NS#011l.root-servers.net.#012.#011518400#011IN#011NS#011k.root-servers.net.#012.#011518400#011IN#011NS#011h.root-servers.net.#012.#011518400#011IN#011NS#011c.root-servers.net.#012.#011518400#011IN#011NS#011i.root-servers.net.#012.#011518400#011IN#011NS#011m.root-servers.net.#012.#011518400#011IN#011NS#011f.root-servers.net.#012.#011518400#011IN#011NS#011b.root-servers.net.#012.#011518400#011IN#011NS#011d.root-servers.net.#012.#011518400#011IN#011NS#011j.root-servers.net.#012.#011518400#011IN#011RRSIG#011NS 8 0 518400 20171213050000 20171130040000 46809 . [payload removed: 344 characters] ;{id = 46809}#012#012;; AUTHORITY SECTION:#012#012;; ADDITIONAL SECTION:#012a.root-servers.net.#0113600000#011IN#011A#011198.41.0.4#012b.root-servers.net.#0113600000#011IN#011A#011199.9.14.201#012c.root-servers.net.#0113600000#011IN#011A#011192.33.4.12#012d.root-servers.net.#0113600000#011IN#011A#011199.7.91.13#012e.root-servers.net.#0113600000#011IN#011A#011192.203.230.10#012f.root-servers.net.#0113600000#011IN#011A#011192.5.5.241#012g.root-servers.net.#0113600000#011IN#011A#011192.112.36.4#012h.root-servers.net.#0113600000#011IN#011A#011198.97.190.53#012i.root-servers.net.#0113600000#011IN#011A#011192.36.148.17#012j.root-servers.net.#0113600000#011IN#011A#011192.58.128.30#012k.root-servers.net.#0113600000#011IN#011A#011193.0.14.129#012l.root-servers.net.#0113600000#011IN#011A#011199.7.83.42#012m.root-servers.net.#0113600000#011IN#011A#011202.12.27.33#012a.root-servers.net.#0113600000#011IN#011AAAA#0112001:503:ba3e::2:30#012b.root-servers.net.#0113600000#011IN#011AAAA#0112001:500:200::b#012c.root-servers.net.#0113600000#011IN#011AAAA#0112001:500:2::c#012d.root-servers.net.#0113600000#011IN#011AAAA#0112001:500:2d::d#012e.root-servers.net.#0113600000#011IN#011AAAA#0112001:500:a8::e#012f.root-servers.net.#0113600000#011IN#011AAAA#0112001:500:2f::f#012g.root-servers.net.#0113600000#011IN#011AAAA#0112001:500:12::d0d#012h.root-servers.net.#0113600000#011IN#011AAAA#0112001:500:1::53#012i.root-servers.net.#0113600000#011IN#011AAAA#0112001:7fe::53#012j.root-servers.net.#0113600000#011IN#011AAAA#0112001:503:c27::2:30#012k.root-servers.net.#0113600000#011IN#011AAAA#0112001:7fd::1#012l.root-servers.net.#0113600000#011IN#011AAAA#0112001:500:9f::42#012m.root-servers.net.#0113600000#011IN#011AAAA#0112001:dc3::35#012;; MSG SIZE  rcvd: 1086
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: query response was ANSWER
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state PRIME RESPONSE STATE
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_finished
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: priming successful for . NS IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: DelegationPoint<.>: 13 names (0 missing), 26 addrs (0 result, 26 avail) parentNS
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   j.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   d.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   b.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   f.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   m.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   i.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   c.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   h.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   k.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   l.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   g.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   e.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   a.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:dc3::35 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:9f::42 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:7fd::1 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:c27::2:30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:7fe::53 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:1::53 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:12::d0d port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2f::f port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:a8::e port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2d::d port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2::c port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:200::b port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:ba3e::2:30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 202.12.27.33 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 199.7.83.42 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 193.0.14.129 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.58.128.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.36.148.17 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 198.97.190.53 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.112.36.4 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.5.5.241 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.203.230.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 199.7.91.13 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.33.4.12 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 199.9.14.201 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 198.41.0.4 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_subquery event:module_event_pass
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: iterator operate: query www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state INIT REQUEST STATE (stage 2)
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: resolving (init part 2):  www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state INIT REQUEST STATE (stage 3)
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: resolving (init part 3):  www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: processQueryTargets: www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: DelegationPoint<.>: 13 names (0 missing), 26 addrs (0 result, 26 avail) parentNS
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   j.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   d.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   b.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   f.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   m.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   i.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   c.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   h.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   k.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   l.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   g.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   e.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   a.root-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:dc3::35 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:9f::42 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:7fd::1 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:c27::2:30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:7fe::53 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:1::53 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:12::d0d port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2f::f port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:a8::e port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2d::d port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2::c port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:200::b port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:ba3e::2:30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 202.12.27.33 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 199.7.83.42 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 193.0.14.129 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.58.128.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.36.148.17 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 198.97.190.53 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.112.36.4 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.5.5.241 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.203.230.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 199.7.91.13 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.33.4.12 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 199.9.14.201 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 198.41.0.4 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: attempt to get extra 3 targets
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: servselect ip4 193.0.14.129 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    rtt=324
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: selrtt 324
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: sending query: www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: sending to target: <.> 198.97.190.53#53
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: dnssec status: not expected
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=376 msec
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: inserted new pending reply id=8551
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=59599
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: comm point start listening 13
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_reply
Nov 30 11:29:18 NickDeb unbound: [108552:0] 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
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: 0RDd mod0 rep www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: cache memory msg=66929 rrset=73612 infra=5818 val=0 subnet=0
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: svcd callbacks end
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: close of port 38937
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: close fd 12
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: answer cb
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: Incoming reply id = 8551
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: Incoming reply addr = ip4 198.97.190.53 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: lookup size is 1 entries
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: received udp reply.
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[1174:0] [payload removed: 512 characters]
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[1174:256] [payload removed: 512 characters]
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[1174:512] [payload removed: 512 characters]
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[1174:768] [payload removed: 512 characters]
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[1174:1024] [payload removed: 300 characters]
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: outnet handle udp reply
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: serviced query: EDNS works for ip4 198.97.190.53 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: measured roundtrip at 120 msec
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: svcd callbacks start
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: worker svcd callback for qstate 0x555d5edfb890
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_reply
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: iterator operate: query www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: process_response: new external response event
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: scrub for . NS IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: response for www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: reply from <.> 198.97.190.53#53
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0#012;; flags: qr ; QUERY: 1, ANSWER: 0, AUTHORITY: 15, ADDITIONAL: 26 #012;; QUESTION SECTION:#012www.google.com.#011IN#011A#012#012;; ANSWER SECTION:#012#012;; AUTHORITY SECTION:#012com.#011172800#011IN#011NS#011a.gtld-servers.net.#012com.#011172800#011IN#011NS#011b.gtld-servers.net.#012com.#011172800#011IN#011NS#011c.gtld-servers.net.#012com.#011172800#011IN#011NS#011d.gtld-servers.net.#012com.#011172800#011IN#011NS#011e.gtld-servers.net.#012com.#011172800#011IN#011NS#011f.gtld-servers.net.#012com.#011172800#011IN#011NS#011g.gtld-servers.net.#012com.#011172800#011IN#011NS#011h.gtld-servers.net.#012com.#011172800#011IN#011NS#011i.gtld-servers.net.#012com.#011172800#011IN#011NS#011j.gtld-servers.net.#012com.#011172800#011IN#011NS#011k.gtld-servers.net.#012com.#011172800#011IN#011NS#011l.gtld-servers.net.#012com.#011172800#011IN#011NS#011m.gtld-servers.net.#012com.#01186400#011IN#011DS#01130909 8 2 E2D3C916F6DEEAC73294E8268FB5885044A833FC5459588F4A9184CFC41A5766#012com.#01186400#011IN#011RRSIG#011DS 8 1 86400 20171213050000 20171130040000 46809 . [payload removed: 344 characters] ;{id = 46809}#012#012;; ADDITIONAL SECTION:#012a.gtld-servers.net.#011172800#011IN#011A#011192.5.6.30#012b.gtld-servers.net.#011172800#011IN#011A#011192.33.14.30#012c.gtld-servers.net.#011172800#011IN#011A#011192.26.92.30#012d.gtld-servers.net.#011172800#011IN#011A#011192.31.80.30#012e.gtld-servers.net.#011172800#011IN#011A#011192.12.94.30#012f.gtld-servers.net.#011172800#011IN#011A#011192.35.51.30#012g.gtld-servers.net.#011172800#011IN#011A#011192.42.93.30#012h.gtld-servers.net.#011172800#011IN#011A#011192.54.112.30#012i.gtld-servers.net.#011172800#011IN#011A#011192.43.172.30#012j.gtld-servers.net.#011172800#011IN#011A#011192.48.79.30#012k.gtld-servers.net.#011172800#011IN#011A#011192.52.178.30#012l.gtld-servers.net.#011172800#011IN#011A#011192.41.162.30#012m.gtld-servers.net.#011172800#011IN#011A#011192.55.83.30#012a.gtld-servers.net.#011172800#011IN#011AAAA#0112001:503:a83e::2:30#012b.gtld-servers.net.#011172800#011IN#011AAAA#0112001:503:231d::2:30#012c.gtld-servers.net.#011172800#011IN#011AAAA#0112001:503:83eb::30#012d.gtld-servers.net.#011172800#011IN#011AAAA#0112001:500:856e::30#012e.gtld-servers.net.#011172800#011IN#011AAAA#0112001:502:1ca1::30#012f.gtld-servers.net.#011172800#011IN#011AAAA#0112001:503:d414::30#012g.gtld-servers.net.#011172800#011IN#011AAAA#0112001:503:eea3::30#012h.gtld-servers.net.#011172800#011IN#011AAAA#0112001:502:8cc::30#012i.gtld-servers.net.#011172800#011IN#011AAAA#0112001:503:39c1::30#012j.gtld-servers.net.#011172800#011IN#011AAAA#0112001:502:7094::30#012k.gtld-servers.net.#011172800#011IN#011AAAA#0112001:503:d2d::30#012l.gtld-servers.net.#011172800#011IN#011AAAA#0112001:500:d937::30#012m.gtld-servers.net.#011172800#011IN#011AAAA#0112001:501:b1f9::30#012;; MSG SIZE  rcvd: 1163
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: query response was REFERRAL
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache m.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache m.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache l.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache l.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache k.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache k.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache j.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache j.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache i.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache i.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache h.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache h.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache g.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache g.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache f.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache f.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache e.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache e.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache d.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache d.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache c.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache c.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache b.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache b.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache a.gtld-servers.net. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache a.gtld-servers.net. AAAA IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: DelegationPoint<com.>: 13 names (0 missing), 26 addrs (0 result, 26 avail) parentNS
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   m.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   l.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   k.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   j.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   i.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   h.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   g.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   f.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   e.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   d.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   c.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   b.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   a.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:501:b1f9::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:d937::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:d2d::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:502:7094::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:39c1::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:502:8cc::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:eea3::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:d414::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:502:1ca1::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:856e::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:83eb::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:231d::2:30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:a83e::2:30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.55.83.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.41.162.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.52.178.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.48.79.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.43.172.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.54.112.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.42.93.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.35.51.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.12.94.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.31.80.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.26.92.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.33.14.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.5.6.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: cleared outbound list for next round
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: processQueryTargets: www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: DelegationPoint<com.>: 13 names (0 missing), 26 addrs (0 result, 26 avail) parentNS
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   m.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   l.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   k.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   j.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   i.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   h.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   g.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   f.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   e.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   d.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   c.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   b.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   a.gtld-servers.net. * A AAAA
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:501:b1f9::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:d937::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:d2d::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:502:7094::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:39c1::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:502:8cc::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:eea3::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:d414::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:502:1ca1::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:500:856e::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:83eb::30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:231d::2:30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip6 2001:503:a83e::2:30 port 53 (len 28)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.55.83.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.41.162.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.52.178.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.48.79.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.43.172.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.54.112.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.42.93.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.35.51.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.12.94.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.31.80.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.26.92.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.33.14.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 192.5.6.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: attempt to get extra 3 targets
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: selrtt 376
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: sending query: www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: sending to target: <com.> 192.12.94.30#53
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: dnssec status: not expected
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=376 msec
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: inserted new pending reply id=304b
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=55316
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: comm point start listening 12
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_reply
Nov 30 11:29:18 NickDeb unbound: [108552:0] 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
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: 0RDd mod0 rep www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: cache memory msg=66929 rrset=81415 infra=6119 val=0 subnet=0
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: svcd callbacks end
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: close of port 59599
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: close fd 13
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: answer cb
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: Incoming reply id = 304b
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: Incoming reply addr = ip4 192.12.94.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: lookup size is 1 entries
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: received udp reply.
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[664:0] [payload removed: 512 characters]
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[664:256] [payload removed: 512 characters]
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[664:512] [payload removed: 304 characters]
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: outnet handle udp reply
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: serviced query: EDNS works for ip4 192.12.94.30 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: measured roundtrip at 44 msec
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: svcd callbacks start
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: worker svcd callback for qstate 0x555d5edfb890
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_reply
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: iterator operate: query www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: process_response: new external response event
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: scrub for com. NS IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: response for www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: reply from <com.> 192.12.94.30#53
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0#012;; flags: qr ; QUERY: 1, ANSWER: 0, AUTHORITY: 8, ADDITIONAL: 4 #012;; QUESTION SECTION:#012www.google.com.#011IN#011A#012#012;; ANSWER SECTION:#012#012;; AUTHORITY SECTION:#012google.com.#011172800#011IN#011NS#011ns2.google.com.#012google.com.#011172800#011IN#011NS#011ns1.google.com.#012google.com.#011172800#011IN#011NS#011ns3.google.com.#012google.com.#011172800#011IN#011NS#011ns4.google.com.#012CK0POJMG874LJREF7EFN8430QVIT8BSM.com.#01186400#011IN#011NSEC3#0111 1 0 - ck0q1gin43n1arrc9osm6qpqr81h5m9a NS SOA RRSIG DNSKEY NSEC3PARAM ;{flags: optout}#012CK0POJMG874LJREF7EFN8430QVIT8BSM.com.#01186400#011IN#011RRSIG#011NSEC3 8 2 86400 20171207054808 20171130043808 11324 com. CwCFhkA0622r0eQ/DkLvQvPza+O8qtZBA0nNcT59HENWEVU1I5pkfOjbFHZHki7/SUZlq3hu4K/pbDS/BV+EqzD6+0Xirg+DJ77PqaxTOVCHjX8h7+GctRkG0QXyv478T362ztTzb1l8dWQ1H7CyubqN291GnfwFIDnPZ+IXzx4= ;{id = 11324}#012S848U70KJDCTE8UH1N07QH2EK7LNOUC6.com.#01186400#011IN#011NSEC3#0111 1 0 - s84c439c9haccnuvh6cbpptus93vltug NS DS RRSIG ;{flags: optout}#012S848U70KJDCTE8UH1N07QH2EK7LNOUC6.com.#01186400#011IN#011RRSIG#011NSEC3 8 2 86400 20171205055919 20171128044919 11324 com. lQ3D/KBaucflI9nLhMaCooTp7/y1/XkENx9UlRSgxNvuoKk+wl42+jpbNMCrySePJTZyIX2Nb9PBRiOxfvOWSEc228kzT575OGzoToYFb3d3o8n6Dbx5twL6pPbo64rz+QtA92/sEEOzCzntK84D2FRHY9HQVNhIzxhyfOcLPys= ;{id = 11324}#012#012;; ADDITIONAL SECTION:#012ns2.google.com.#011172800#011IN#011A#011216.239.34.10#012ns1.google.com.#011172800#011IN#011A#011216.239.32.10#012ns3.google.com.#011172800#011IN#011A#011216.239.36.10#012ns4.google.com.#011172800#011IN#011A#011216.239.38.10#012;; MSG SIZE  rcvd: 653
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: query response was REFERRAL
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache ns4.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache ns3.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache ns1.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: found in cache ns2.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: DelegationPoint<google.com.>: 4 names (4 missing), 4 addrs (0 result, 4 avail) parentNS
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   ns4.google.com.  A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   ns3.google.com.  A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   ns1.google.com.  A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   ns2.google.com.  A
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 216.239.38.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 216.239.36.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 216.239.32.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 216.239.34.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: cleared outbound list for next round
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: processQueryTargets: www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: DelegationPoint<google.com.>: 4 names (0 missing), 4 addrs (0 result, 4 avail) parentNS
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   ns4.google.com. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   ns3.google.com. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   ns1.google.com. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:   ns2.google.com. * A
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 216.239.38.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 216.239.36.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 216.239.32.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug:    ip4 216.239.34.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: attempt to get extra 3 targets
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: selrtt 376
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: sending query: www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: sending to target: <google.com.> 216.239.32.10#53
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: dnssec status: not expected
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=376 msec
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: inserted new pending reply id=7ac5
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=63595
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: comm point start listening 13
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_reply
Nov 30 11:29:18 NickDeb unbound: [108552:0] 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
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: 0RDd mod0 rep www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: cache memory msg=66929 rrset=83674 infra=6427 val=0 subnet=0
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: svcd callbacks end
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: close of port 55316
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: close fd 12
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: answer cb
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: Incoming reply id = 7ac5
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: Incoming reply addr = ip4 216.239.32.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: lookup size is 1 entries
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: received udp reply.
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: udp message[48:0] 7AC5840000010001000000000377777706676F6F676C6503636F6D0000010001C00C000100010000012C0004D83AC644
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: outnet handle udp reply
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: serviced query: EDNS works for ip4 216.239.32.10 port 53 (len 16)
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: measured roundtrip at 42 msec
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: svcd callbacks start
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: worker svcd callback for qstate 0x555d5edfb890
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_reply
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: iterator operate: query www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: process_response: new external response event
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: scrub for google.com. NS IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: response for www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: reply from <google.com.> 216.239.32.10#53
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0#012;; flags: qr aa ; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0 #012;; QUESTION SECTION:#012www.google.com.#011IN#011A#012#012;; ANSWER SECTION:#012www.google.com.#011300#011IN#011A#011216.58.198.68#012#012;; AUTHORITY SECTION:#012#012;; ADDITIONAL SECTION:#012;; MSG SIZE  rcvd: 48
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: query response was ANSWER
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: iter_handle processing q with state FINISHED RESPONSE STATE
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: finishing processing for www.google.com. A IN
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_finished
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: query took 0.243609 sec
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 1 recursion replies sent, 0 replies dropped, 0 states jostled out
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: average recursion processing time 0.243609 sec
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: histogram of recursion processing times
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: [25%]=0 median[50%]=0 [75%]=0
Nov 30 11:29:18 NickDeb unbound: [108552:0] info: lower(secs) upper(secs) recursions
Nov 30 11:29:18 NickDeb unbound: [108552:0] info:    0.131072    0.262144 1
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: cache memory msg=67177 rrset=83912 infra=6427 val=0 subnet=0
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: svcd callbacks end
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: close of port 63595
Nov 30 11:29:18 NickDeb unbound: [108552:0] debug: close fd 13
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: 172.16.198.20 mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: udp request from ip4 172.16.198.20 port 48911 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_state_initial event:module_event_new
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: process_request: new external request event
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: iter_handle processing q with state INIT REQUEST STATE
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: resolving mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: request has dependency depth of 0
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: cache delegation returns delegpt
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: DelegationPoint<.>: 13 names (0 missing), 26 addrs (0 result, 26 avail) cacheNS
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   j.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   d.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   b.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   f.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   m.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   i.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   c.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   h.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   k.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   l.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   g.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   e.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   a.root-servers.net. * A AAAA
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:503:ba3e::2:30 port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 198.41.0.4 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:500:a8::e port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 192.203.230.10 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:500:12::d0d port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 192.112.36.4 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:500:9f::42 port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 199.7.83.42 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:7fd::1 port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 193.0.14.129 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:500:1::53 port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 198.97.190.53 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2::c port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 192.33.4.12 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:7fe::53 port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 192.36.148.17 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:dc3::35 port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 202.12.27.33 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2f::f port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 192.5.5.241 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:500:200::b port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 199.9.14.201 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2d::d port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 199.7.91.13 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip6 2001:503:c27::2:30 port 53 (len 28)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 192.58.128.30 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: iter_handle processing q with state INIT REQUEST STATE (stage 2)
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: resolving (init part 2):  mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: use stub mytest. NS IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: iter_handle processing q with state INIT REQUEST STATE (stage 3)
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: resolving (init part 3):  mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: processQueryTargets: mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: DelegationPoint<mytest.>: 0 names (0 missing), 1 addrs (0 result, 1 avail) parentNS
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 172.20.0.1 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: attempt to get extra 3 targets
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: selrtt 376
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: sending query: mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: sending to target: <mytest.> 172.20.0.1#53
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: dnssec status: not expected
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=376 msec
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: inserted new pending reply id=36ea
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=37822
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: comm point start listening 12
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_reply
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 1 recursion replies sent, 0 replies dropped, 0 states jostled out
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: average recursion processing time 0.243609 sec
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: histogram of recursion processing times
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: [25%]=0 median[50%]=0 [75%]=0
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: lower(secs) upper(secs) recursions
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:    0.131072    0.262144 1
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: 0RDd mod0 rep mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: cache memory msg=67177 rrset=83912 infra=6731 val=0 subnet=0
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: answer cb
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: Incoming reply id = 36ea
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: Incoming reply addr = ip4 172.20.0.1 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: lookup size is 1 entries
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: received udp reply.
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: udp message[83:0] 36EA84900001000000010002066D7974657374076578616D706C65066D79746573740000010001C00C00020001000151800005026E73C00CC03300010001000151800004AC1500010000291000000080000000
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: outnet handle udp reply
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: serviced query: EDNS works for ip4 172.20.0.1 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: measured roundtrip at 0 msec
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: svcd callbacks start
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: worker svcd callback for qstate 0x555d5edfb890
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_reply
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: iterator operate: query mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: process_response: new external response event
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: scrub for mytest. NS IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: response for mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: reply from <mytest.> 172.20.0.1#53
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0#012;; flags: qr aa ra ; QUERY: 1, ANSWER: 0, AUTHORITY: 1, ADDITIONAL: 1 #012;; QUESTION SECTION:#012mytest.example.mytest.#011IN#011A#012#012;; ANSWER SECTION:#012#012;; AUTHORITY SECTION:#012mytest.example.mytest.#01186400#011IN#011NS#011ns.mytest.example.mytest.#012#012;; ADDITIONAL SECTION:#012ns.mytest.example.mytest.#01186400#011IN#011A#011172.21.0.1#012;; MSG SIZE  rcvd: 72
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: query response was REFERRAL
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: found in cache ns.mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: DelegationPoint<mytest.example.mytest.>: 1 names (1 missing), 1 addrs (0 result, 1 avail) parentNS
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   ns.mytest.example.mytest.  A
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 172.21.0.1 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: cleared outbound list for next round
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: processQueryTargets: mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: DelegationPoint<mytest.example.mytest.>: 1 names (0 missing), 1 addrs (0 result, 1 avail) parentNS
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   ns.mytest.example.mytest. * A
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 172.21.0.1 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: attempt to get extra 3 targets
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: selrtt 376
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: sending query: mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: sending to target: <mytest.example.mytest.> 172.21.0.1#53
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: dnssec status: not expected
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=376 msec
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: inserted new pending reply id=723a
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=25174
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: comm point start listening 13
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_reply
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 1 recursion replies sent, 0 replies dropped, 0 states jostled out
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: average recursion processing time 0.243609 sec
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: histogram of recursion processing times
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: [25%]=0 median[50%]=0 [75%]=0
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: lower(secs) upper(secs) recursions
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:    0.131072    0.262144 1
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: 0RDd mod0 rep mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: cache memory msg=67177 rrset=84427 infra=7050 val=0 subnet=0
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: svcd callbacks end
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: close of port 37822
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: close fd 12
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: timeout udp
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: try edns1xx0 <mytest.example.mytest.> 172.21.0.1#53
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=376 msec
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: inserted new pending reply id=7439
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=26976
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: comm point start listening 12
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: close of port 25174
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: close fd 13
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: timeout udp
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: svcd callbacks start
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: worker svcd callback for qstate 0x555d5edfb890
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_noreply
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: iterator operate: query mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: process_response: new external response event
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: query response was timeout
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: processQueryTargets: mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 1
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: DelegationPoint<mytest.example.mytest.>: 1 names (0 missing), 1 addrs (1 result, 0 avail) parentNS
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:   ns.mytest.example.mytest. * A
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    ip4 172.21.0.1 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: attempt to get extra 3 targets
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: servselect ip4 172.21.0.1 port 53 (len 16)
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug:    rtt=752
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: selrtt 752
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: sending query: mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: sending to target: <mytest.example.mytest.> 172.21.0.1#53
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: dnssec status: not expected
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=752 msec
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: inserted new pending reply id=38e2
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=63857
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: comm point start listening 13
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_reply
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 1 recursion replies sent, 0 replies dropped, 0 states jostled out
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: average recursion processing time 0.243609 sec
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: histogram of recursion processing times
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: [25%]=0 median[50%]=0 [75%]=0
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: lower(secs) upper(secs) recursions
Nov 30 11:29:31 NickDeb unbound: [108552:0] info:    0.131072    0.262144 1
Nov 30 11:29:31 NickDeb unbound: [108552:0] info: 0RDd mod0 rep mytest.example.mytest. A IN
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: cache memory msg=67177 rrset=84427 infra=7050 val=0 subnet=0
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: svcd callbacks end
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: close of port 26976
Nov 30 11:29:31 NickDeb unbound: [108552:0] debug: close fd 12
Nov 30 11:29:32 NickDeb unbound: [108552:0] debug: timeout udp
Nov 30 11:29:32 NickDeb unbound: [108552:0] debug: try edns1xx0 <mytest.example.mytest.> 172.21.0.1#53
Nov 30 11:29:32 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:32 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=752 msec
Nov 30 11:29:32 NickDeb unbound: [108552:0] debug: inserted new pending reply id=ef1d
Nov 30 11:29:32 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=32740
Nov 30 11:29:32 NickDeb unbound: [108552:0] debug: comm point start listening 12
Nov 30 11:29:32 NickDeb unbound: [108552:0] debug: close of port 63857
Nov 30 11:29:32 NickDeb unbound: [108552:0] debug: close fd 13
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: timeout udp
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: svcd callbacks start
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: worker svcd callback for qstate 0x555d5edfb890
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_noreply
Nov 30 11:29:33 NickDeb unbound: [108552:0] info: iterator operate: query mytest.example.mytest. A IN
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: process_response: new external response event
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: query response was timeout
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:33 NickDeb unbound: [108552:0] info: processQueryTargets: mytest.example.mytest. A IN
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 2
Nov 30 11:29:33 NickDeb unbound: [108552:0] info: DelegationPoint<mytest.example.mytest.>: 1 names (0 missing), 1 addrs (1 result, 0 avail) parentNS
Nov 30 11:29:33 NickDeb unbound: [108552:0] info:   ns.mytest.example.mytest. * A
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug:    ip4 172.21.0.1 port 53 (len 16)
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: attempt to get extra 3 targets
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: servselect ip4 172.21.0.1 port 53 (len 16)
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug:    rtt=1504
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: selrtt 1504
Nov 30 11:29:33 NickDeb unbound: [108552:0] info: sending query: mytest.example.mytest. A IN
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: sending to target: <mytest.example.mytest.> 172.21.0.1#53
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: dnssec status: not expected
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=1504 msec
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: inserted new pending reply id=dec8
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=51656
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: comm point start listening 13
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_reply
Nov 30 11:29:33 NickDeb unbound: [108552:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 1 recursion replies sent, 0 replies dropped, 0 states jostled out
Nov 30 11:29:33 NickDeb unbound: [108552:0] info: average recursion processing time 0.243609 sec
Nov 30 11:29:33 NickDeb unbound: [108552:0] info: histogram of recursion processing times
Nov 30 11:29:33 NickDeb unbound: [108552:0] info: [25%]=0 median[50%]=0 [75%]=0
Nov 30 11:29:33 NickDeb unbound: [108552:0] info: lower(secs) upper(secs) recursions
Nov 30 11:29:33 NickDeb unbound: [108552:0] info:    0.131072    0.262144 1
Nov 30 11:29:33 NickDeb unbound: [108552:0] info: 0RDd mod0 rep mytest.example.mytest. A IN
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: cache memory msg=67177 rrset=84427 infra=7050 val=0 subnet=0
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: svcd callbacks end
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: close of port 32740
Nov 30 11:29:33 NickDeb unbound: [108552:0] debug: close fd 12
Nov 30 11:29:34 NickDeb unbound: [108552:0] debug: timeout udp
Nov 30 11:29:34 NickDeb unbound: [108552:0] debug: try edns1xx0 <mytest.example.mytest.> 172.21.0.1#53
Nov 30 11:29:34 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:34 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=1504 msec
Nov 30 11:29:34 NickDeb unbound: [108552:0] debug: inserted new pending reply id=18da
Nov 30 11:29:34 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=44126
Nov 30 11:29:34 NickDeb unbound: [108552:0] debug: comm point start listening 12
Nov 30 11:29:34 NickDeb unbound: [108552:0] debug: close of port 51656
Nov 30 11:29:34 NickDeb unbound: [108552:0] debug: close fd 13
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: timeout udp
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: svcd callbacks start
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: worker svcd callback for qstate 0x555d5edfb890
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_noreply
Nov 30 11:29:36 NickDeb unbound: [108552:0] info: iterator operate: query mytest.example.mytest. A IN
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: process_response: new external response event
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: query response was timeout
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:36 NickDeb unbound: [108552:0] info: processQueryTargets: mytest.example.mytest. A IN
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 3
Nov 30 11:29:36 NickDeb unbound: [108552:0] info: DelegationPoint<mytest.example.mytest.>: 1 names (0 missing), 1 addrs (1 result, 0 avail) parentNS
Nov 30 11:29:36 NickDeb unbound: [108552:0] info:   ns.mytest.example.mytest. * A
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug:    ip4 172.21.0.1 port 53 (len 16)
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: servselect ip4 172.21.0.1 port 53 (len 16)
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug:    rtt=3008
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: selrtt 3008
Nov 30 11:29:36 NickDeb unbound: [108552:0] info: sending query: mytest.example.mytest. A IN
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: sending to target: <mytest.example.mytest.> 172.21.0.1#53
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: dnssec status: not expected
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=3008 msec
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: inserted new pending reply id=2677
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=52382
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: comm point start listening 13
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_reply
Nov 30 11:29:36 NickDeb unbound: [108552:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 1 recursion replies sent, 0 replies dropped, 0 states jostled out
Nov 30 11:29:36 NickDeb unbound: [108552:0] info: average recursion processing time 0.243609 sec
Nov 30 11:29:36 NickDeb unbound: [108552:0] info: histogram of recursion processing times
Nov 30 11:29:36 NickDeb unbound: [108552:0] info: [25%]=0 median[50%]=0 [75%]=0
Nov 30 11:29:36 NickDeb unbound: [108552:0] info: lower(secs) upper(secs) recursions
Nov 30 11:29:36 NickDeb unbound: [108552:0] info:    0.131072    0.262144 1
Nov 30 11:29:36 NickDeb unbound: [108552:0] info: 0RDd mod0 rep mytest.example.mytest. A IN
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: cache memory msg=67177 rrset=84427 infra=7050 val=0 subnet=0
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: svcd callbacks end
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: close of port 44126
Nov 30 11:29:36 NickDeb unbound: [108552:0] debug: close fd 12
Nov 30 11:29:39 NickDeb unbound: [108552:0] debug: timeout udp
Nov 30 11:29:39 NickDeb unbound: [108552:0] debug: try edns1xx0 <mytest.example.mytest.> 172.21.0.1#53
Nov 30 11:29:39 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:39 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=3008 msec
Nov 30 11:29:39 NickDeb unbound: [108552:0] debug: inserted new pending reply id=0332
Nov 30 11:29:39 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=57558
Nov 30 11:29:39 NickDeb unbound: [108552:0] debug: comm point start listening 12
Nov 30 11:29:39 NickDeb unbound: [108552:0] debug: close of port 52382
Nov 30 11:29:39 NickDeb unbound: [108552:0] debug: close fd 13
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: timeout udp
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: svcd callbacks start
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: worker svcd callback for qstate 0x555d5edfb890
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_noreply
Nov 30 11:29:42 NickDeb unbound: [108552:0] info: iterator operate: query mytest.example.mytest. A IN
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: process_response: new external response event
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: query response was timeout
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:42 NickDeb unbound: [108552:0] info: processQueryTargets: mytest.example.mytest. A IN
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 4
Nov 30 11:29:42 NickDeb unbound: [108552:0] info: DelegationPoint<mytest.example.mytest.>: 1 names (0 missing), 1 addrs (1 result, 0 avail) parentNS
Nov 30 11:29:42 NickDeb unbound: [108552:0] info:   ns.mytest.example.mytest. * A
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug:    ip4 172.21.0.1 port 53 (len 16)
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: servselect ip4 172.21.0.1 port 53 (len 16)
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug:    rtt=6016
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: selrtt 6016
Nov 30 11:29:42 NickDeb unbound: [108552:0] info: sending query: mytest.example.mytest. A IN
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: sending to target: <mytest.example.mytest.> 172.21.0.1#53
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: dnssec status: not expected
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: EDNS lookup known=0 vs=0
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: serviced query: send probe to see  if use of EDNS causes timeouts
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=1000 msec
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: inserted new pending reply id=c832
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=13446
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: comm point start listening 13
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_reply
Nov 30 11:29:42 NickDeb unbound: [108552:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 1 recursion replies sent, 0 replies dropped, 0 states jostled out
Nov 30 11:29:42 NickDeb unbound: [108552:0] info: average recursion processing time 0.243609 sec
Nov 30 11:29:42 NickDeb unbound: [108552:0] info: histogram of recursion processing times
Nov 30 11:29:42 NickDeb unbound: [108552:0] info: [25%]=0 median[50%]=0 [75%]=0
Nov 30 11:29:42 NickDeb unbound: [108552:0] info: lower(secs) upper(secs) recursions
Nov 30 11:29:42 NickDeb unbound: [108552:0] info:    0.131072    0.262144 1
Nov 30 11:29:42 NickDeb unbound: [108552:0] info: 0RDd mod0 rep mytest.example.mytest. A IN
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: cache memory msg=67177 rrset=84427 infra=7050 val=0 subnet=0
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: svcd callbacks end
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: close of port 57558
Nov 30 11:29:42 NickDeb unbound: [108552:0] debug: close fd 12
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: timeout udp
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: svcd callbacks start
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: worker svcd callback for qstate 0x555d5edfb890
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_noreply
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: iterator operate: query mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: process_response: new external response event
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: query response was timeout
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: processQueryTargets: mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 5
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: DelegationPoint<mytest.example.mytest.>: 1 names (0 missing), 1 addrs (0 result, 0 avail) parentNS
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   ns.mytest.example.mytest. * A
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 172.21.0.1 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: No more query targets, attempting last resort
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: found in cache ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: new pside target ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: try parent-side glue lookup
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_subquery
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_state_initial event:module_event_pass
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: iterator operate: query ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iter_handle processing q with state INIT REQUEST STATE
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: resolving ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: request has dependency depth of 1
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: cache blacklisted, going to the network
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: cache delegation returns delegpt
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: DelegationPoint<.>: 13 names (0 missing), 26 addrs (0 result, 26 avail) cacheNS
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   j.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   d.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   b.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   f.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   m.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   i.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   c.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   h.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   k.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   l.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   g.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   e.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   a.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:503:ba3e::2:30 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 198.41.0.4 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:a8::e port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 192.203.230.10 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:12::d0d port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 192.112.36.4 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:9f::42 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 199.7.83.42 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:7fd::1 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 193.0.14.129 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:1::53 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 198.97.190.53 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2::c port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 192.33.4.12 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:7fe::53 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 192.36.148.17 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:dc3::35 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 202.12.27.33 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2f::f port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 192.5.5.241 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:200::b port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 199.9.14.201 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2d::d port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 199.7.91.13 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:503:c27::2:30 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 192.58.128.30 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iter_handle processing q with state INIT REQUEST STATE (stage 2)
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: resolving (init part 2):  ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iter_handle processing q with state INIT REQUEST STATE (stage 3)
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: resolving (init part 3):  ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: processQueryTargets: ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: DelegationPoint<.>: 13 names (0 missing), 26 addrs (0 result, 26 avail) cacheNS
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   j.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   d.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   b.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   f.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   m.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   i.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   c.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   h.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   k.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   l.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   g.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   e.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   a.root-servers.net. * A AAAA
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:503:ba3e::2:30 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 198.41.0.4 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:a8::e port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 192.203.230.10 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:12::d0d port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 192.112.36.4 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:9f::42 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 199.7.83.42 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:7fd::1 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 193.0.14.129 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:1::53 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 198.97.190.53 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2::c port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 192.33.4.12 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:7fe::53 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 192.36.148.17 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:dc3::35 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 202.12.27.33 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2f::f port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 192.5.5.241 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:200::b port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 199.9.14.201 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:500:2d::d port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 199.7.91.13 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip6 2001:503:c27::2:30 port 53 (len 28)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 192.58.128.30 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: attempt to get extra 2 targets
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: servselect ip4 198.97.190.53 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    rtt=415
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: servselect ip4 193.0.14.129 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    rtt=324
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: selrtt 324
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: sending query: ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: sending to target: <.> 198.97.190.53#53
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: dnssec status: not expected
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: EDNS lookup known=1 vs=0
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: serviced query UDP timeout=415 msec
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: inserted new pending reply id=cd0a
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: opened UDP if=0 port=15861
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: comm point start listening 12
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_wait_reply
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: mesh_run: end 2 recursion states (1 with reply, 0 detached), 1 waiting replies, 1 recursion replies sent, 0 replies dropped, 0 states jostled out
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: average recursion processing time 0.243609 sec
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: histogram of recursion processing times
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: [25%]=0 median[50%]=0 [75%]=0
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: lower(secs) upper(secs) recursions
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:    0.131072    0.262144 1
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: 0vRDCD mod0  ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: 1RDdc mod0 rep mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: cache memory msg=67177 rrset=84427 infra=7050 val=0 subnet=0
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: svcd callbacks end
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: close of port 13446
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: close fd 13
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: answer cb
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: Incoming reply id = cd0a
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: Incoming reply addr = ip4 198.97.190.53 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: lookup size is 1 entries
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: received udp reply.
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: udp message[1038:0] [payload removed: 512 characters]
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: udp message[1038:256] [payload removed: 512 characters]
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: udp message[1038:512] [payload removed: 512 characters]
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: udp message[1038:768] [payload removed: 512 characters]
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: udp message[1038:1024] BBC6370000291000000080000000
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: outnet handle udp reply
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: measured roundtrip at 88 msec
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: svcd callbacks start
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: worker svcd callback for qstate 0x555d5edf7880
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: mesh_run: start
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_reply event:module_event_reply
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: iterator operate: query ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: process_response: new external response event
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: scrub for . NS IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: response for ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: reply from <.> 198.97.190.53#53
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NXDOMAIN, id: 0#012;; flags: qr aa ; QUERY: 1, ANSWER: 0, AUTHORITY: 6, ADDITIONAL: 0 #012;; QUESTION SECTION:#012ns.mytest.example.mytest.#011IN#011A#012#012;; ANSWER SECTION:#012#012;; AUTHORITY SECTION:#012my.#01186400#011IN#011NSEC#011mz. NS DS RRSIG NSEC#012my.#01186400#011IN#011RRSIG#011NSEC 8 1 86400 20171213050000 20171130040000 46809 . [payload removed: 344 characters] ;{id = 46809}#012.#01186400#011IN#011NSEC#011aaa. NS SOA RRSIG NSEC DNSKEY#012.#01186400#011IN#011RRSIG#011NSEC 8 0 86400 20171213050000 20171130040000 46809 . [payload removed: 344 characters] ;{id = 46809}#012.#0113600#011IN#011SOA#011a.root-servers.net. nstld.verisign-grs.com. 2017113000 1800 900 604800 86400#012.#01186400#011IN#011RRSIG#011SOA 8 0 86400 20171213050000 20171130040000 46809 . [payload removed: 344 characters] ;{id = 46809}#012#012;; ADDITIONAL SECTION:#012;; MSG SIZE  rcvd: 1027
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: query response was NXDOMAIN ANSWER
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iter_handle processing q with state FINISHED RESPONSE STATE
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: finishing processing for ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: store parent-side negative ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_finished
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: processTargetResponse ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: processTargetResponse super mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iterator TargetResponse failed
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iterator[module 0] operate: extstate:module_wait_subquery event:module_event_pass
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: iterator operate: query mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: iter_handle processing q with state QUERY TARGETS STATE
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: processQueryTargets: mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 5
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: DelegationPoint<mytest.example.mytest.>: 1 names (0 missing), 1 addrs (0 result, 0 avail) parentNS
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:   ns.mytest.example.mytest. * A PSIDE_A
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug:    ip4 172.21.0.1 port 53 (len 16)
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: No more query targets, attempting last resort
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: found in cache ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: found parent-side ns.mytest.example.mytest. A IN
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: out of query targets -- returning SERVFAIL
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: store error response in message cache
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: return error response SERVFAIL
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: mesh_run: iterator module exit state is module_finished
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: query took 12.389101 sec
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: average recursion processing time 6.316355 sec
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: histogram of recursion processing times
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: [25%]=0 median[50%]=0 [75%]=0
Nov 30 11:29:43 NickDeb unbound: [108552:0] info: lower(secs) upper(secs) recursions
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:    0.131072    0.262144 1
Nov 30 11:29:43 NickDeb unbound: [108552:0] info:    8.000000   16.000000 1
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: cache memory msg=67714 rrset=86324 infra=7050 val=0 subnet=0
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: svcd callbacks end
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: close of port 15861
Nov 30 11:29:43 NickDeb unbound: [108552:0] debug: close fd 12
