Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refuse[53:0] E11701000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 61935 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] debug: refuse[53:0] 7ACC01000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:44 gw unbound[31576]: [31576:1] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 56032 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refuse[53:0] 9EAC01000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 62146 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: refuse[53:0] 2F7C01000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 50619 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: refuse[53:0] 7E8401000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 55306 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refuse[53:0] 49E101000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 49408 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refuse[53:0] EF7E01000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 54724 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] debug: refuse[53:0] 229701000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:44 gw unbound[31576]: [31576:1] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 63075 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refuse[53:0] 54DF01000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 63922 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: refuse[53:0] 363B01000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 60514 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refuse[53:0] 5B7501000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 64394 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refuse[53:0] 4B5601000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:44 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 64836 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:1] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: comm point listen_for_rw 21 0 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: startlistening 21 mode rw Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: comm point start listening 21 (-1 msec) Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: outnet_tcp_take_query_setup: setup packet to write len 128 timeout 48128 msec Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: reuse_tcp_insert 1.0.0.1#853 fd -1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: the query is using TLS encryption, for cloudflare-dns.com Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: pending_tcp_query: new fd, connect Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: reuse_tcp_find: num reuse streams 0 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: reuse_tcp_find Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: pending_tcp_query Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: serviced send timer Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: cache memory msg=78589 rrset=66104 infra=10516 val=66320 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: 0RDd mod1 rep p2p.reolink.com. A IN Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: 0.524288 1.000000 1 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: 0.000000 0.000001 29 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: lower(secs) upper(secs) recursions Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: [25%]=2.58621e-07 median[50%]=5.17241e-07 [75%]=7.75862e-07 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: histogram of recursion processing times Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: average recursion processing time 0.019271 sec Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 64 waiting replies, 30 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: mesh_run: iterator module exit state is module_wait_reply Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: dnssec status: not expected Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: sending to target: <.> 1.0.0.1#853 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: sending query: p2p.reolink.com. A IN Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: selrtt 48128 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: rtt=48128 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: rtt=48128 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: rtt=48128 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: rtt=48128 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: attempt to get extra 3 targets Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: processQueryTargets: p2p.reolink.com. A IN Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: forwarding request Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: request has dependency depth of 0 Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: resolving p2p.reolink.com. A IN Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: process_request: new external request event Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: validator: pass to next module Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: validator operate: query p2p.reolink.com. A IN Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: mesh_run: start Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: udp request from ip4 10.10.5.17 port 39421 (len 16) Aug 8 10:41:44 gw unbound[31576]: [31576:2] debug: answer from the cache failed Aug 8 10:41:44 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:43 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:43 gw unbound[31576]: [31576:2] debug: refuse[49:0] 59680100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:43 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 58663 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:43 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:43 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:43 gw unbound[31576]: [31576:3] debug: refuse[49:0] 89150100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:43 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 50469 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:43 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:43 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:43 gw unbound[31576]: [31576:2] debug: refuse[49:0] F5EF0100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:43 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 58889 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:43 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:43 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:43 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:43 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:43 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:43 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:43 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:43 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:43 gw unbound[31576]: [31576:2] debug: refuse[49:0] 308B0100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:43 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 51656 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:43 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:43 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:43 gw unbound[31576]: [31576:3] debug: refuse[49:0] 65BD0100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:43 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 62270 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:43 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:43 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:43 gw unbound[31576]: [31576:3] debug: refuse[49:0] 700A0100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:43 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 60152 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:43 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:43 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:43 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:43 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:43 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:43 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:43 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refuse[49:0] C03C0100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 62919 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refuse[49:0] 6BCA0100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 60970 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] debug: refuse[49:0] 9FC20100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:42 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 50798 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] debug: refuse[49:0] CAFA0100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:42 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 60749 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refuse[49:0] AB660100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 59400 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refuse[49:0] 7DD40100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 49329 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:0] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:0] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refuse[49:0] 82090100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 58544 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] debug: refuse[49:0] 5F700100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:42 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 61021 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refuse[49:0] 0EAD0100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 59634 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refuse[49:0] A2890100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 55674 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] debug: refuse[49:0] 0ED90100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:42 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 56504 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refuse[49:0] 00D90100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:42 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 50832 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:42 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:1] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:1] debug: using localzone hq.redacted.com. transparent Aug 8 10:41:41 gw unbound[31576]: [31576:1] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: refuse[39:0] B99B010000010000000000000B7773732D7072696D61727905736C61636B03636F6D0000410001 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 58938 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:41 gw unbound[31576]: [31576:1] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:41 gw unbound[31576]: [31576:1] debug: refuse[39:0] 317F010000010000000000000B7773732D7072696D61727905736C61636B03636F6D0000010001 Aug 8 10:41:41 gw unbound[31576]: [31576:1] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 49921 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:41 gw unbound[31576]: [31576:1] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: refuse[39:0] 28E1010000010000000000000B7773732D7072696D61727905736C61636B03636F6D00001C0001 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 57644 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: refuse[39:0] C173010000010000000000000B7773732D7072696D61727905736C61636B03636F6D0000410001 Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 54755 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: refuse[39:0] 52C6010000010000000000000B7773732D7072696D61727905736C61636B03636F6D0000010001 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 52440 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: refuse[39:0] BDE5010000010000000000000B7773732D7072696D61727905736C61636B03636F6D00001C0001 Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 63244 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: serviced_delete Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: svcd callbacks end Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: cache memory msg=78589 rrset=66104 infra=10516 val=66320 Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: 0.524288 1.000000 1 Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: 0.000000 0.000001 29 Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: lower(secs) upper(secs) recursions Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: [25%]=2.58621e-07 median[50%]=5.17241e-07 [75%]=7.75862e-07 Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: histogram of recursion processing times Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: average recursion processing time 0.019271 sec Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 63 waiting replies, 30 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: drop reply, it is older than discard-timeout Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: drop reply, it is older than discard-timeout Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: validator: nextmodule returned Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: validator operate: query client.wns.windows.com. AAAA IN Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: return error response SERVFAIL Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: store error response in message cache Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: No more query targets, attempting last resort Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: attempt to get extra 3 targets Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (4 result, 0 avail) parentNS Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 1 Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: processQueryTargets: client.wns.windows.com. AAAA IN Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: query response was timeout Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state QUERY RESPONSE STATE Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: process_response: new external response event Aug 8 10:41:41 gw unbound[31576]: [31576:2] info: iterator operate: query client.wns.windows.com. AAAA IN Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: mesh_run: start Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: worker svcd callback for qstate 0x2f727d15610 Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: svcd callbacks start Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: tcp error for address ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: close fd 24 Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: comm_point_close of 24: event_del Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: reuse_tcp_remove_tree_list Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: decommission_pending_tcp Aug 8 10:41:41 gw unbound[31576]: [31576:2] debug: outnet_tcptimer Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: serviced_delete Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: svcd callbacks end Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: cache memory msg=78589 rrset=66104 infra=10516 val=66320 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: 1.000000 2.000000 1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: 0.524288 1.000000 1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: 0.065536 0.131072 1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: 0.000000 0.000001 29 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: lower(secs) upper(secs) recursions Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: [25%]=2.75862e-07 median[50%]=5.51724e-07 [75%]=8.27586e-07 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: histogram of recursion processing times Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: average recursion processing time 0.088777 sec Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 34 waiting replies, 32 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: drop reply, it is older than discard-timeout Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: drop reply, it is older than discard-timeout Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: validator: nextmodule returned Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: validator operate: query client.wns.windows.com. A IN Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: return error response SERVFAIL Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: store error response in message cache Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: No more query targets, attempting last resort Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: attempt to get extra 3 targets Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (4 result, 0 avail) parentNS Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 1 Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: processQueryTargets: client.wns.windows.com. A IN Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: query response was timeout Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state QUERY RESPONSE STATE Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: process_response: new external response event Aug 8 10:41:41 gw unbound[31576]: [31576:3] info: iterator operate: query client.wns.windows.com. A IN Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: mesh_run: start Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: worker svcd callback for qstate 0x2f727f5f2d0 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: svcd callbacks start Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: tcp error for address ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: close fd 23 Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: comm_point_close of 23: event_del Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: reuse_tcp_remove_tree_list Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: decommission_pending_tcp Aug 8 10:41:41 gw unbound[31576]: [31576:3] debug: outnet_tcptimer Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: serviced_delete Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: svcd callbacks end Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: cache memory msg=78589 rrset=66104 infra=10516 val=66320 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: 0RDd mod1 rep client.wns.windows.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: 0.524288 1.000000 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: 0.000000 0.000001 29 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: lower(secs) upper(secs) recursions Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: [25%]=2.58621e-07 median[50%]=5.17241e-07 [75%]=7.75862e-07 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: histogram of recursion processing times Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: average recursion processing time 0.019271 sec Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 63 waiting replies, 30 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: drop reply, it is older than discard-timeout Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: validator: nextmodule returned Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: validator operate: query wpad.hq.redacted.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: return error response SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: store error response in message cache Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: No more query targets, attempting last resort Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: attempt to get extra 3 targets Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (4 result, 0 avail) parentNS Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: processQueryTargets: wpad.hq.redacted.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: query response was timeout Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state QUERY RESPONSE STATE Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: process_response: new external response event Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: iterator operate: query wpad.hq.redacted.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: mesh_run: start Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: worker svcd callback for qstate 0x2f727cd4b10 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: svcd callbacks start Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: tcp error for address ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: close fd 22 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: comm_point_close of 22: event_del Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: reuse_tcp_remove_tree_list Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: decommission_pending_tcp Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: outnet_tcptimer Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: serviced_delete Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: svcd callbacks end Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: cache memory msg=78589 rrset=66104 infra=10516 val=66320 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: 1.000000 2.000000 1 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: 0.000000 0.000001 18 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: lower(secs) upper(secs) recursions Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: [25%]=2.63889e-07 median[50%]=5.27778e-07 [75%]=7.91667e-07 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: histogram of recursion processing times Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: average recursion processing time 0.056021 sec Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 11 waiting replies, 19 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: drop reply, it is older than discard-timeout Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: validator: nextmodule returned Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: validator operate: query wpad.hq.redacted.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: return error response SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: store error response in message cache Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: No more query targets, attempting last resort Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: attempt to get extra 3 targets Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (4 result, 0 avail) parentNS Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 1 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: processQueryTargets: wpad.hq.redacted.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: query response was timeout Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: iter_handle processing q with state QUERY RESPONSE STATE Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: process_response: new external response event Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: iterator operate: query wpad.hq.redacted.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: mesh_run: start Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: worker svcd callback for qstate 0x2f727b46a10 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: svcd callbacks start Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: tcp error for address ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: close fd 21 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: comm_point_close of 21: event_del Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: reuse_tcp_remove_tree_list Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: decommission_pending_tcp Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: outnet_tcptimer Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refuse[49:0] 5C870100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 53877 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refuse[49:0] 56FA0100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 59917 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refuse[49:0] ADD60100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 54772 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refuse[49:0] 593D0100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 49384 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: refuse[49:0] A0D50100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 63636 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: cache memory msg=78589 rrset=66104 infra=10516 val=66320 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refuse[49:0] EA310100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 54504 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: 0.524288 1.000000 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: 0.065536 0.131072 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: lower(secs) upper(secs) recursions Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: [25%]=2.75862e-07 median[50%]=5.51724e-07 [75%]=8.27586e-07 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: histogram of recursion processing times Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 34 waiting replies, 32 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: query took 0.000000 sec Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: 0RDd mod1 rep wpad.hq.redacted.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: validator: nextmodule returned Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: return error response SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: cache memory msg=78589 rrset=66104 infra=10516 val=66320 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: 0.524288 1.000000 1 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: 0RDd mod1 rep wpad.hq.redacted.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: store error response in message cache Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: 0.000000 0.000001 29 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: lower(secs) upper(secs) recursions Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: [25%]=2.58621e-07 median[50%]=5.17241e-07 [75%]=7.75862e-07 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: 1.000000 2.000000 1 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: 0.000000 0.000001 18 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: lower(secs) upper(secs) recursions Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: [25%]=2.63889e-07 median[50%]=5.27778e-07 [75%]=7.91667e-07 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: histogram of recursion processing times Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: average recursion processing time 0.019271 sec Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: histogram of recursion processing times Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: average recursion processing time 0.056021 sec Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 11 waiting replies, 19 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: No more query targets, attempting last resort Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: query took 0.000000 sec Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: mesh_run: end 2 recursion states (2 with reply, 0 detached), 63 waiting replies, 30 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: query took 0.000000 sec Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: validator: nextmodule returned Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: validator operate: query content-autofill.googleapis.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: validator: nextmodule returned Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: validator operate: query content-autofill.googleapis.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: return error response SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: store error response in message cache Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: return error response SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: store error response in message cache Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: attempt to get extra 3 targets Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: No more query targets, attempting last resort Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: No more query targets, attempting last resort Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: attempt to get extra 3 targets Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: attempt to get extra 3 targets Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: processQueryTargets: content-autofill.googleapis.com. HTTPS IN Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: forwarding request Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: request has dependency depth of 0 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: resolving content-autofill.googleapis.com. HTTPS IN Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: process_request: new external request event Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: validator: pass to next module Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: validator operate: query content-autofill.googleapis.com. HTTPS IN Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: mesh_run: start Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: udp request from ip4 10.10.0.11 port 57754 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: answer from the cache failed Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: processQueryTargets: content-autofill.googleapis.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: forwarding request Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: request has dependency depth of 0 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: resolving content-autofill.googleapis.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: process_request: new external request event Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: validator: pass to next module Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: validator operate: query content-autofill.googleapis.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: processQueryTargets: content-autofill.googleapis.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: forwarding request Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: mesh_run: start Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: request has dependency depth of 0 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: resolving content-autofill.googleapis.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: process_request: new external request event Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: validator: pass to next module Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: validator operate: query content-autofill.googleapis.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: udp request from ip4 10.10.0.11 port 59782 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: answer from the cache failed Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: mesh_run: start Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: udp request from ip4 10.10.0.11 port 51016 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: answer from the cache failed Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refuse[53:0] 1C3D01000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 63744 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refuse[53:0] B01101000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 52065 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refuse[53:0] CC4401000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 60504 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refuse[53:0] FBE401000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 56111 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refuse[53:0] 5A1001000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 55734 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refuse[53:0] D01301000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 49737 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refuse[53:0] 701001000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 64984 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refuse[53:0] 7FEC01000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 58748 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refuse[53:0] 7D3701000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 51158 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refuse[53:0] 443A01000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 49231 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refuse[53:0] AA6901000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 59484 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refuse[53:0] 1EE501000001000000000000146F7074696D697A6174696F6E67756964652D70610A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:40 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 54172 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:40 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: cache memory msg=78589 rrset=66104 infra=10516 val=66320 Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: cache memory msg=78589 rrset=66104 infra=10516 val=66320 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: 1RDd mod1 rep client.wns.windows.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: 0RDd mod1 rep wpad.hq.redacted.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:0] info: lower(secs) upper(secs) recursions Aug 8 10:41:40 gw unbound[31576]: [31576:0] info: [25%]=2.5e-07 median[50%]=5e-07 [75%]=7.5e-07 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: 1.000000 2.000000 1 Aug 8 10:41:40 gw unbound[31576]: [31576:0] info: histogram of recursion processing times Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: 0.524288 1.000000 1 Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: 0.000000 0.000001 17 Aug 8 10:41:40 gw unbound[31576]: [31576:0] info: average recursion processing time 0.000000 sec Aug 8 10:41:40 gw unbound[31576]: [31576:0] info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 6 waiting replies, 9 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: lower(secs) upper(secs) recursions Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: 0.000000 0.000001 28 Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: query took 0.000000 sec Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: [25%]=2.64706e-07 median[50%]=5.29412e-07 [75%]=7.94118e-07 Aug 8 10:41:40 gw unbound[31576]: [31576:0] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: lower(secs) upper(secs) recursions Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: [25%]=2.58929e-07 median[50%]=5.17857e-07 [75%]=7.76786e-07 Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: histogram of recursion processing times Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: average recursion processing time 0.059133 sec Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: histogram of recursion processing times Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: average recursion processing time 0.019936 sec Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: mesh_run: end 2 recursion states (2 with reply, 0 detached), 63 waiting replies, 29 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 11 waiting replies, 18 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: validator: nextmodule returned Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: query took 0.000000 sec Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: query took 0.000000 sec Aug 8 10:41:40 gw unbound[31576]: [31576:0] info: validator operate: query optimizationguide-pa.googleapis.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: validator: nextmodule returned Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: validator operate: query optimizationguide-pa.googleapis.com. HTTPS IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: validator: nextmodule returned Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: return error response SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: validator operate: query optimizationguide-pa.googleapis.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: store error response in message cache Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: return error response SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: No more query targets, attempting last resort Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: store error response in message cache Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: return error response SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: store error response in message cache Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: No more query targets, attempting last resort Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: No more query targets, attempting last resort Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: attempt to get extra 3 targets Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: attempt to get extra 3 targets Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: attempt to get extra 3 targets Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: processQueryTargets: optimizationguide-pa.googleapis.com. HTTPS IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:0] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: forwarding request Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: request has dependency depth of 0 Aug 8 10:41:40 gw unbound[31576]: [31576:0] info: processQueryTargets: optimizationguide-pa.googleapis.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: resolving optimizationguide-pa.googleapis.com. HTTPS IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: forwarding request Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: process_request: new external request event Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: request has dependency depth of 0 Aug 8 10:41:40 gw unbound[31576]: [31576:0] info: resolving optimizationguide-pa.googleapis.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: process_request: new external request event Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: validator: pass to next module Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: validator operate: query optimizationguide-pa.googleapis.com. HTTPS IN Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: processQueryTargets: optimizationguide-pa.googleapis.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: validator: pass to next module Aug 8 10:41:40 gw unbound[31576]: [31576:0] info: validator operate: query optimizationguide-pa.googleapis.com. A IN Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: mesh_run: start Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: udp request from ip4 10.10.0.11 port 57062 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: forwarding request Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: mesh_run: start Aug 8 10:41:40 gw unbound[31576]: [31576:2] debug: answer from the cache failed Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: request has dependency depth of 0 Aug 8 10:41:40 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: udp request from ip4 10.10.0.11 port 50433 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: resolving optimizationguide-pa.googleapis.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: process_request: new external request event Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:40 gw unbound[31576]: [31576:0] debug: answer from the cache failed Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: validator: pass to next module Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: validator operate: query optimizationguide-pa.googleapis.com. AAAA IN Aug 8 10:41:40 gw unbound[31576]: [31576:0] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: mesh_run: start Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: udp request from ip4 10.10.0.11 port 59428 (len 16) Aug 8 10:41:40 gw unbound[31576]: [31576:1] debug: answer from the cache failed Aug 8 10:41:40 gw unbound[31576]: [31576:1] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: refuse[32:0] E167010000010000000000000377777706676F6F676C6503636F6D0000410001 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 57043 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: refuse[32:0] E949010000010000000000000377777706676F6F676C6503636F6D0000010001 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 49378 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: refuse[32:0] D2B4010000010000000000000377777706676F6F676C6503636F6D00001C0001 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 53986 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: refuse[32:0] DDBC010000010000000000000377777706676F6F676C6503636F6D0000410001 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 51926 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: refuse[32:0] 91DC010000010000000000000377777706676F6F676C6503636F6D0000010001 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 56941 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: refuse[32:0] 1B86010000010000000000000377777706676F6F676C6503636F6D00001C0001 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 65211 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: cache memory msg=78589 rrset=66104 infra=10516 val=66320 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: 0RDd mod1 rep client.wns.windows.com. A IN Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: 1.000000 2.000000 1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: 0.524288 1.000000 1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: 0.065536 0.131072 1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: 0.000000 0.000001 28 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: lower(secs) upper(secs) recursions Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: [25%]=2.76786e-07 median[50%]=5.53571e-07 [75%]=8.30357e-07 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: histogram of recursion processing times Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: average recursion processing time 0.091641 sec Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 34 waiting replies, 31 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: query took 0.000000 sec Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: validator: nextmodule returned Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: validator operate: query www.google.com. HTTPS IN Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: return error response SERVFAIL Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: store error response in message cache Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: No more query targets, attempting last resort Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: attempt to get extra 3 targets Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: processQueryTargets: www.google.com. HTTPS IN Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: forwarding request Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: request has dependency depth of 0 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: resolving www.google.com. HTTPS IN Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: process_request: new external request event Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: validator: pass to next module Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: validator operate: query www.google.com. HTTPS IN Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: mesh_run: start Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: udp request from ip4 10.10.0.11 port 56608 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: cache memory msg=78389 rrset=66104 infra=10516 val=66320 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: 1RDd mod1 rep client.wns.windows.com. AAAA IN Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: 0RDd mod1 rep wpad.hq.redacted.com. AAAA IN Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: 0.524288 1.000000 1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: 0.000000 0.000001 27 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: lower(secs) upper(secs) recursions Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: [25%]=2.59259e-07 median[50%]=5.18519e-07 [75%]=7.77778e-07 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: histogram of recursion processing times Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: average recursion processing time 0.020648 sec Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: mesh_run: end 2 recursion states (2 with reply, 0 detached), 63 waiting replies, 28 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: query took 0.000000 sec Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: validator: nextmodule returned Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: validator operate: query www.google.com. A IN Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: return error response SERVFAIL Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: store error response in message cache Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: No more query targets, attempting last resort Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: attempt to get extra 3 targets Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: processQueryTargets: www.google.com. A IN Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: forwarding request Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: request has dependency depth of 0 Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: resolving www.google.com. A IN Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: process_request: new external request event Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: validator: pass to next module Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: validator operate: query www.google.com. A IN Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: mesh_run: start Aug 8 10:41:39 gw unbound[31576]: [31576:2] debug: udp request from ip4 10.10.0.11 port 61516 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: cache memory msg=78189 rrset=66104 infra=10516 val=66320 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: 0RDd mod1 rep client.wns.windows.com. A IN Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: 1.000000 2.000000 1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: 0.524288 1.000000 1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: 0.065536 0.131072 1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: 0.000000 0.000001 27 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: lower(secs) upper(secs) recursions Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: [25%]=2.77778e-07 median[50%]=5.55556e-07 [75%]=8.33333e-07 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: histogram of recursion processing times Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: average recursion processing time 0.094695 sec Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 34 waiting replies, 30 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: query took 0.000000 sec Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: validator: nextmodule returned Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: validator operate: query www.google.com. AAAA IN Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: return error response SERVFAIL Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: store error response in message cache Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: No more query targets, attempting last resort Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: attempt to get extra 3 targets Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: processQueryTargets: www.google.com. AAAA IN Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: forwarding request Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: request has dependency depth of 0 Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: resolving www.google.com. AAAA IN Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: process_request: new external request event Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: validator: pass to next module Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: validator operate: query www.google.com. AAAA IN Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: mesh_run: start Aug 8 10:41:39 gw unbound[31576]: [31576:3] debug: udp request from ip4 10.10.0.11 port 53111 (len 16) Aug 8 10:41:39 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: refuse[39:0] D4AF010000010000000000000B7773732D7072696D61727905736C61636B03636F6D0000410001 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 52074 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: refuse[39:0] 9D14010000010000000000000B7773732D7072696D61727905736C61636B03636F6D0000010001 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 51297 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: refuse[39:0] 0BEF010000010000000000000B7773732D7072696D61727905736C61636B03636F6D00001C0001 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 56497 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: refuse[39:0] 24F1010000010000000000000B7773732D7072696D61727905736C61636B03636F6D0000410001 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 60120 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: refuse[39:0] C536010000010000000000000B7773732D7072696D61727905736C61636B03636F6D0000010001 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 56586 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: refuse[39:0] B638010000010000000000000B7773732D7072696D61727905736C61636B03636F6D00001C0001 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 61894 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: cache memory msg=77989 rrset=66104 infra=10516 val=66320 Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: 1RDd mod1 rep client.wns.windows.com. AAAA IN Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: 0RDd mod1 rep wpad.hq.redacted.com. AAAA IN Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: 0.524288 1.000000 1 Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: 0.000000 0.000001 26 Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: lower(secs) upper(secs) recursions Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: [25%]=2.59615e-07 median[50%]=5.19231e-07 [75%]=7.78846e-07 Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: histogram of recursion processing times Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: average recursion processing time 0.021412 sec Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: mesh_run: end 2 recursion states (2 with reply, 0 detached), 63 waiting replies, 27 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: query took 0.000000 sec Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: validator: nextmodule returned Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: validator operate: query wss-primary.slack.com. HTTPS IN Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: return error response SERVFAIL Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: store error response in message cache Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: No more query targets, attempting last resort Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: attempt to get extra 3 targets Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: processQueryTargets: wss-primary.slack.com. HTTPS IN Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: forwarding request Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: request has dependency depth of 0 Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: resolving wss-primary.slack.com. HTTPS IN Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: process_request: new external request event Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: validator: pass to next module Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: validator operate: query wss-primary.slack.com. HTTPS IN Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: mesh_run: start Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: udp request from ip4 10.10.0.11 port 54860 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:2] debug: answer from the cache failed Aug 8 10:41:38 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: cache memory msg=77989 rrset=66104 infra=10516 val=66320 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: 0RDd mod1 rep client.wns.windows.com. A IN Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: 1.000000 2.000000 1 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: 0.524288 1.000000 1 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: 0.065536 0.131072 1 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: 0.000000 0.000001 26 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: lower(secs) upper(secs) recursions Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: [25%]=2.78846e-07 median[50%]=5.57692e-07 [75%]=8.36538e-07 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: histogram of recursion processing times Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: average recursion processing time 0.097961 sec Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 34 waiting replies, 29 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: query took 0.000000 sec Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: validator: nextmodule returned Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: validator operate: query wss-primary.slack.com. A IN Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: return error response SERVFAIL Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: store error response in message cache Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: No more query targets, attempting last resort Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: attempt to get extra 3 targets Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: processQueryTargets: wss-primary.slack.com. A IN Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: forwarding request Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: request has dependency depth of 0 Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: resolving wss-primary.slack.com. A IN Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: process_request: new external request event Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: validator: pass to next module Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: validator operate: query wss-primary.slack.com. A IN Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: mesh_run: start Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: udp request from ip4 10.10.0.11 port 64014 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:3] debug: answer from the cache failed Aug 8 10:41:38 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: cache memory msg=77989 rrset=66104 infra=10516 val=66320 Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: 0RDd mod1 rep wpad.hq.redacted.com. A IN Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: 1.000000 2.000000 1 Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: 0.000000 0.000001 16 Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: lower(secs) upper(secs) recursions Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: [25%]=2.65625e-07 median[50%]=5.3125e-07 [75%]=7.96875e-07 Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: histogram of recursion processing times Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: average recursion processing time 0.062611 sec Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 11 waiting replies, 17 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: query took 0.000000 sec Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: validator: nextmodule returned Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: validator operate: query wss-primary.slack.com. AAAA IN Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: return error response SERVFAIL Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: store error response in message cache Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: No more query targets, attempting last resort Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: attempt to get extra 3 targets Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: processQueryTargets: wss-primary.slack.com. AAAA IN Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: forwarding request Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: request has dependency depth of 0 Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: resolving wss-primary.slack.com. AAAA IN Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: process_request: new external request event Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: validator: pass to next module Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: validator operate: query wss-primary.slack.com. AAAA IN Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: mesh_run: start Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: udp request from ip4 10.10.0.11 port 57475 (len 16) Aug 8 10:41:38 gw unbound[31576]: [31576:1] debug: answer from the cache failed Aug 8 10:41:38 gw unbound[31576]: [31576:1] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refuse[43:0] EB36010000010000000000000D677565312D7370636C69656E740773706F7469667903636F6D0000410001 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 63963 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: refuse[43:0] E6E3010000010000000000000D677565312D7370636C69656E740773706F7469667903636F6D0000010001 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 57747 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refuse[43:0] 1A9B010000010000000000000D677565312D7370636C69656E740773706F7469667903636F6D00001C0001 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 65399 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: refuse[43:0] 2FD6010000010000000000000D677565312D7370636C69656E740773706F7469667903636F6D0000410001 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 55058 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refuse[43:0] 6A9D010000010000000000000D677565312D7370636C69656E740773706F7469667903636F6D0000010001 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 55353 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: refuse[43:0] D674010000010000000000000D677565312D7370636C69656E740773706F7469667903636F6D00001C0001 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 55982 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refuse[43:0] 8E32010000010000000000000D677565312D7370636C69656E740773706F7469667903636F6D0000010001 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 61705 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refuse[43:0] 297B010000010000000000000D677565312D7370636C69656E740773706F7469667903636F6D0000410001 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 54934 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: refuse[43:0] 0AC9010000010000000000000D677565312D7370636C69656E740773706F7469667903636F6D00001C0001 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 49612 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refuse[43:0] 523D010000010000000000000D677565312D7370636C69656E740773706F7469667903636F6D0000010001 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 49813 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refuse[43:0] 90C2010000010000000000000D677565312D7370636C69656E740773706F7469667903636F6D0000410001 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: cache memory msg=77989 rrset=66104 infra=10516 val=66320 Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: cache memory msg=77989 rrset=66104 infra=10516 val=66320 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: 0RDd mod1 rep client.wns.windows.com. A IN Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: 0RDd mod1 rep wpad.hq.redacted.com. A IN Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: 0.524288 1.000000 1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: 0.065536 0.131072 1 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: lower(secs) upper(secs) recursions Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: [25%]=2.8e-07 median[50%]=5.6e-07 [75%]=8.4e-07 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: 1.000000 2.000000 1 Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: 0.000000 0.000001 15 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refuse[43:0] 9E67010000010000000000000D677565312D7370636C69656E740773706F7469667903636F6D00001C0001 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: histogram of recursion processing times Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: average recursion processing time 0.101459 sec Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 34 waiting replies, 28 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: lower(secs) upper(secs) recursions Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 56474 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: query took 0.000000 sec Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: [25%]=2.66667e-07 median[50%]=5.33333e-07 [75%]=8e-07 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: histogram of recursion processing times Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: average recursion processing time 0.066525 sec Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 11 waiting replies, 16 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: cache memory msg=77989 rrset=66104 infra=10516 val=66320 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: validator: nextmodule returned Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: validator operate: query gue1-spclient.spotify.com. A IN Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: query took 0.000000 sec Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: 1RDd mod1 rep client.wns.windows.com. AAAA IN Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: return error response SERVFAIL Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: validator: nextmodule returned Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: validator operate: query gue1-spclient.spotify.com. HTTPS IN Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: return error response SERVFAIL Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: 0RDd mod1 rep wpad.hq.redacted.com. AAAA IN Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: store error response in message cache Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: store error response in message cache Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: No more query targets, attempting last resort Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: No more query targets, attempting last resort Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: 0.524288 1.000000 1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: 0.000000 0.000001 25 Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: lower(secs) upper(secs) recursions Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: [25%]=2.6e-07 median[50%]=5.2e-07 [75%]=7.8e-07 Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: histogram of recursion processing times Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: average recursion processing time 0.022236 sec Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: rtt=120000 Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: mesh_run: end 2 recursion states (2 with reply, 0 detached), 63 waiting replies, 26 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: query took 0.000000 sec Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: attempt to get extra 3 targets Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: validator: nextmodule returned Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: validator operate: query gue1-spclient.spotify.com. AAAA IN Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: return error response SERVFAIL Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: store error response in message cache Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: attempt to get extra 3 targets Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: No more query targets, attempting last resort Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: processQueryTargets: gue1-spclient.spotify.com. HTTPS IN Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: forwarding request Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: request has dependency depth of 0 Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: resolving gue1-spclient.spotify.com. HTTPS IN Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: process_request: new external request event Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: validator: pass to next module Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: validator operate: query gue1-spclient.spotify.com. HTTPS IN Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: mesh_run: start Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:35 gw unbound[31576]: [31576:1] debug: udp request from ip4 10.10.0.11 port 53061 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: attempt to get extra 3 targets Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:35 gw unbound[31576]: [31576:1] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: processQueryTargets: gue1-spclient.spotify.com. A IN Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: forwarding request Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: request has dependency depth of 0 Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: resolving gue1-spclient.spotify.com. A IN Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: process_request: new external request event Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: validator: pass to next module Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: validator operate: query gue1-spclient.spotify.com. A IN Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: mesh_run: start Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:35 gw unbound[31576]: [31576:3] debug: udp request from ip4 10.10.0.11 port 59538 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:35 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: processQueryTargets: gue1-spclient.spotify.com. AAAA IN Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: forwarding request Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: request has dependency depth of 0 Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: resolving gue1-spclient.spotify.com. AAAA IN Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: process_request: new external request event Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: validator: pass to next module Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: validator operate: query gue1-spclient.spotify.com. AAAA IN Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: mesh_run: start Aug 8 10:41:35 gw unbound[31576]: [31576:2] debug: udp request from ip4 10.10.0.11 port 58960 (len 16) Aug 8 10:41:35 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: refuse[33:0] 4CFB010000010000000000000268710876696C6C6E6F726D03636F6D0000010001 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1006:1cb7:dbc6:e7b4:da00 port 62291 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:1] info: send_udp over interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: send_udp over interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:1] debug: refuse[62:0] 885201000001000000000000046570646705676C627072066D6E63323230066D6363333032037075620B336770706E6574776F726B036F72670000010001 Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: refuse[33:0] EBBB010000010000000000000268710876696C6C6E6F726D03636F6D00001C0001 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: refuse[62:0] CB1D01000001000000000000046570646705676C627072066D6E63323230066D6363333032037075620B336770706E6574776F726B036F726700001C0001 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1006:1cb7:dbc6:e7b4:da00 port 61657 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:1] debug: refused query from fd9a:62c0:b57d:1006:1cb7:dbc6:e7b4:da00 port 56086 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: refused query from fd9a:62c0:b57d:1006:1cb7:dbc6:e7b4:da00 port 56210 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: refuse[39:0] 2F6D01000001000000000000076F75746C6F6F6B096F666669636533363503636F6D0000010001 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:1] info: receive_udp on interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: receive_udp on interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1006:1cb7:dbc6:e7b4:da00 port 55217 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: refuse[39:0] A7E301000001000000000000076F75746C6F6F6B096F666669636533363503636F6D00001C0001 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1006:1cb7:dbc6:e7b4:da00 port 49771 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: refuse[39:0] 772F01000001000000000000076F75746C6F6F6B096F666669636533363503636F6D0000410001 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1006:1cb7:dbc6:e7b4:da00 port 49715 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1006::1 10 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: refuse[38:0] 0283010000010000000000000A7773732D6261636B757005736C61636B03636F6D0000410001 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 59488 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: refuse[38:0] FEEC010000010000000000000A7773732D6261636B757005736C61636B03636F6D0000010001 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 61226 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: refuse[38:0] F960010000010000000000000A7773732D6261636B757005736C61636B03636F6D00001C0001 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 62200 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: refuse[38:0] E037010000010000000000000A7773732D6261636B757005736C61636B03636F6D0000410001 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 56483 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: refuse[38:0] 2139010000010000000000000A7773732D6261636B757005736C61636B03636F6D0000010001 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 62233 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:34 gw unbound[31576]: [31576:1] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: cache memory msg=77356 rrset=66104 infra=10516 val=66320 Aug 8 10:41:34 gw unbound[31576]: [31576:1] debug: refuse[38:0] 7DF6010000010000000000000A7773732D6261636B757005736C61636B03636F6D00001C0001 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: 0RDd mod1 rep client.wns.windows.com. A IN Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: cache memory msg=77356 rrset=66104 infra=10516 val=66320 Aug 8 10:41:34 gw unbound[31576]: [31576:1] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 63625 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: 1.000000 2.000000 1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: 0.524288 1.000000 1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: 0.065536 0.131072 1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: 1RDd mod1 rep client.wns.windows.com. AAAA IN Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: cache memory msg=77356 rrset=66104 infra=10516 val=66320 Aug 8 10:41:34 gw unbound[31576]: [31576:1] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: 0.000000 0.000001 24 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: 0RDd mod1 rep wpad.hq.redacted.com. AAAA IN Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: 0.000000 0.000001 8 Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: lower(secs) upper(secs) recursions Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: [25%]=2.5e-07 median[50%]=5e-07 [75%]=7.5e-07 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: lower(secs) upper(secs) recursions Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: [25%]=2.8125e-07 median[50%]=5.625e-07 [75%]=8.4375e-07 Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: histogram of recursion processing times Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: average recursion processing time 0.000000 sec Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 6 waiting replies, 8 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: 0.524288 1.000000 1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: histogram of recursion processing times Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: query took 0.000000 sec Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: 0.000000 0.000001 24 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: average recursion processing time 0.105218 sec Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: lower(secs) upper(secs) recursions Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: [25%]=2.60417e-07 median[50%]=5.20833e-07 [75%]=7.8125e-07 Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: histogram of recursion processing times Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: average recursion processing time 0.023125 sec Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: validator: nextmodule returned Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: validator operate: query wss-backup.slack.com. HTTPS IN Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: mesh_run: end 2 recursion states (2 with reply, 0 detached), 63 waiting replies, 25 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 34 waiting replies, 27 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: query took 0.000000 sec Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: query took 0.000000 sec Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: return error response SERVFAIL Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: validator: nextmodule returned Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: validator operate: query wss-backup.slack.com. A IN Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: store error response in message cache Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: validator: nextmodule returned Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: validator operate: query wss-backup.slack.com. AAAA IN Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: No more query targets, attempting last resort Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: rtt=120000 Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: return error response SERVFAIL Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: store error response in message cache Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: rtt=120000 Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: return error response SERVFAIL Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: rtt=120000 Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: store error response in message cache Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: No more query targets, attempting last resort Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: rtt=120000 Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: No more query targets, attempting last resort Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: attempt to get extra 3 targets Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: attempt to get extra 3 targets Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: attempt to get extra 3 targets Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: processQueryTargets: wss-backup.slack.com. HTTPS IN Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: forwarding request Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: request has dependency depth of 0 Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: resolving wss-backup.slack.com. HTTPS IN Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: process_request: new external request event Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: validator: pass to next module Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: validator operate: query wss-backup.slack.com. HTTPS IN Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: mesh_run: start Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: udp request from ip4 10.10.0.11 port 54194 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:0] debug: answer from the cache failed Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: processQueryTargets: wss-backup.slack.com. A IN Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: forwarding request Aug 8 10:41:34 gw unbound[31576]: [31576:0] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: request has dependency depth of 0 Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: resolving wss-backup.slack.com. A IN Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: process_request: new external request event Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: validator: pass to next module Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: validator operate: query wss-backup.slack.com. A IN Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: mesh_run: start Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: processQueryTargets: wss-backup.slack.com. AAAA IN Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: forwarding request Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: udp request from ip4 10.10.0.11 port 50206 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: request has dependency depth of 0 Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: resolving wss-backup.slack.com. AAAA IN Aug 8 10:41:34 gw unbound[31576]: [31576:2] debug: answer from the cache failed Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: process_request: new external request event Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:34 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: validator: pass to next module Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: validator operate: query wss-backup.slack.com. AAAA IN Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: mesh_run: start Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: udp request from ip4 10.10.0.11 port 64884 (len 16) Aug 8 10:41:34 gw unbound[31576]: [31576:3] debug: answer from the cache failed Aug 8 10:41:34 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: using localzone hq.redacted.com. transparent Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: using localzone hq.redacted.com. transparent Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: using localzone hq.redacted.com. transparent Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: using localzone hq.redacted.com. transparent Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: using localzone hq.redacted.com. transparent Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: cache memory msg=77356 rrset=66104 infra=10516 val=66320 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: 1RDd mod1 rep client.wns.windows.com. AAAA IN Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: 0RDd mod1 rep wpad.hq.redacted.com. AAAA IN Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: 0.524288 1.000000 1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: 0.000000 0.000001 23 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: lower(secs) upper(secs) recursions Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: [25%]=2.6087e-07 median[50%]=5.21739e-07 [75%]=7.82609e-07 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: histogram of recursion processing times Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: average recursion processing time 0.024089 sec Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: mesh_run: end 2 recursion states (2 with reply, 0 detached), 63 waiting replies, 24 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: query took 0.000000 sec Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: validator: nextmodule returned Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: validator operate: query p2p.reolink.com.hq.redacted.com. A IN Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: return error response SERVFAIL Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: store error response in message cache Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: No more query targets, attempting last resort Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: attempt to get extra 3 targets Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: processQueryTargets: p2p.reolink.com.hq.redacted.com. A IN Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: forwarding request Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: request has dependency depth of 0 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: resolving p2p.reolink.com.hq.redacted.com. A IN Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: process_request: new external request event Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: validator: pass to next module Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: validator operate: query p2p.reolink.com.hq.redacted.com. A IN Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: mesh_run: start Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: udp request from ip4 10.10.5.17 port 43631 (len 16) Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: answer from the cache failed Aug 8 10:41:33 gw unbound[31576]: [31576:2] debug: using localzone hq.redacted.com. transparent Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: cache memory msg=77356 rrset=66104 infra=10516 val=66320 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: 0RDd mod1 rep client.wns.windows.com. A IN Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: 1.000000 2.000000 1 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: 0.524288 1.000000 1 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: 0.065536 0.131072 1 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: 0.000000 0.000001 23 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: lower(secs) upper(secs) recursions Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: [25%]=2.82609e-07 median[50%]=5.65217e-07 [75%]=8.47826e-07 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: histogram of recursion processing times Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: average recursion processing time 0.109264 sec Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 34 waiting replies, 26 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: query took 0.000000 sec Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.5.1 Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: validator: nextmodule returned Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: validator operate: query p2p.reolink.com. A IN Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: return error response SERVFAIL Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: store error response in message cache Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: No more query targets, attempting last resort Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: attempt to get extra 3 targets Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: DelegationPoint<.>: 0 names (0 missing), 4 addrs (0 result, 4 avail) parentNS Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: processQueryTargets: p2p.reolink.com. A IN Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state QUERY TARGETS STATE Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: forwarding request Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: request has dependency depth of 0 Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: resolving p2p.reolink.com. A IN Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: iter_handle processing q with state INIT REQUEST STATE Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: process_request: new external request event Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_wait_module Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: validator: pass to next module Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: validator operate: query p2p.reolink.com. A IN Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: mesh_run: start Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: udp request from ip4 10.10.5.17 port 59052 (len 16) Aug 8 10:41:33 gw unbound[31576]: [31576:3] debug: answer from the cache failed Aug 8 10:41:33 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.5.1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: refuse[49:0] F1B30100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 56881 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: refuse[49:0] 04820100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 64974 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: refuse[49:0] 31E60100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 51519 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: receive_udp on interface: 10.10.0.1 Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: refuse[49:0] BF100100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000010001 Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 64399 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: refuse[49:0] C00D0100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D00001C0001 Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 61154 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: send_udp over interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: refuse[49:0] BFD90100000100000000000010636F6E74656E742D6175746F66696C6C0A676F6F676C656170697303636F6D0000410001 Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: 1RDd mod1 rep client.wns.windows.com. AAAA IN Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: refused query from fd9a:62c0:b57d:1000:5ced:8df3:f68:87c4 port 49394 because of ::/128 (ACL on interface IP) refuse Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: receive_udp on interface: fd9a:62c0:b57d:1000::1 1 Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: 0.524288 1.000000 1 Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: lower(secs) upper(secs) recursions Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: cache memory msg=77356 rrset=66104 infra=10516 val=66320 Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: histogram of recursion processing times Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: average recursion processing time 0.025136 sec Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: mesh_run: end 2 recursion states (2 with reply, 0 detached), 63 waiting replies, 23 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: 0RDd mod1 rep client.wns.windows.com. A IN Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: query took 0.000000 sec Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: 1.000000 2.000000 1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: 0.524288 1.000000 1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: 0.065536 0.131072 1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: 0.000000 0.000001 22 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: lower(secs) upper(secs) recursions Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: [25%]=2.84091e-07 median[50%]=5.68182e-07 [75%]=8.52273e-07 Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: cache memory msg=77356 rrset=66104 infra=10516 val=66320 Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: histogram of recursion processing times Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: average recursion processing time 0.113635 sec Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 34 waiting replies, 25 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:32 gw unbound[31576]: [31576:0] info: 0.000000 0.000001 7 Aug 8 10:41:32 gw unbound[31576]: [31576:0] info: lower(secs) upper(secs) recursions Aug 8 10:41:32 gw unbound[31576]: [31576:0] info: [25%]=2.5e-07 median[50%]=5e-07 [75%]=7.5e-07 Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: validator: nextmodule returned Aug 8 10:41:32 gw unbound[31576]: [31576:2] info: validator operate: query content-autofill.googleapis.com. A IN Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: return error response SERVFAIL Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: query took 0.000000 sec Aug 8 10:41:32 gw unbound[31576]: [31576:0] info: histogram of recursion processing times Aug 8 10:41:32 gw unbound[31576]: [31576:0] info: average recursion processing time 0.000000 sec Aug 8 10:41:32 gw unbound[31576]: [31576:0] info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 6 waiting replies, 7 recursion replies sent, 0 replies dropped, 0 states jostled out Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: store error response in message cache Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: query took 0.000000 sec Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: validator: nextmodule returned Aug 8 10:41:32 gw unbound[31576]: [31576:3] info: validator operate: query content-autofill.googleapis.com. HTTPS IN Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: return error response SERVFAIL Aug 8 10:41:32 gw unbound[31576]: [31576:0] info: send_udp over interface: 10.10.0.1 Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: No more query targets, attempting last resort Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: store error response in message cache Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: No more query targets, attempting last resort Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: mesh_run: validator module exit state is module_finished Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: cannot validate non-answer, rcode SERVFAIL Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: validator: nextmodule returned Aug 8 10:41:32 gw unbound[31576]: [31576:0] info: validator operate: query content-autofill.googleapis.com. AAAA IN Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: mesh_run: iterator module exit state is module_finished Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: return error response SERVFAIL Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: store error response in message cache Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: configured stub or forward servers failed -- returning SERVFAIL Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: No more query targets, attempting last resort Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: rtt=120000 Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: servselect ip6 2606:4700:4700::1001 port 853 (len 28) Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: rtt=120000 Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: servselect ip4 1.1.1.1 port 853 (len 16) Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: rtt=120000 Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: servselect ip6 2606:4700:4700::1111 port 853 (len 28) Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: rpz: iterator module callback: have_rpz=0 Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: rtt=120000 Aug 8 10:41:32 gw unbound[31576]: [31576:2] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: attempt to get extra 3 targets Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: rtt=120000 Aug 8 10:41:32 gw unbound[31576]: [31576:0] debug: servselect ip4 1.0.0.1 port 853 (len 16) Aug 8 10:41:32 gw unbound[31576]: [31576:3] debug: [cloudflare-dns.com] ip4 1.1.1.1 port 853 (len 16)