DNS löst eine Domain nicht auf
-
Hallo,
ich nutze seit drei Tagen eine pfSense und habe jetzt das Problem, dass der dortige DNS-Server eine Domain nicht auflöst. Bis jetzt ist sharepoint.com die einzige Domain, die nicht aufgelöst wird, in den drei Tagen sind mir jedenfalls keine weiteren Seiten aufgefallen, die nicht gingen.
Vom PC aus ergibt sich folgendes Bild, wenn dieser die pfSense als DNS nutzt:
C:\WINDOWS\system32>nslookup
Standardserver: pfSense.ich.hier
Address: 192.168.100.1spiegel.de
Server: pfSense.ich.hier
Address: 192.168.100.1Nicht autorisierende Antwort:
Name: spiegel.de
Address: 128.65.210.8sharepoint.com
Server: pfSense.ich.hier
Address: 192.168.100.1***** sharepoint.com wurde von pfSense.ich.hier nicht gefunden: Server failed.**
Nutze ich die Funktion "DNS Lookup" in der pfSense direkt, bekomme ich durchaus ein Ergebnis für sharepoint.com - also kann die pfSense die Domain schon auflösen:
Result Record type
40.84.199.233 A
52.178.167.109 A
sharepoint.microsoft.com CNAMETimings
Name server Query time
8.8.8.8 43 msec
8.8.4.4 5055 msecDer DNS resolver ist aktiviert.
Hat jemand eine Idee, was ich falsch eingestellt habe?
Hätte ich zum Beispiel den Zugriff vom PC auf die pfSense blockiert, würde ja auch spiegel.de im Beispiel ganz oben nicht aufgelöst. Irgendwie finde ich das ziemlich mysteriös…
Viele Grüße,
Oliver
-
Wäre schön, wenn ein anderer Nutzer mal schauen könnte, ob seine/ihre pfSense die Domain sharepoint.com auflöst (von einem PC im LAN aus, nicht über das pfSense-Webinterface)… vielen Dank vorab! :)
-
Ja, getestet hab ich das. Geht problemlos. Das hilft dir vermutlich aber auch nicht weiter.
Welchen DNS verwendest du? Forwarder, Resolver?
Soweit ich mich erinnern kann, war ich mit beiden erfolgreich. -
Ah, danke. Na ja, das zeigt ja erstmal, dass es kein allgemeines Problem ist.
Ich benutze DNS Resolver, Screenshots anbei. Wie geschrieben, per Webinterface der pfSense bekomme ich die Domain aufgelöst. Nur nicht, wenn ein PC im LAN nachfragt…
PS: Reboot der pfSense hilft jedenfalls nicht.
-
Dies löst die Anfrage im Log aus:
Jun 7 14:32:12 unbound 18544:2 debug: rtt=79 Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=113 Jun 7 14:32:12 unbound 18544:2 debug: selrtt 480079 Jun 7 14:32:12 unbound 18544:2 info: sending query: sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: sending to target: <.> 8.8.8.8#53 Jun 7 14:32:12 unbound 18544:2 debug: dnssec status: not expected Jun 7 14:32:12 unbound 18544:2 debug: EDNS lookup known=1 vs=0 Jun 7 14:32:12 unbound 18544:2 debug: serviced query UDP timeout=79 msec Jun 7 14:32:12 unbound 18544:2 debug: inserted new pending reply id=28ec Jun 7 14:32:12 unbound 18544:2 debug: opened UDP if=0 port=20081 Jun 7 14:32:12 unbound 18544:2 debug: comm point start listening 23 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: iterator module exit state is module_wait_reply Jun 7 14:32:12 unbound 18544:2 info: mesh_run: end 2 recursion states (1 with reply, 0 detached), 1 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out Jun 7 14:32:12 unbound 18544:2 info: average recursion processing time 0.281238 sec Jun 7 14:32:12 unbound 18544:2 info: histogram of recursion processing times Jun 7 14:32:12 unbound 18544:2 info: [25%]=0 median[50%]=0 [75%]=0 Jun 7 14:32:12 unbound 18544:2 info: lower(secs) upper(secs) recursions Jun 7 14:32:12 unbound 18544:2 info: 0.131072 0.262144 1 Jun 7 14:32:12 unbound 18544:2 info: 0.262144 0.524288 1 Jun 7 14:32:12 unbound 18544:2 info: 0vRDCD mod1 sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: 1RDdc mod0 rep sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 debug: cache memory msg=71702 rrset=83103 infra=5722 val=72303 Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks end Jun 7 14:32:12 unbound 18544:2 debug: close of port 11451 Jun 7 14:32:12 unbound 18544:2 debug: close fd 24 Jun 7 14:32:12 unbound 18544:2 debug: answer cb Jun 7 14:32:12 unbound 18544:2 debug: Incoming reply id = 28ec Jun 7 14:32:12 unbound 18544:2 debug: Incoming reply addr = ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: lookup size is 1 entries Jun 7 14:32:12 unbound 18544:2 debug: received udp reply. Jun 7 14:32:12 unbound 18544:2 debug: udp message[133:0] 28EC819000010001000100010A7368617265706F696E7403636F6D00002B0001C00C0005000100008B5500170A7368617265706F696E74096D6963726F736F6674C017C03700060001000003D2002B036E7331046D736674036E657400066D736E687374C0377839E70000001C20000002580024EA0000000E100000290200000080000000 Jun 7 14:32:12 unbound 18544:2 debug: outnet handle udp reply Jun 7 14:32:12 unbound 18544:2 debug: measured roundtrip at 39 msec Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks start Jun 7 14:32:12 unbound 18544:2 debug: worker svcd callback for qstate 0x803a50080 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: start Jun 7 14:32:12 unbound 18544:2 debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Jun 7 14:32:12 unbound 18544:2 info: iterator operate: query sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: process_response: new external response event Jun 7 14:32:12 unbound 18544:2 info: scrub for . NS IN Jun 7 14:32:12 unbound 18544:2 info: response for sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: reply from <.> 8.8.8.8#53 Jun 7 14:32:12 unbound 18544:2 info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 1, ADDITIONAL: 0 ;; QUESTION SECTION: sharepoint.com. IN DS ;; ANSWER SECTION: sharepoint.com. 35669 IN CNAME sharepoint.microsoft.com. ;; AUTHORITY SECTION: microsoft.com. 978 IN SOA ns1.msft.net. msnhst.microsoft.com. 2017060608 7200 600 2419200 3600 ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 122 Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state QUERY RESPONSE STATE Jun 7 14:32:12 unbound 18544:2 info: query response was CNAME Jun 7 14:32:12 unbound 18544:2 info: cname msg ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 1, ADDITIONAL: 0 ;; QUESTION SECTION: sharepoint.com. IN DS ;; ANSWER SECTION: sharepoint.com. 35669 IN CNAME sharepoint.microsoft.com. ;; AUTHORITY SECTION: microsoft.com. 978 IN SOA ns1.msft.net. msnhst.microsoft.com. 2017060608 7200 600 2419200 3600 ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 122 Jun 7 14:32:12 unbound 18544:2 debug: cleared outbound list for query restart Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state INIT REQUEST STATE Jun 7 14:32:12 unbound 18544:2 info: resolving sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: request has dependency depth of 0 Jun 7 14:32:12 unbound 18544:2 debug: cache blacklisted, going to the network Jun 7 14:32:12 unbound 18544:2 debug: forwarding request Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state QUERY TARGETS STATE Jun 7 14:32:12 unbound 18544:2 info: processQueryTargets: sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Jun 7 14:32:12 unbound 18544:2 info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail) parentNS Jun 7 14:32:12 unbound 18544:2 debug: ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: attempt to get extra 3 targets Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=71 Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=113 Jun 7 14:32:12 unbound 18544:2 debug: selrtt 480071 Jun 7 14:32:12 unbound 18544:2 info: sending query: sharepoint.microsoft.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: sending to target: <.> 8.8.8.8#53 Jun 7 14:32:12 unbound 18544:2 debug: dnssec status: not expected Jun 7 14:32:12 unbound 18544:2 debug: EDNS lookup known=1 vs=0 Jun 7 14:32:12 unbound 18544:2 debug: serviced query UDP timeout=71 msec Jun 7 14:32:12 unbound 18544:2 debug: inserted new pending reply id=9051 Jun 7 14:32:12 unbound 18544:2 debug: opened UDP if=0 port=59571 Jun 7 14:32:12 unbound 18544:2 debug: comm point start listening 24 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: iterator module exit state is module_wait_reply Jun 7 14:32:12 unbound 18544:2 info: mesh_run: end 2 recursion states (1 with reply, 0 detached), 1 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out Jun 7 14:32:12 unbound 18544:2 info: average recursion processing time 0.281238 sec Jun 7 14:32:12 unbound 18544:2 info: histogram of recursion processing times Jun 7 14:32:12 unbound 18544:2 info: [25%]=0 median[50%]=0 [75%]=0 Jun 7 14:32:12 unbound 18544:2 info: lower(secs) upper(secs) recursions Jun 7 14:32:12 unbound 18544:2 info: 0.131072 0.262144 1 Jun 7 14:32:12 unbound 18544:2 info: 0.262144 0.524288 1 Jun 7 14:32:12 unbound 18544:2 info: 0vRDCD mod1 sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: 1RDdc mod0 rep sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 debug: cache memory msg=71702 rrset=83103 infra=5722 val=72303 Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks end Jun 7 14:32:12 unbound 18544:2 debug: close of port 20081 Jun 7 14:32:12 unbound 18544:2 debug: close fd 23 Jun 7 14:32:12 unbound 18544:2 debug: answer cb Jun 7 14:32:12 unbound 18544:2 debug: Incoming reply id = 9051 Jun 7 14:32:12 unbound 18544:2 debug: Incoming reply addr = ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: lookup size is 1 entries Jun 7 14:32:12 unbound 18544:2 debug: received udp reply. Jun 7 14:32:12 unbound 18544:2 debug: udp message[108:0] 9051819000010000000100010A7368617265706F696E74096D6963726F736F667403636F6D00002B0001C01700060001000006A7002B036E7331046D736674036E657400066D736E687374C0177839E70000001C20000002580024EA0000000E100000290200000080000000 Jun 7 14:32:12 unbound 18544:2 debug: outnet handle udp reply Jun 7 14:32:12 unbound 18544:2 debug: measured roundtrip at 38 msec Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks start Jun 7 14:32:12 unbound 18544:2 debug: worker svcd callback for qstate 0x803a50080 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: start Jun 7 14:32:12 unbound 18544:2 debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Jun 7 14:32:12 unbound 18544:2 info: iterator operate: query sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: iterator operate: chased to sharepoint.microsoft.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: process_response: new external response event Jun 7 14:32:12 unbound 18544:2 info: scrub for . NS IN Jun 7 14:32:12 unbound 18544:2 info: response for sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: reply from <.> 8.8.8.8#53 Jun 7 14:32:12 unbound 18544:2 info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 0, AUTHORITY: 1, ADDITIONAL: 0 ;; QUESTION SECTION: sharepoint.microsoft.com. IN DS ;; ANSWER SECTION: ;; AUTHORITY SECTION: microsoft.com. 1703 IN SOA ns1.msft.net. msnhst.microsoft.com. 2017060608 7200 600 2419200 3600 ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 97 Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state QUERY RESPONSE STATE Jun 7 14:32:12 unbound 18544:2 info: query response was nodata ANSWER Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state FINISHED RESPONSE STATE Jun 7 14:32:12 unbound 18544:2 info: finishing processing for sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: prepending 1 rrsets Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: iterator module exit state is module_finished Jun 7 14:32:12 unbound 18544:2 debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Jun 7 14:32:12 unbound 18544:2 info: validator operate: query sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: validator: nextmodule returned Jun 7 14:32:12 unbound 18544:2 debug: not validating response, is valrec(validation recursion lookup) Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: validator module exit state is module_finished Jun 7 14:32:12 unbound 18544:2 info: validator: inform_super, sub is sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: super is sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 debug: blacklist ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: blacklist ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: blacklist add ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: blacklist add ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: validator[module 0] operate: extstate:module_wait_subquery event:module_event_pass Jun 7 14:32:12 unbound 18544:2 info: validator operate: query sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 debug: val handle processing q with state VAL_FINDKEY_STATE Jun 7 14:32:12 unbound 18544:2 info: validator: FindKey sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 info: current keyname com. DNSKEY IN Jun 7 14:32:12 unbound 18544:2 info: target keyname sharepoint.com. DNSKEY IN Jun 7 14:32:12 unbound 18544:2 debug: striplab 0 Jun 7 14:32:12 unbound 18544:2 info: next keyname sharepoint.com. DNSKEY IN Jun 7 14:32:12 unbound 18544:2 debug: No DS RRset Jun 7 14:32:12 unbound 18544:2 info: generate request sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: validator module exit state is module_wait_subquery Jun 7 14:32:12 unbound 18544:2 debug: validator[module 0] operate: extstate:module_state_initial event:module_event_pass Jun 7 14:32:12 unbound 18544:2 info: validator operate: query sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: validator: pass to next module Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: validator module exit state is module_wait_module Jun 7 14:32:12 unbound 18544:2 debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Jun 7 14:32:12 unbound 18544:2 debug: process_request: new external request event Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state INIT REQUEST STATE Jun 7 14:32:12 unbound 18544:2 info: resolving sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: request has dependency depth of 0 Jun 7 14:32:12 unbound 18544:2 debug: cache blacklisted, going to the network Jun 7 14:32:12 unbound 18544:2 debug: forwarding request Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state QUERY TARGETS STATE Jun 7 14:32:12 unbound 18544:2 info: processQueryTargets: sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Jun 7 14:32:12 unbound 18544:2 info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail) parentNS Jun 7 14:32:12 unbound 18544:2 debug: ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: attempt to get extra 3 targets Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=67 Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=113 Jun 7 14:32:12 unbound 18544:2 debug: selrtt 480067 Jun 7 14:32:12 unbound 18544:2 info: sending query: sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: sending to target: <.> 8.8.8.8#53 Jun 7 14:32:12 unbound 18544:2 debug: dnssec status: not expected Jun 7 14:32:12 unbound 18544:2 debug: EDNS lookup known=1 vs=0 Jun 7 14:32:12 unbound 18544:2 debug: serviced query UDP timeout=67 msec Jun 7 14:32:12 unbound 18544:2 debug: inserted new pending reply id=d7fc Jun 7 14:32:12 unbound 18544:2 debug: opened UDP if=0 port=50822 Jun 7 14:32:12 unbound 18544:2 debug: comm point start listening 23 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: iterator module exit state is module_wait_reply Jun 7 14:32:12 unbound 18544:2 info: mesh_run: end 2 recursion states (1 with reply, 0 detached), 1 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out Jun 7 14:32:12 unbound 18544:2 info: average recursion processing time 0.281238 sec Jun 7 14:32:12 unbound 18544:2 info: histogram of recursion processing times Jun 7 14:32:12 unbound 18544:2 info: [25%]=0 median[50%]=0 [75%]=0 Jun 7 14:32:12 unbound 18544:2 info: lower(secs) upper(secs) recursions Jun 7 14:32:12 unbound 18544:2 info: 0.131072 0.262144 1 Jun 7 14:32:12 unbound 18544:2 info: 0.262144 0.524288 1 Jun 7 14:32:12 unbound 18544:2 info: 0vRDCD mod1 sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: 1RDdc mod0 rep sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 debug: cache memory msg=71702 rrset=83103 infra=5722 val=72303 Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks end Jun 7 14:32:12 unbound 18544:2 debug: close of port 59571 Jun 7 14:32:12 unbound 18544:2 debug: close fd 24 Jun 7 14:32:12 unbound 18544:2 debug: answer cb Jun 7 14:32:12 unbound 18544:2 debug: Incoming reply id = d7fc Jun 7 14:32:12 unbound 18544:2 debug: Incoming reply addr = ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: lookup size is 1 entries Jun 7 14:32:12 unbound 18544:2 debug: received udp reply. Jun 7 14:32:12 unbound 18544:2 debug: udp message[133:0] D7FC819000010001000100010A7368617265706F696E7403636F6D00002B0001C00C000500010001417500170A7368617265706F696E74096D6963726F736F6674C017C03700060001000003D2002B036E7331046D736674036E657400066D736E687374C0377839E70000001C20000002580024EA0000000E100000290200000080000000 Jun 7 14:32:12 unbound 18544:2 debug: outnet handle udp reply Jun 7 14:32:12 unbound 18544:2 debug: measured roundtrip at 39 msec Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks start Jun 7 14:32:12 unbound 18544:2 debug: worker svcd callback for qstate 0x803a50080 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: start Jun 7 14:32:12 unbound 18544:2 debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Jun 7 14:32:12 unbound 18544:2 info: iterator operate: query sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: process_response: new external response event Jun 7 14:32:12 unbound 18544:2 info: scrub for . NS IN Jun 7 14:32:12 unbound 18544:2 info: response for sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: reply from <.> 8.8.8.8#53 Jun 7 14:32:12 unbound 18544:2 info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 1, ADDITIONAL: 0 ;; QUESTION SECTION: sharepoint.com. IN DS ;; ANSWER SECTION: sharepoint.com. 82293 IN CNAME sharepoint.microsoft.com. ;; AUTHORITY SECTION: microsoft.com. 978 IN SOA ns1.msft.net. msnhst.microsoft.com. 2017060608 7200 600 2419200 3600 ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 122 Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state QUERY RESPONSE STATE Jun 7 14:32:12 unbound 18544:2 info: query response was CNAME Jun 7 14:32:12 unbound 18544:2 info: cname msg ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 1, ADDITIONAL: 0 ;; QUESTION SECTION: sharepoint.com. IN DS ;; ANSWER SECTION: sharepoint.com. 82293 IN CNAME sharepoint.microsoft.com. ;; AUTHORITY SECTION: microsoft.com. 978 IN SOA ns1.msft.net. msnhst.microsoft.com. 2017060608 7200 600 2419200 3600 ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 122 Jun 7 14:32:12 unbound 18544:2 debug: cleared outbound list for query restart Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state INIT REQUEST STATE Jun 7 14:32:12 unbound 18544:2 info: resolving sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: request has dependency depth of 0 Jun 7 14:32:12 unbound 18544:2 debug: cache blacklisted, going to the network Jun 7 14:32:12 unbound 18544:2 debug: forwarding request Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state QUERY TARGETS STATE Jun 7 14:32:12 unbound 18544:2 info: processQueryTargets: sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Jun 7 14:32:12 unbound 18544:2 info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail) parentNS Jun 7 14:32:12 unbound 18544:2 debug: ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: attempt to get extra 3 targets Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=63 Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=113 Jun 7 14:32:12 unbound 18544:2 debug: selrtt 480063 Jun 7 14:32:12 unbound 18544:2 info: sending query: sharepoint.microsoft.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: sending to target: <.> 8.8.4.4#53 Jun 7 14:32:12 unbound 18544:2 debug: dnssec status: not expected Jun 7 14:32:12 unbound 18544:2 debug: EDNS lookup known=1 vs=0 Jun 7 14:32:12 unbound 18544:2 debug: serviced query UDP timeout=113 msec Jun 7 14:32:12 unbound 18544:2 debug: inserted new pending reply id=4443 Jun 7 14:32:12 unbound 18544:2 debug: opened UDP if=0 port=14377 Jun 7 14:32:12 unbound 18544:2 debug: comm point start listening 24 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: iterator module exit state is module_wait_reply Jun 7 14:32:12 unbound 18544:2 info: mesh_run: end 2 recursion states (1 with reply, 0 detached), 1 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out Jun 7 14:32:12 unbound 18544:2 info: average recursion processing time 0.281238 sec Jun 7 14:32:12 unbound 18544:2 info: histogram of recursion processing times Jun 7 14:32:12 unbound 18544:2 info: [25%]=0 median[50%]=0 [75%]=0 Jun 7 14:32:12 unbound 18544:2 info: lower(secs) upper(secs) recursions Jun 7 14:32:12 unbound 18544:2 info: 0.131072 0.262144 1 Jun 7 14:32:12 unbound 18544:2 info: 0.262144 0.524288 1 Jun 7 14:32:12 unbound 18544:2 info: 0vRDCD mod1 sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: 1RDdc mod0 rep sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 debug: cache memory msg=71702 rrset=83103 infra=5722 val=72303 Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks end Jun 7 14:32:12 unbound 18544:2 debug: close of port 50822 Jun 7 14:32:12 unbound 18544:2 debug: close fd 23 Jun 7 14:32:12 unbound 18544:2 debug: answer cb Jun 7 14:32:12 unbound 18544:2 debug: Incoming reply id = 4443 Jun 7 14:32:12 unbound 18544:2 debug: Incoming reply addr = ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: lookup size is 1 entries Jun 7 14:32:12 unbound 18544:2 debug: received udp reply. Jun 7 14:32:12 unbound 18544:2 debug: udp message[108:0] 4443819000010000000100010A7368617265706F696E74096D6963726F736F667403636F6D00002B0001C01700060001000005EC002B036E7331046D736674036E657400066D736E687374C0177839E70000001C20000002580024EA0000000E100000290200000080000000 Jun 7 14:32:12 unbound 18544:2 debug: outnet handle udp reply Jun 7 14:32:12 unbound 18544:2 debug: measured roundtrip at 35 msec Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks start Jun 7 14:32:12 unbound 18544:2 debug: worker svcd callback for qstate 0x803a50080 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: start Jun 7 14:32:12 unbound 18544:2 debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Jun 7 14:32:12 unbound 18544:2 info: iterator operate: query sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: iterator operate: chased to sharepoint.microsoft.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: process_response: new external response event Jun 7 14:32:12 unbound 18544:2 info: scrub for . NS IN Jun 7 14:32:12 unbound 18544:2 info: response for sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: reply from <.> 8.8.4.4#53 Jun 7 14:32:12 unbound 18544:2 info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 0, AUTHORITY: 1, ADDITIONAL: 0 ;; QUESTION SECTION: sharepoint.microsoft.com. IN DS ;; ANSWER SECTION: ;; AUTHORITY SECTION: microsoft.com. 1516 IN SOA ns1.msft.net. msnhst.microsoft.com. 2017060608 7200 600 2419200 3600 ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 97 Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state QUERY RESPONSE STATE Jun 7 14:32:12 unbound 18544:2 info: query response was nodata ANSWER Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state FINISHED RESPONSE STATE Jun 7 14:32:12 unbound 18544:2 info: finishing processing for sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: prepending 1 rrsets Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: iterator module exit state is module_finished Jun 7 14:32:12 unbound 18544:2 debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Jun 7 14:32:12 unbound 18544:2 info: validator operate: query sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: validator: nextmodule returned Jun 7 14:32:12 unbound 18544:2 debug: not validating response, is valrec(validation recursion lookup) Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: validator module exit state is module_finished Jun 7 14:32:12 unbound 18544:2 info: validator: inform_super, sub is sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: super is sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 debug: blacklist ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: blacklist ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: blacklist add ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: blacklist add ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: validator[module 0] operate: extstate:module_wait_subquery event:module_event_pass Jun 7 14:32:12 unbound 18544:2 info: validator operate: query sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 debug: val handle processing q with state VAL_FINDKEY_STATE Jun 7 14:32:12 unbound 18544:2 info: validator: FindKey sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 info: current keyname com. DNSKEY IN Jun 7 14:32:12 unbound 18544:2 info: target keyname sharepoint.com. DNSKEY IN Jun 7 14:32:12 unbound 18544:2 debug: striplab 0 Jun 7 14:32:12 unbound 18544:2 info: next keyname sharepoint.com. DNSKEY IN Jun 7 14:32:12 unbound 18544:2 debug: No DS RRset Jun 7 14:32:12 unbound 18544:2 info: generate request sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: validator module exit state is module_wait_subquery Jun 7 14:32:12 unbound 18544:2 debug: validator[module 0] operate: extstate:module_state_initial event:module_event_pass Jun 7 14:32:12 unbound 18544:2 info: validator operate: query sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: validator: pass to next module Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: validator module exit state is module_wait_module Jun 7 14:32:12 unbound 18544:2 debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Jun 7 14:32:12 unbound 18544:2 debug: process_request: new external request event Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state INIT REQUEST STATE Jun 7 14:32:12 unbound 18544:2 info: resolving sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: request has dependency depth of 0 Jun 7 14:32:12 unbound 18544:2 debug: cache blacklisted, going to the network Jun 7 14:32:12 unbound 18544:2 debug: forwarding request Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state QUERY TARGETS STATE Jun 7 14:32:12 unbound 18544:2 info: processQueryTargets: sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Jun 7 14:32:12 unbound 18544:2 info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail) parentNS Jun 7 14:32:12 unbound 18544:2 debug: ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: attempt to get extra 3 targets Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=63 Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=97 Jun 7 14:32:12 unbound 18544:2 debug: selrtt 480063 Jun 7 14:32:12 unbound 18544:2 info: sending query: sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: sending to target: <.> 8.8.4.4#53 Jun 7 14:32:12 unbound 18544:2 debug: dnssec status: not expected Jun 7 14:32:12 unbound 18544:2 debug: EDNS lookup known=1 vs=0 Jun 7 14:32:12 unbound 18544:2 debug: serviced query UDP timeout=97 msec Jun 7 14:32:12 unbound 18544:2 debug: inserted new pending reply id=97c1 Jun 7 14:32:12 unbound 18544:2 debug: opened UDP if=0 port=32904 Jun 7 14:32:12 unbound 18544:2 debug: comm point start listening 23 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: iterator module exit state is module_wait_reply Jun 7 14:32:12 unbound 18544:2 info: mesh_run: end 2 recursion states (1 with reply, 0 detached), 1 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out Jun 7 14:32:12 unbound 18544:2 info: average recursion processing time 0.281238 sec Jun 7 14:32:12 unbound 18544:2 info: histogram of recursion processing times Jun 7 14:32:12 unbound 18544:2 info: [25%]=0 median[50%]=0 [75%]=0 Jun 7 14:32:12 unbound 18544:2 info: lower(secs) upper(secs) recursions Jun 7 14:32:12 unbound 18544:2 info: 0.131072 0.262144 1 Jun 7 14:32:12 unbound 18544:2 info: 0.262144 0.524288 1 Jun 7 14:32:12 unbound 18544:2 info: 0vRDCD mod1 sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: 1RDdc mod0 rep sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 debug: cache memory msg=71702 rrset=83103 infra=5722 val=72303 Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks end Jun 7 14:32:12 unbound 18544:2 debug: close of port 14377 Jun 7 14:32:12 unbound 18544:2 debug: close fd 24 Jun 7 14:32:12 unbound 18544:2 debug: answer cb Jun 7 14:32:12 unbound 18544:2 debug: Incoming reply id = 97c1 Jun 7 14:32:12 unbound 18544:2 debug: Incoming reply addr = ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: lookup size is 1 entries Jun 7 14:32:12 unbound 18544:2 debug: received udp reply. Jun 7 14:32:12 unbound 18544:2 debug: udp message[133:0] 97C1819000010001000100010A7368617265706F696E7403636F6D00002B0001C00C0005000100014B3300170A7368617265706F696E74096D6963726F736F6674C017C0370006000100000281002B036E7331046D736674036E657400066D736E687374C0377839E70000001C20000002580024EA0000000E100000290200000080000000 Jun 7 14:32:12 unbound 18544:2 debug: outnet handle udp reply Jun 7 14:32:12 unbound 18544:2 debug: measured roundtrip at 36 msec Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks start Jun 7 14:32:12 unbound 18544:2 debug: worker svcd callback for qstate 0x803a50080 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: start Jun 7 14:32:12 unbound 18544:2 debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Jun 7 14:32:12 unbound 18544:2 info: iterator operate: query sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: process_response: new external response event Jun 7 14:32:12 unbound 18544:2 info: scrub for . NS IN Jun 7 14:32:12 unbound 18544:2 info: response for sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: reply from <.> 8.8.4.4#53 Jun 7 14:32:12 unbound 18544:2 info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 1, ADDITIONAL: 0 ;; QUESTION SECTION: sharepoint.com. IN DS ;; ANSWER SECTION: sharepoint.com. 84787 IN CNAME sharepoint.microsoft.com. ;; AUTHORITY SECTION: microsoft.com. 641 IN SOA ns1.msft.net. msnhst.microsoft.com. 2017060608 7200 600 2419200 3600 ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 122 Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state QUERY RESPONSE STATE Jun 7 14:32:12 unbound 18544:2 info: query response was CNAME Jun 7 14:32:12 unbound 18544:2 info: cname msg ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 1, ADDITIONAL: 0 ;; QUESTION SECTION: sharepoint.com. IN DS ;; ANSWER SECTION: sharepoint.com. 84787 IN CNAME sharepoint.microsoft.com. ;; AUTHORITY SECTION: microsoft.com. 641 IN SOA ns1.msft.net. msnhst.microsoft.com. 2017060608 7200 600 2419200 3600 ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 122 Jun 7 14:32:12 unbound 18544:2 debug: cleared outbound list for query restart Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state INIT REQUEST STATE Jun 7 14:32:12 unbound 18544:2 info: resolving sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: request has dependency depth of 0 Jun 7 14:32:12 unbound 18544:2 debug: cache blacklisted, going to the network Jun 7 14:32:12 unbound 18544:2 debug: forwarding request Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state QUERY TARGETS STATE Jun 7 14:32:12 unbound 18544:2 info: processQueryTargets: sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Jun 7 14:32:12 unbound 18544:2 info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail) parentNS Jun 7 14:32:12 unbound 18544:2 debug: ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: attempt to get extra 3 targets Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=63 Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=85 Jun 7 14:32:12 unbound 18544:2 debug: selrtt 480063 Jun 7 14:32:12 unbound 18544:2 info: sending query: sharepoint.microsoft.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: sending to target: <.> 8.8.4.4#53 Jun 7 14:32:12 unbound 18544:2 debug: dnssec status: not expected Jun 7 14:32:12 unbound 18544:2 debug: EDNS lookup known=1 vs=0 Jun 7 14:32:12 unbound 18544:2 debug: serviced query UDP timeout=85 msec Jun 7 14:32:12 unbound 18544:2 debug: inserted new pending reply id=a853 Jun 7 14:32:12 unbound 18544:2 debug: opened UDP if=0 port=58126 Jun 7 14:32:12 unbound 18544:2 debug: comm point start listening 24 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: iterator module exit state is module_wait_reply Jun 7 14:32:12 unbound 18544:2 info: mesh_run: end 2 recursion states (1 with reply, 0 detached), 1 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out Jun 7 14:32:12 unbound 18544:2 info: average recursion processing time 0.281238 sec Jun 7 14:32:12 unbound 18544:2 info: histogram of recursion processing times Jun 7 14:32:12 unbound 18544:2 info: [25%]=0 median[50%]=0 [75%]=0 Jun 7 14:32:12 unbound 18544:2 info: lower(secs) upper(secs) recursions Jun 7 14:32:12 unbound 18544:2 info: 0.131072 0.262144 1 Jun 7 14:32:12 unbound 18544:2 info: 0.262144 0.524288 1 Jun 7 14:32:12 unbound 18544:2 info: 0vRDCD mod1 sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: 1RDdc mod0 rep sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 debug: cache memory msg=71702 rrset=83103 infra=5722 val=72303 Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks end Jun 7 14:32:12 unbound 18544:2 debug: close of port 32904 Jun 7 14:32:12 unbound 18544:2 debug: close fd 23 Jun 7 14:32:12 unbound 18544:2 debug: answer cb Jun 7 14:32:12 unbound 18544:2 debug: Incoming reply id = a853 Jun 7 14:32:12 unbound 18544:2 debug: Incoming reply addr = ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: lookup size is 1 entries Jun 7 14:32:12 unbound 18544:2 debug: received udp reply. Jun 7 14:32:12 unbound 18544:2 debug: udp message[108:0] A853819000010000000100010A7368617265706F696E74096D6963726F736F667403636F6D00002B0001C01700060001000000BB002B036E7331046D736674036E657400066D736E687374C0177839E70000001C20000002580024EA0000000E100000290200000080000000 Jun 7 14:32:12 unbound 18544:2 debug: outnet handle udp reply Jun 7 14:32:12 unbound 18544:2 debug: measured roundtrip at 35 msec Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks start Jun 7 14:32:12 unbound 18544:2 debug: worker svcd callback for qstate 0x803a50080 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: start Jun 7 14:32:12 unbound 18544:2 debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Jun 7 14:32:12 unbound 18544:2 info: iterator operate: query sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: iterator operate: chased to sharepoint.microsoft.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: process_response: new external response event Jun 7 14:32:12 unbound 18544:2 info: scrub for . NS IN Jun 7 14:32:12 unbound 18544:2 info: response for sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: reply from <.> 8.8.4.4#53 Jun 7 14:32:12 unbound 18544:2 info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 0, AUTHORITY: 1, ADDITIONAL: 0 ;; QUESTION SECTION: sharepoint.microsoft.com. IN DS ;; ANSWER SECTION: ;; AUTHORITY SECTION: microsoft.com. 187 IN SOA ns1.msft.net. msnhst.microsoft.com. 2017060608 7200 600 2419200 3600 ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 97 Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state QUERY RESPONSE STATE Jun 7 14:32:12 unbound 18544:2 info: query response was nodata ANSWER Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state FINISHED RESPONSE STATE Jun 7 14:32:12 unbound 18544:2 info: finishing processing for sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: prepending 1 rrsets Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: iterator module exit state is module_finished Jun 7 14:32:12 unbound 18544:2 debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Jun 7 14:32:12 unbound 18544:2 info: validator operate: query sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 debug: validator: nextmodule returned Jun 7 14:32:12 unbound 18544:2 debug: not validating response, is valrec(validation recursion lookup) Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: validator module exit state is module_finished Jun 7 14:32:12 unbound 18544:2 info: validator: inform_super, sub is sharepoint.com. DS IN Jun 7 14:32:12 unbound 18544:2 info: super is sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 debug: validator[module 0] operate: extstate:module_wait_subquery event:module_event_pass Jun 7 14:32:12 unbound 18544:2 info: validator operate: query sharepoint.com. A IN Jun 7 14:32:12 unbound 18544:2 debug: val handle processing q with state VAL_VALIDATE_STATE Jun 7 14:32:12 unbound 18544:2 info: Could not establish a chain of trust to keys for sharepoint.com. DNSKEY IN Jun 7 14:32:12 unbound 18544:2 debug: val handle processing q with state VAL_FINISHED_STATE Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: validator module exit state is module_finished Jun 7 14:32:12 unbound 18544:2 info: send_udp over interface: 192.168.100.1 Jun 7 14:32:12 unbound 18544:2 debug: query took 0.579096 sec Jun 7 14:32:12 unbound 18544:2 info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 3 recursion replies sent, 0 replies dropped, 0 states jostled out Jun 7 14:32:12 unbound 18544:2 info: average recursion processing time 0.380524 sec Jun 7 14:32:12 unbound 18544:2 info: histogram of recursion processing times Jun 7 14:32:12 unbound 18544:2 info: [25%]=0 median[50%]=0 [75%]=0 Jun 7 14:32:12 unbound 18544:2 info: lower(secs) upper(secs) recursions Jun 7 14:32:12 unbound 18544:2 info: 0.131072 0.262144 1 Jun 7 14:32:12 unbound 18544:2 info: 0.262144 0.524288 1 Jun 7 14:32:12 unbound 18544:2 info: 0.524288 1.000000 1 Jun 7 14:32:12 unbound 18544:2 debug: cache memory msg=71702 rrset=83103 infra=5722 val=72439 Jun 7 14:32:12 unbound 18544:2 debug: svcd callbacks end Jun 7 14:32:12 unbound 18544:2 debug: close of port 58126 Jun 7 14:32:12 unbound 18544:2 debug: close fd 24 Jun 7 14:32:12 unbound 18544:2 info: receive_udp on interface: 192.168.100.1 Jun 7 14:32:12 unbound 18544:2 debug: udp request from ip4 192.168.100.10 port 60463 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: start Jun 7 14:32:12 unbound 18544:2 debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Jun 7 14:32:12 unbound 18544:2 info: validator operate: query sharepoint.com. AAAA IN Jun 7 14:32:12 unbound 18544:2 debug: validator: pass to next module Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: validator module exit state is module_wait_module Jun 7 14:32:12 unbound 18544:2 debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Jun 7 14:32:12 unbound 18544:2 debug: process_request: new external request event Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state INIT REQUEST STATE Jun 7 14:32:12 unbound 18544:2 info: resolving sharepoint.com. AAAA IN Jun 7 14:32:12 unbound 18544:2 debug: request has dependency depth of 0 Jun 7 14:32:12 unbound 18544:2 info: msg from cache lookup ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr ; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0 ;; QUESTION SECTION: sharepoint.com. IN AAAA ;; ANSWER SECTION: sharepoint.com. 36082 IN CNAME sharepoint.microsoft.com. ;; AUTHORITY SECTION: ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 67 Jun 7 14:32:12 unbound 18544:2 debug: msg ttl is 36082, prefetch ttl 32474 Jun 7 14:32:12 unbound 18544:2 debug: returning CNAME response from cache Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state INIT REQUEST STATE Jun 7 14:32:12 unbound 18544:2 info: resolving sharepoint.com. AAAA IN Jun 7 14:32:12 unbound 18544:2 debug: request has dependency depth of 0 Jun 7 14:32:12 unbound 18544:2 debug: forwarding request Jun 7 14:32:12 unbound 18544:2 debug: iter_handle processing q with state QUERY TARGETS STATE Jun 7 14:32:12 unbound 18544:2 info: processQueryTargets: sharepoint.com. AAAA IN Jun 7 14:32:12 unbound 18544:2 debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Jun 7 14:32:12 unbound 18544:2 info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail) parentNS Jun 7 14:32:12 unbound 18544:2 debug: ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: attempt to get extra 3 targets Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=63 Jun 7 14:32:12 unbound 18544:2 debug: servselect ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:12 unbound 18544:2 debug: rtt=77 Jun 7 14:32:12 unbound 18544:2 debug: selrtt 63 Jun 7 14:32:12 unbound 18544:2 info: sending query: sharepoint.microsoft.com. AAAA IN Jun 7 14:32:12 unbound 18544:2 debug: sending to target: <.> 8.8.4.4#53 Jun 7 14:32:12 unbound 18544:2 debug: dnssec status: not expected Jun 7 14:32:12 unbound 18544:2 debug: EDNS lookup known=1 vs=0 Jun 7 14:32:12 unbound 18544:2 debug: serviced query UDP timeout=77 msec Jun 7 14:32:12 unbound 18544:2 debug: inserted new pending reply id=ed1b Jun 7 14:32:12 unbound 18544:2 debug: opened UDP if=0 port=29617 Jun 7 14:32:12 unbound 18544:2 debug: comm point start listening 23 Jun 7 14:32:12 unbound 18544:2 debug: mesh_run: iterator module exit state is module_wait_reply Jun 7 14:32:12 unbound 18544:2 info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 3 recursion replies sent, 0 replies dropped, 0 states jostled out Jun 7 14:32:12 unbound 18544:2 info: average recursion processing time 0.380524 sec Jun 7 14:32:12 unbound 18544:2 info: histogram of recursion processing times Jun 7 14:32:12 unbound 18544:2 info: [25%]=0 median[50%]=0 [75%]=0 Jun 7 14:32:12 unbound 18544:2 info: lower(secs) upper(secs) recursions Jun 7 14:32:12 unbound 18544:2 info: 0.131072 0.262144 1 Jun 7 14:32:12 unbound 18544:2 info: 0.262144 0.524288 1 Jun 7 14:32:12 unbound 18544:2 info: 0.524288 1.000000 1 Jun 7 14:32:12 unbound 18544:2 info: 0RDd mod1 rep sharepoint.com. AAAA IN Jun 7 14:32:12 unbound 18544:2 debug: cache memory msg=71702 rrset=83103 infra=5722 val=72439 Jun 7 14:32:13 unbound 18544:2 debug: answer cb Jun 7 14:32:13 unbound 18544:2 debug: Incoming reply id = ed1b Jun 7 14:32:13 unbound 18544:2 debug: Incoming reply addr = ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:13 unbound 18544:2 debug: lookup size is 1 entries Jun 7 14:32:13 unbound 18544:2 debug: received udp reply. Jun 7 14:32:13 unbound 18544:2 debug: udp message[108:0] ED1B818000010000000100010A7368617265706F696E74096D6963726F736F667403636F6D00001C0001C01700060001000003B5002B036E7331046D736674036E657400066D736E687374C0177839E70000001C20000002580024EA0000000E100000290200000080000000 Jun 7 14:32:13 unbound 18544:2 debug: outnet handle udp reply Jun 7 14:32:13 unbound 18544:2 debug: measured roundtrip at 46 msec Jun 7 14:32:13 unbound 18544:2 debug: svcd callbacks start Jun 7 14:32:13 unbound 18544:2 debug: worker svcd callback for qstate 0x803a54080 Jun 7 14:32:13 unbound 18544:2 debug: mesh_run: start Jun 7 14:32:13 unbound 18544:2 debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Jun 7 14:32:13 unbound 18544:2 info: iterator operate: query sharepoint.com. AAAA IN Jun 7 14:32:13 unbound 18544:2 info: iterator operate: chased to sharepoint.microsoft.com. AAAA IN Jun 7 14:32:13 unbound 18544:2 debug: process_response: new external response event Jun 7 14:32:13 unbound 18544:2 info: scrub for . NS IN Jun 7 14:32:13 unbound 18544:2 info: response for sharepoint.com. AAAA IN Jun 7 14:32:13 unbound 18544:2 info: reply from <.> 8.8.4.4#53 Jun 7 14:32:13 unbound 18544:2 info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 0, AUTHORITY: 1, ADDITIONAL: 0 ;; QUESTION SECTION: sharepoint.microsoft.com. IN AAAA ;; ANSWER SECTION: ;; AUTHORITY SECTION: microsoft.com. 949 IN SOA ns1.msft.net. msnhst.microsoft.com. 2017060608 7200 600 2419200 3600 ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 97 Jun 7 14:32:13 unbound 18544:2 debug: iter_handle processing q with state QUERY RESPONSE STATE Jun 7 14:32:13 unbound 18544:2 info: query response was nodata ANSWER Jun 7 14:32:13 unbound 18544:2 debug: iter_handle processing q with state FINISHED RESPONSE STATE Jun 7 14:32:13 unbound 18544:2 info: finishing processing for sharepoint.com. AAAA IN Jun 7 14:32:13 unbound 18544:2 debug: prepending 1 rrsets Jun 7 14:32:13 unbound 18544:2 debug: mesh_run: iterator module exit state is module_finished Jun 7 14:32:13 unbound 18544:2 debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Jun 7 14:32:13 unbound 18544:2 info: validator operate: query sharepoint.com. AAAA IN Jun 7 14:32:13 unbound 18544:2 debug: validator: nextmodule returned Jun 7 14:32:13 unbound 18544:2 debug: val handle processing q with state VAL_INIT_STATE Jun 7 14:32:13 unbound 18544:2 debug: validator classification cname Jun 7 14:32:13 unbound 18544:2 info: no signer, using sharepoint.com. TYPE0 CLASS0 Jun 7 14:32:13 unbound 18544:2 info: chased extract ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0 ;; QUESTION SECTION: sharepoint.com. IN AAAA ;; ANSWER SECTION: sharepoint.com. 36081 IN CNAME sharepoint.microsoft.com. ;; AUTHORITY SECTION: ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 67 Jun 7 14:32:13 unbound 18544:2 debug: val handle processing q with state VAL_FINISHED_STATE Jun 7 14:32:13 unbound 18544:2 debug: mesh_run: validator module exit state is module_finished Jun 7 14:32:13 unbound 18544:2 info: send_udp over interface: 192.168.100.1 Jun 7 14:32:13 unbound 18544:2 debug: query took 0.045997 sec Jun 7 14:32:13 unbound 18544:2 info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 4 recursion replies sent, 0 replies dropped, 0 states jostled out Jun 7 14:32:13 unbound 18544:2 info: average recursion processing time 0.296892 sec Jun 7 14:32:13 unbound 18544:2 info: histogram of recursion processing times Jun 7 14:32:13 unbound 18544:2 info: [25%]=0.065536 median[50%]=0.262144 [75%]=0.524288 Jun 7 14:32:13 unbound 18544:2 info: lower(secs) upper(secs) recursions Jun 7 14:32:13 unbound 18544:2 info: 0.032768 0.065536 1 Jun 7 14:32:13 unbound 18544:2 info: 0.131072 0.262144 1 Jun 7 14:32:13 unbound 18544:2 info: 0.262144 0.524288 1 Jun 7 14:32:13 unbound 18544:2 info: 0.524288 1.000000 1 Jun 7 14:32:13 unbound 18544:2 debug: cache memory msg=72136 rrset=83103 infra=5722 val=72439 Jun 7 14:32:13 unbound 18544:2 debug: svcd callbacks end Jun 7 14:32:13 unbound 18544:2 debug: close of port 29617 Jun 7 14:32:13 unbound 18544:2 debug: close fd 23 Jun 7 14:32:13 unbound 18544:1 info: receive_udp on interface: 192.168.100.1 Jun 7 14:32:13 unbound 18544:1 info: send_udp over interface: 192.168.100.1 Jun 7 14:32:13 unbound 18544:1 info: receive_udp on interface: 192.168.100.1 Jun 7 14:32:13 unbound 18544:1 info: send_udp over interface: 192.168.100.1 Jun 7 14:32:13 unbound 18544:1 info: receive_udp on interface: 192.168.100.1 Jun 7 14:32:13 unbound 18544:1 debug: udp request from ip4 192.168.100.10 port 54946 (len 16) Jun 7 14:32:13 unbound 18544:1 debug: mesh_run: start Jun 7 14:32:13 unbound 18544:1 debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Jun 7 14:32:13 unbound 18544:1 info: validator operate: query olli-my.sharepoint.com. A IN Jun 7 14:32:13 unbound 18544:1 debug: validator: pass to next module Jun 7 14:32:13 unbound 18544:1 debug: mesh_run: validator module exit state is module_wait_module Jun 7 14:32:13 unbound 18544:1 debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Jun 7 14:32:13 unbound 18544:1 debug: process_request: new external request event Jun 7 14:32:13 unbound 18544:1 debug: iter_handle processing q with state INIT REQUEST STATE Jun 7 14:32:13 unbound 18544:1 info: resolving olli-my.sharepoint.com. A IN Jun 7 14:32:13 unbound 18544:1 debug: request has dependency depth of 0 Jun 7 14:32:13 unbound 18544:1 debug: forwarding request Jun 7 14:32:13 unbound 18544:1 debug: iter_handle processing q with state QUERY TARGETS STATE Jun 7 14:32:13 unbound 18544:1 info: processQueryTargets: olli-my.sharepoint.com. A IN Jun 7 14:32:13 unbound 18544:1 debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Jun 7 14:32:13 unbound 18544:1 info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail) parentNS Jun 7 14:32:13 unbound 18544:1 debug: ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:13 unbound 18544:1 debug: ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:13 unbound 18544:1 debug: attempt to get extra 3 targets Jun 7 14:32:13 unbound 18544:1 debug: servselect ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:13 unbound 18544:1 debug: rtt=63 Jun 7 14:32:13 unbound 18544:1 debug: servselect ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:13 unbound 18544:1 debug: rtt=78 Jun 7 14:32:13 unbound 18544:1 debug: selrtt 63 Jun 7 14:32:13 unbound 18544:1 info: sending query: olli-my.sharepoint.com. A IN Jun 7 14:32:13 unbound 18544:1 debug: sending to target: <.> 8.8.4.4#53 Jun 7 14:32:13 unbound 18544:1 debug: dnssec status: not expected Jun 7 14:32:13 unbound 18544:1 debug: EDNS lookup known=1 vs=0 Jun 7 14:32:13 unbound 18544:1 debug: serviced query UDP timeout=78 msec Jun 7 14:32:13 unbound 18544:1 debug: inserted new pending reply id=d8ec Jun 7 14:32:13 unbound 18544:1 debug: opened UDP if=0 port=55853 Jun 7 14:32:13 unbound 18544:1 debug: comm point start listening 23 Jun 7 14:32:13 unbound 18544:1 debug: mesh_run: iterator module exit state is module_wait_reply Jun 7 14:32:13 unbound 18544:1 info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 1 recursion replies sent, 0 replies dropped, 0 states jostled out Jun 7 14:32:13 unbound 18544:1 info: average recursion processing time 0.556247 sec Jun 7 14:32:13 unbound 18544:1 info: histogram of recursion processing times Jun 7 14:32:13 unbound 18544:1 info: [25%]=0 median[50%]=0 [75%]=0 Jun 7 14:32:13 unbound 18544:1 info: lower(secs) upper(secs) recursions Jun 7 14:32:13 unbound 18544:1 info: 0.524288 1.000000 1 Jun 7 14:32:13 unbound 18544:1 info: 0RDd mod1 rep olli-my.sharepoint.com. A IN Jun 7 14:32:13 unbound 18544:1 debug: cache memory msg=72136 rrset=83103 infra=5722 val=72439 Jun 7 14:32:13 unbound 18544:1 debug: timeout udp Jun 7 14:32:13 unbound 18544:1 debug: try edns1xx0 <olli-my.sharepoint.com.>8.8.4.4#53 Jun 7 14:32:13 unbound 18544:1 debug: EDNS lookup known=1 vs=0 Jun 7 14:32:13 unbound 18544:1 debug: serviced query UDP timeout=78 msec Jun 7 14:32:13 unbound 18544:1 debug: inserted new pending reply id=46ce Jun 7 14:32:13 unbound 18544:1 debug: opened UDP if=0 port=22249 Jun 7 14:32:13 unbound 18544:1 debug: comm point start listening 24 Jun 7 14:32:13 unbound 18544:1 debug: close of port 55853 Jun 7 14:32:13 unbound 18544:1 debug: close fd 23 Jun 7 14:32:13 unbound 18544:1 info: receive_udp on interface: 192.168.100.1 Jun 7 14:32:13 unbound 18544:1 debug: udp request from ip4 192.168.100.10 port 54946 (len 16) Jun 7 14:32:13 unbound 18544:1 debug: cache memory msg=72136 rrset=83103 infra=5722 val=72439 Jun 7 14:32:13 unbound 18544:1 debug: timeout udp Jun 7 14:32:13 unbound 18544:1 debug: svcd callbacks start Jun 7 14:32:13 unbound 18544:1 debug: worker svcd callback for qstate 0x802654080 Jun 7 14:32:13 unbound 18544:1 debug: mesh_run: start Jun 7 14:32:13 unbound 18544:1 debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply Jun 7 14:32:13 unbound 18544:1 info: iterator operate: query olli-my.sharepoint.com. A IN Jun 7 14:32:13 unbound 18544:1 debug: process_response: new external response event Jun 7 14:32:13 unbound 18544:1 debug: iter_handle processing q with state QUERY RESPONSE STATE Jun 7 14:32:13 unbound 18544:1 debug: query response was timeout Jun 7 14:32:13 unbound 18544:1 debug: iter_handle processing q with state QUERY TARGETS STATE Jun 7 14:32:13 unbound 18544:1 info: processQueryTargets: olli-my.sharepoint.com. A IN Jun 7 14:32:13 unbound 18544:1 debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 1 Jun 7 14:32:13 unbound 18544:1 info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (2 result, 0 avail) parentNS Jun 7 14:32:13 unbound 18544:1 debug: ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:13 unbound 18544:1 debug: ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:13 unbound 18544:1 debug: attempt to get extra 3 targets Jun 7 14:32:13 unbound 18544:1 debug: servselect ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:13 unbound 18544:1 debug: rtt=156 Jun 7 14:32:13 unbound 18544:1 debug: servselect ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:13 unbound 18544:1 debug: rtt=63 Jun 7 14:32:13 unbound 18544:1 debug: selrtt 63 Jun 7 14:32:13 unbound 18544:1 info: sending query: olli-my.sharepoint.com. A IN Jun 7 14:32:13 unbound 18544:1 debug: sending to target: <.> 8.8.4.4#53 Jun 7 14:32:13 unbound 18544:1 debug: dnssec status: not expected Jun 7 14:32:13 unbound 18544:1 debug: EDNS lookup known=1 vs=0 Jun 7 14:32:13 unbound 18544:1 debug: serviced query UDP timeout=156 msec Jun 7 14:32:13 unbound 18544:1 debug: inserted new pending reply id=4384 Jun 7 14:32:13 unbound 18544:1 debug: opened UDP if=0 port=24174 Jun 7 14:32:13 unbound 18544:1 debug: comm point start listening 23 Jun 7 14:32:13 unbound 18544:1 debug: mesh_run: iterator module exit state is module_wait_reply Jun 7 14:32:13 unbound 18544:1 info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 2 waiting replies, 1 recursion replies sent, 0 replies dropped, 0 states jostled out Jun 7 14:32:13 unbound 18544:1 info: average recursion processing time 0.556247 sec Jun 7 14:32:13 unbound 18544:1 info: histogram of recursion processing times Jun 7 14:32:13 unbound 18544:1 info: [25%]=0 median[50%]=0 [75%]=0 Jun 7 14:32:13 unbound 18544:1 info: lower(secs) upper(secs) recursions Jun 7 14:32:13 unbound 18544:1 info: 0.524288 1.000000 1 Jun 7 14:32:13 unbound 18544:1 info: 0RDd mod1 rep olli-my.sharepoint.com. A IN Jun 7 14:32:13 unbound 18544:1 debug: cache memory msg=72136 rrset=83103 infra=5722 val=72439 Jun 7 14:32:13 unbound 18544:1 debug: svcd callbacks end Jun 7 14:32:13 unbound 18544:1 debug: close of port 22249 Jun 7 14:32:13 unbound 18544:1 debug: close fd 24 Jun 7 14:32:14 unbound 18544:1 debug: answer cb Jun 7 14:32:14 unbound 18544:1 debug: Incoming reply id = 4384 Jun 7 14:32:14 unbound 18544:1 debug: Incoming reply addr = ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:14 unbound 18544:1 debug: lookup size is 1 entries Jun 7 14:32:14 unbound 18544:1 debug: received udp reply. Jun 7 14:32:14 unbound 18544:1 debug: udp message[305:0] 438481900001000600000001076F6C6C692D6D790A7368617265706F696E7403636F6D0000010001C00C000500010000012B0007046F6C6C69C014C0340005000100000E0F00371570726F646E657433392D3132656467656230303033107368617265706F696E746F6E6C696E6503636F6D06616B61646E73036E657400C047000500010000001D00441170726F646E657433392D31326230303033107368617265706F696E746F6E6C696E6503636F6D06616B61646E73036E657406622D3030303108622D6D7365646765C079C08A000500010000004800141170726F646E657433392D31326230303033C05DC0DA000500010000001D001C1970726F646E Jun 7 14:32:14 unbound 18544:1 debug: udp message[305:256] 657433392D313273656C6563746F726230303033C05DC0FA000100010000001D00046892B0240000290200000080000000 Jun 7 14:32:14 unbound 18544:1 debug: outnet handle udp reply Jun 7 14:32:14 unbound 18544:1 debug: measured roundtrip at 103 msec Jun 7 14:32:14 unbound 18544:1 debug: svcd callbacks start Jun 7 14:32:14 unbound 18544:1 debug: worker svcd callback for qstate 0x802654080 Jun 7 14:32:14 unbound 18544:1 debug: mesh_run: start Jun 7 14:32:14 unbound 18544:1 debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Jun 7 14:32:14 unbound 18544:1 info: iterator operate: query olli-my.sharepoint.com. A IN Jun 7 14:32:14 unbound 18544:1 debug: process_response: new external response event Jun 7 14:32:14 unbound 18544:1 info: scrub for . NS IN Jun 7 14:32:14 unbound 18544:1 info: sanitize: removing extraneous answer RRset: olli.sharepoint.com. CNAME IN Jun 7 14:32:14 unbound 18544:1 info: sanitize: removing extraneous answer RRset: prodnet39-12edgeb0003.sharepointonline.com.akadns.net. CNAME IN Jun 7 14:32:14 unbound 18544:1 info: sanitize: removing extraneous answer RRset: prodnet39-12b0003.sharepointonline.com.akadns.net.b-0001.b-msedge.net. CNAME IN Jun 7 14:32:14 unbound 18544:1 info: sanitize: removing extraneous answer RRset: prodnet39-12b0003.sharepointonline.com.akadns.net. CNAME IN Jun 7 14:32:14 unbound 18544:1 info: sanitize: removing extraneous answer RRset: prodnet39-12selectorb0003.sharepointonline.com.akadns.net. A IN Jun 7 14:32:14 unbound 18544:1 info: response for olli-my.sharepoint.com. A IN Jun 7 14:32:14 unbound 18544:1 info: reply from <.> 8.8.4.4#53 Jun 7 14:32:14 unbound 18544:1 info: incoming scrubbed packet: ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0 ;; QUESTION SECTION: olli-my.sharepoint.com. IN A ;; ANSWER SECTION: olli-my.sharepoint.com. 299 IN CNAME olli.sharepoint.com. ;; AUTHORITY SECTION: ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 59 Jun 7 14:32:14 unbound 18544:1 debug: iter_handle processing q with state QUERY RESPONSE STATE Jun 7 14:32:14 unbound 18544:1 info: query response was CNAME Jun 7 14:32:14 unbound 18544:1 info: cname msg ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 0 ;; flags: qr rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0 ;; QUESTION SECTION: olli-my.sharepoint.com. IN A ;; ANSWER SECTION: olli-my.sharepoint.com. 299 IN CNAME olli.sharepoint.com. ;; AUTHORITY SECTION: ;; ADDITIONAL SECTION: ;; MSG SIZE rcvd: 59 Jun 7 14:32:14 unbound 18544:1 debug: cleared outbound list for query restart Jun 7 14:32:14 unbound 18544:1 debug: iter_handle processing q with state INIT REQUEST STATE Jun 7 14:32:14 unbound 18544:1 info: resolving olli-my.sharepoint.com. A IN Jun 7 14:32:14 unbound 18544:1 debug: request has dependency depth of 0 Jun 7 14:32:14 unbound 18544:1 debug: forwarding request Jun 7 14:32:14 unbound 18544:1 debug: iter_handle processing q with state QUERY TARGETS STATE Jun 7 14:32:14 unbound 18544:1 info: processQueryTargets: olli-my.sharepoint.com. A IN Jun 7 14:32:14 unbound 18544:1 debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0 Jun 7 14:32:14 unbound 18544:1 info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail) parentNS Jun 7 14:32:14 unbound 18544:1 debug: ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:14 unbound 18544:1 debug: ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:14 unbound 18544:1 debug: attempt to get extra 3 targets Jun 7 14:32:14 unbound 18544:1 debug: servselect ip4 8.8.8.8 port 53 (len 16) Jun 7 14:32:14 unbound 18544:1 debug: rtt=63 Jun 7 14:32:14 unbound 18544:1 debug: servselect ip4 8.8.4.4 port 53 (len 16) Jun 7 14:32:14 unbound 18544:1 debug: rtt=138 Jun 7 14:32:14 unbound 18544:1 debug: selrtt 63 Jun 7 14:32:14 unbound 18544:1 info: sending query: olli.sharepoint.com. A IN Jun 7 14:32:14 unbound 18544:1 debug: sending to target: <.> 8.8.8.8#53 Jun 7 14:32:14 unbound 18544:1 debug: dnssec status: not expected Jun 7 14:32:14 unbound 18544:1 debug: EDNS lookup known=1 vs=0 Jun 7 14:32:14 unbound 18544:1 debug: serviced query UDP timeout=63 msec Jun 7 14:32:14 unbound 18544:1 debug: inserted new pending reply id=d614 Jun 7 14:32:14 unbound 18544:1 debug: opened UDP if=0 port=60184 Jun 7 14:32:14 unbound 18544:1 debug: comm point start listening 24 Jun 7 14:32:14 unbound 18544:1 debug: mesh_run: iterator module exit state is module_wait_reply Jun 7 14:32:14 unbound 18544:1 info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 2 waiting replies, 1 recursion replies sent, 0 replies dropped, 0 states jostled out Jun 7 14:32:14 unbound 18544:1 info: average recursion processing time 0.556247 sec Jun 7 14:32:14 unbound 18544:1 info: histogram of recursion processing times Jun 7 14:32:14 unbound 18544:1 info: [25%]=0 median[50%]=0 [75%]=0 Jun 7 14:32:14 unbound 18544:1 info: lower(secs) upper(secs) recursions Jun 7 14:32:14 unbound 18544:1 info: 0.524288 1.000000 1 Jun 7 14:32:14 unbound 18544:1 info: 0RDd mod1 rep olli-my.sharepoint.com. A IN Jun 7 14:32:14 unbound 18544:1 debug: cache memory msg=72136 rrset=83318 infra=5722 val=72439 Jun 7 14:32:14 unbound 18544:1 debug: svcd callbacks end Jun 7 14:32:14 unbound 18544:1 debug: close of port 24174 Jun 7 14:32:14 unbound 18544:1 debug: close fd 23 Jun 7 14:32:14 unbound 18544:1 debug: answer cb Jun 7 14:32:14 unbound 18544:1 debug: Incoming reply id = d614 Jun 7 14:32:14 unbound 18544:1 debug: Incoming reply addr = ip4 8.8.8.8 port 53 (len 16)</olli-my.sharepoint.com.>
-
Unbound scheint sehr gesprächig zu sein.
Die Ausgabe in einen Code-Tag zu packen hätte Zeilenumbrüche verhindert und die Sache etwas lesbarer gemacht. ???In dem Log ist mir aufgefallen:
-
Deine Uhr oder die des Forum-Servers gehen falsch
-
debug: dnssec status: not expected
-
debug: blacklist add ip4 8.8.4.4 port 53 (len 16)
-
debug: blacklist add ip4 8.8.8.8 port 53 (len 16)
Mit unbound bin ich auch nicht gerade auf du und du, aber ich denke eine Änderung der Einstellung einer dieser beiden Optionen könnten das Problem beseitigen:
DNSSEC
DNS Query ForwardingWobei, wenn du das Forwarding abschaltest und damit der Localhost abgefragt wird, macht DNSSEC auch nicht viel Sinn.
-
-
Habe nun das code-Tag benutzt. :)
Vielen Dank für Deine Tipps! Ich habe nun DNSSEC abgeschaltet, und es funktioniert. Die Alternative (nur Abschalten des DNS Query Forwardings) hat testweise ebenfalls geholfen.
Dankeschön! :)