Trying to find out why my unbound will not resolve www.startpuntgeldzaken.nl

Gerben_Wierda · May 5, 2021, 5:03pm

My unbound 1.12.0 will not resolve www.startpuntgeldzaken.nl but it does resolve most other domains without a problem

May 05 16:54:50 unbound-default[40069:0] info: resolving www.startpuntgeldzaken.nl. A IN
May 05 16:54:50 unbound-default[40069:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 16:54:50 unbound-default[40069:0] info: sending query: www.startpuntgeldzaken.nl. A IN
May 05 16:54:50 unbound-default[40069:0] debug: sending to target: <.> 9.9.9.9#53
May 05 16:54:50 unbound-default[40069:0] debug: cache memory msg=297432 rrset=298522 infra=30866 val=296000
May 05 16:54:53 unbound-default[40069:0] debug: tcp error for address 9.9.9.9 port 53
May 05 16:54:53 unbound-default[40069:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
May 05 16:54:53 unbound-default[40069:0] info: iterator operate: query www.startpuntgeldzaken.nl. A IN
May 05 16:54:53 unbound-default[40069:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 16:54:53 unbound-default[40069:0] info: sending query: www.startpuntgeldzaken.nl. A IN
May 05 16:54:53 unbound-default[40069:0] debug: sending to target: <.> 149.112.112.112#53
May 05 16:54:53 unbound-default[40069:0] debug: cache memory msg=297432 rrset=298522 infra=30866 val=296000
May 05 16:54:55 unbound-default[40069:0] info: 192.168.2.66 www.startpuntgeldzaken.nl. A IN
May 05 16:54:55 unbound-default[40069:0] debug: cache memory msg=297432 rrset=298522 infra=30866 val=296000

The problem seems to be tcp error, but I have no clue what causes that error. I could use some help in hunting this down.

Note, asking the forwarder directly resolves without problem. So it is the communication between my unbound and the other resolver.

Gerben Wierda (LinkedIn)
R&A Enterprise Architecture (main site)
Book: Chess and the Art of Enterprise Architecture
Book: Mastering ArchiMate

Gerben_Wierda · May 5, 2021, 6:50pm

I have tested additionally on a separate test machine with unbound 1.13.1 with logging set to 4

Same problem. I also noticed there are TCP errors, but I have do-tcp set to no.

May 05 18:30:39 unbound-default[1267:0] info: 0.016384 0.032768 1
May 05 18:30:39 unbound-default[1267:0] info: 0.032768 0.065536 1
May 05 18:30:39 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30425 val=296000
May 05 18:30:39 unbound-default[1267:0] debug: svcd callbacks end
May 05 18:30:39 unbound-default[1267:0] debug: close of port 29533
May 05 18:30:39 unbound-default[1267:0] debug: close fd 10
May 05 18:30:47 unbound-default[1267:0] info: 192.168.2.32 trace.svc.ui.com. A IN
May 05 18:30:47 unbound-default[1267:0] debug: using localzone . transparent
May 05 18:30:47 unbound-default[1267:0] info: 192.168.2.32 trace.svc.ui.com. AAAA IN
May 05 18:30:47 unbound-default[1267:0] debug: using localzone . transparent
May 05 18:31:20 unbound-default[1267:0] info: 192.168.2.86 www.startpuntgeldzaken.nl. A IN
May 05 18:31:20 unbound-default[1267:0] debug: using localzone . transparent
May 05 18:31:20 unbound-default[1267:0] debug: mesh_run: start
May 05 18:31:20 unbound-default[1267:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new
May 05 18:31:20 unbound-default[1267:0] info: validator operate: query www.startpuntgeldzaken.nl. A IN
May 05 18:31:20 unbound-default[1267:0] debug: validator: pass to next module
May 05 18:31:20 unbound-default[1267:0] debug: mesh_run: validator module exit state is module_wait_module
May 05 18:31:20 unbound-default[1267:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass
May 05 18:31:20 unbound-default[1267:0] debug: process_request: new external request event
May 05 18:31:20 unbound-default[1267:0] debug: iter_handle processing q with state INIT REQUEST STATE
May 05 18:31:20 unbound-default[1267:0] info: resolving www.startpuntgeldzaken.nl. A IN
May 05 18:31:20 unbound-default[1267:0] debug: request has dependency depth of 0
May 05 18:31:20 unbound-default[1267:0] debug: forwarding request
May 05 18:31:20 unbound-default[1267:0] debug: iter_handle processing q with state QUERY TARGETS STATE
May 05 18:31:20 unbound-default[1267:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 18:31:20 unbound-default[1267:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 0
May 05 18:31:20 unbound-default[1267:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 2 avail) parentNS
May 05 18:31:20 unbound-default[1267:0] debug: ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:20 unbound-default[1267:0] debug: ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:20 unbound-default[1267:0] debug: attempt to get extra 3 targets
May 05 18:31:20 unbound-default[1267:0] debug: servselect ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:20 unbound-default[1267:0] debug: rtt=266
May 05 18:31:20 unbound-default[1267:0] debug: selrtt 266
May 05 18:31:20 unbound-default[1267:0] info: sending query: www.startpuntgeldzaken.nl. A IN
May 05 18:31:20 unbound-default[1267:0] debug: sending to target: <.> 9.9.9.9#53
May 05 18:31:20 unbound-default[1267:0] debug: dnssec status: not expected
May 05 18:31:20 unbound-default[1267:0] debug: EDNS lookup known=1 vs=0
May 05 18:31:20 unbound-default[1267:0] debug: serviced query UDP timeout=266 msec
May 05 18:31:20 unbound-default[1267:0] debug: inserted new pending reply id=f9a4
May 05 18:31:20 unbound-default[1267:0] debug: opened UDP if=0 port=8345
May 05 18:31:20 unbound-default[1267:0] debug: comm point start listening 9 (-1 msec)
May 05 18:31:20 unbound-default[1267:0] debug: mesh_run: iterator module exit state is module_wait_reply
May 05 18:31:20 unbound-default[1267:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
May 05 18:31:20 unbound-default[1267:0] info: average recursion processing time 0.029573 sec
May 05 18:31:20 unbound-default[1267:0] info: histogram of recursion processing times
May 05 18:31:20 unbound-default[1267:0] info: [25%]=0 median[50%]=0 [75%]=0
May 05 18:31:20 unbound-default[1267:0] info: lower(secs) upper(secs) recursions
May 05 18:31:20 unbound-default[1267:0] info: 0.016384 0.032768 1
May 05 18:31:20 unbound-default[1267:0] info: 0.032768 0.065536 1
May 05 18:31:20 unbound-default[1267:0] info: 0RDd mod1 rep www.startpuntgeldzaken.nl. A IN
May 05 18:31:20 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30425 val=296000
May 05 18:31:20 unbound-default[1267:0] debug: answer cb
May 05 18:31:20 unbound-default[1267:0] debug: Incoming reply id = f9a4
May 05 18:31:20 unbound-default[1267:0] debug: Incoming reply addr = ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:20 unbound-default[1267:0] debug: lookup size is 1 entries
May 05 18:31:20 unbound-default[1267:0] debug: received udp reply.
May 05 18:31:20 unbound-default[1267:0] debug: udp message[974:0] F9A483A000010007000000010377777712737461727470756E7467656C647A616B656E026E6C0000010001C00C000500010000003C0018056E696275640A7472756570656F706C6505737061636500C00C002E00010000003C00A9000507020000003C609C6C006080BC80706412737461727470756E7467656C647A616B656E026E6C009220FA364B3D0C7EB0B2DF564EB8F5F9B32334C39EC2CB54EE9EADA58600CEA226EF0AE897B51597065DFA773C8A07346996C91A38A903CF7D5E7D94323E2C4EBEBB66A8E1F6198B38F3373C90CF30D252814B4ABBC6D5603E1518DF9C90F88F293236EDC189EC6BB82B01AF2A95B855D95C2BE84643508F49E46697
May 05 18:31:20 unbound-default[1267:0] debug: udp message[974:256] 77C0A8BDC00C002E00010000003C0129000508020000003C609C6C006080BC80F14B12737461727470756E7467656C647A616B656E026E6C0064C40C418346200F0BFFC403EF28F9FC5EE97F0EB3870437410B8D6B4AB1E1EE54AF73DF47751E5CF0F9B0040A095F44AC0B5CCD59F3D988D638C2563E52AC4EC60A50CC65991DF41986536A0FCF3DEBDE725B6061ED70CDEF6CEA694F94889291088FBA600CFBC3DC77DF5E24E0101494DF409DCA35BC05BB17328F2DDDB6363A4CE4F5AB2E1F653C0DFD9092B59EB5489C73691897B7D05B16C124A8F6940662FC66034C012D63ADDA484081CBC1EC27602D2988BF4B8C17628046F3680D4309652132014736
May 05 18:31:20 unbound-default[1267:0] debug: udp message[974:512] 16C01EA7AACA89D31A257172944E98B382416BA3C17C4B1DE3EFA28CCAF71610E4D7A1F98DF9DE1F828097D54BA133EDF748B63B85B198E331C037000500010000012C000E0B74702D6E696275642D3031C03DC037002E00010000012C00A4000507030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500A19B70EDA2BFD27C98CD4239E6386617570CDF6CF1EC15E7053F97420A8B0973C22E25025315B504D482ABAFAFA90E6127C680A33AB3ECAD6AE8B51608E7E1B3FDE7BE4D24E6411C21EE99B41C9884FA4AEA88F874D0B18CDF3F77CFF96D50C27000FF23CF905D6CF23A9538F9C0269C6A8635100D0F93120CB8A7BFF2
May 05 18:31:20 unbound-default[1267:0] debug: udp message[974:768] 73730CC245000100010000012C0004541663B0C245002E00010000012C00A4000107030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500539B832E5A40E412A9B67DC7CB3E3353210CB5A453B63E22FFAC9AAF4648F90079275886E92BAE6989435140E18FC822F37287654A6C4651DAF720B096C3254E66DC282506001EFC0E7351AE5B3F1F9612FB0ACD564D181641C8162E1A25F66EC686069F670677F90A9F34AC2879CF6D7B800D16B8A9AA245AE9BA9A2BD8526E00002904D0000080000000
May 05 18:31:20 unbound-default[1267:0] debug: outnet handle udp reply
May 05 18:31:20 unbound-default[1267:0] debug: measured roundtrip at 45 msec
May 05 18:31:20 unbound-default[1267:0] debug: initiate TCP query EDNS
May 05 18:31:20 unbound-default[1267:0] debug: close of port 8345
May 05 18:31:20 unbound-default[1267:0] debug: close fd 9
May 05 18:31:23 unbound-default[1267:0] debug: tcp error for address ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:23 unbound-default[1267:0] debug: svcd callbacks start
May 05 18:31:23 unbound-default[1267:0] debug: worker svcd callback for qstate 0x7fde48992690
May 05 18:31:23 unbound-default[1267:0] debug: mesh_run: start
May 05 18:31:23 unbound-default[1267:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
May 05 18:31:23 unbound-default[1267:0] info: iterator operate: query www.startpuntgeldzaken.nl. A IN
May 05 18:31:23 unbound-default[1267:0] debug: process_response: new external response event
May 05 18:31:23 unbound-default[1267:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
May 05 18:31:23 unbound-default[1267:0] debug: query response was timeout
May 05 18:31:23 unbound-default[1267:0] debug: iter_handle processing q with state QUERY TARGETS STATE
May 05 18:31:23 unbound-default[1267:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 18:31:23 unbound-default[1267:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 1
May 05 18:31:23 unbound-default[1267:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (2 result, 0 avail) parentNS
May 05 18:31:23 unbound-default[1267:0] debug: ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:23 unbound-default[1267:0] debug: ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:23 unbound-default[1267:0] debug: attempt to get extra 3 targets
May 05 18:31:23 unbound-default[1267:0] debug: servselect ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:23 unbound-default[1267:0] debug: rtt=246
May 05 18:31:23 unbound-default[1267:0] debug: selrtt 246
May 05 18:31:23 unbound-default[1267:0] info: sending query: www.startpuntgeldzaken.nl. A IN
May 05 18:31:23 unbound-default[1267:0] debug: sending to target: <.> 9.9.9.9#53
May 05 18:31:23 unbound-default[1267:0] debug: dnssec status: not expected
May 05 18:31:23 unbound-default[1267:0] debug: EDNS lookup known=1 vs=0
May 05 18:31:23 unbound-default[1267:0] debug: serviced query UDP timeout=246 msec
May 05 18:31:23 unbound-default[1267:0] debug: inserted new pending reply id=7830
May 05 18:31:23 unbound-default[1267:0] debug: opened UDP if=0 port=25891
May 05 18:31:23 unbound-default[1267:0] debug: comm point start listening 9 (-1 msec)
May 05 18:31:23 unbound-default[1267:0] debug: mesh_run: iterator module exit state is module_wait_reply
May 05 18:31:23 unbound-default[1267:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 1 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
May 05 18:31:23 unbound-default[1267:0] info: average recursion processing time 0.029573 sec
May 05 18:31:23 unbound-default[1267:0] info: histogram of recursion processing times
May 05 18:31:23 unbound-default[1267:0] info: [25%]=0 median[50%]=0 [75%]=0
May 05 18:31:23 unbound-default[1267:0] info: lower(secs) upper(secs) recursions
May 05 18:31:23 unbound-default[1267:0] info: 0.016384 0.032768 1
May 05 18:31:23 unbound-default[1267:0] info: 0.032768 0.065536 1
May 05 18:31:23 unbound-default[1267:0] info: 0RDd mod1 rep www.startpuntgeldzaken.nl. A IN
May 05 18:31:23 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30425 val=296000
May 05 18:31:23 unbound-default[1267:0] debug: svcd callbacks end
May 05 18:31:23 unbound-default[1267:0] debug: answer cb
May 05 18:31:23 unbound-default[1267:0] debug: Incoming reply id = 7830
May 05 18:31:23 unbound-default[1267:0] debug: Incoming reply addr = ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:23 unbound-default[1267:0] debug: lookup size is 1 entries
May 05 18:31:23 unbound-default[1267:0] debug: received udp reply.
May 05 18:31:23 unbound-default[1267:0] debug: udp message[974:0] 783083A000010007000000010377777712737461727470756E7467656C647A616B656E026E6C0000010001C00C00050001000000390018056E696275640A7472756570656F706C6505737061636500C00C002E00010000003900A9000507020000003C609C6C006080BC80706412737461727470756E7467656C647A616B656E026E6C009220FA364B3D0C7EB0B2DF564EB8F5F9B32334C39EC2CB54EE9EADA58600CEA226EF0AE897B51597065DFA773C8A07346996C91A38A903CF7D5E7D94323E2C4EBEBB66A8E1F6198B38F3373C90CF30D252814B4ABBC6D5603E1518DF9C90F88F293236EDC189EC6BB82B01AF2A95B855D95C2BE84643508F49E46697
May 05 18:31:23 unbound-default[1267:0] debug: udp message[974:256] 77C0A8BDC00C002E0001000000390129000508020000003C609C6C006080BC80F14B12737461727470756E7467656C647A616B656E026E6C0064C40C418346200F0BFFC403EF28F9FC5EE97F0EB3870437410B8D6B4AB1E1EE54AF73DF47751E5CF0F9B0040A095F44AC0B5CCD59F3D988D638C2563E52AC4EC60A50CC65991DF41986536A0FCF3DEBDE725B6061ED70CDEF6CEA694F94889291088FBA600CFBC3DC77DF5E24E0101494DF409DCA35BC05BB17328F2DDDB6363A4CE4F5AB2E1F653C0DFD9092B59EB5489C73691897B7D05B16C124A8F6940662FC66034C012D63ADDA484081CBC1EC27602D2988BF4B8C17628046F3680D4309652132014736
May 05 18:31:23 unbound-default[1267:0] debug: udp message[974:512] 16C01EA7AACA89D31A257172944E98B382416BA3C17C4B1DE3EFA28CCAF71610E4D7A1F98DF9DE1F828097D54BA133EDF748B63B85B198E331C0370005000100000129000E0B74702D6E696275642D3031C03DC037002E00010000012900A4000507030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500A19B70EDA2BFD27C98CD4239E6386617570CDF6CF1EC15E7053F97420A8B0973C22E25025315B504D482ABAFAFA90E6127C680A33AB3ECAD6AE8B51608E7E1B3FDE7BE4D24E6411C21EE99B41C9884FA4AEA88F874D0B18CDF3F77CFF96D50C27000FF23CF905D6CF23A9538F9C0269C6A8635100D0F93120CB8A7BFF2
May 05 18:31:23 unbound-default[1267:0] debug: udp message[974:768] 73730CC24500010001000001290004541663B0C245002E00010000012900A4000107030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500539B832E5A40E412A9B67DC7CB3E3353210CB5A453B63E22FFAC9AAF4648F90079275886E92BAE6989435140E18FC822F37287654A6C4651DAF720B096C3254E66DC282506001EFC0E7351AE5B3F1F9612FB0ACD564D181641C8162E1A25F66EC686069F670677F90A9F34AC2879CF6D7B800D16B8A9AA245AE9BA9A2BD8526E00002904D0000080000000
May 05 18:31:23 unbound-default[1267:0] debug: outnet handle udp reply
May 05 18:31:23 unbound-default[1267:0] debug: measured roundtrip at 25 msec
May 05 18:31:23 unbound-default[1267:0] debug: initiate TCP query EDNS
May 05 18:31:23 unbound-default[1267:0] debug: close of port 25891
May 05 18:31:23 unbound-default[1267:0] debug: close fd 9
May 05 18:31:25 unbound-default[1267:0] info: 192.168.2.86 www.startpuntgeldzaken.nl. A IN
May 05 18:31:25 unbound-default[1267:0] debug: using localzone . transparent
May 05 18:31:25 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30425 val=296000
May 05 18:31:26 unbound-default[1267:0] debug: tcp error for address ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:26 unbound-default[1267:0] debug: svcd callbacks start
May 05 18:31:26 unbound-default[1267:0] debug: worker svcd callback for qstate 0x7fde48992690
May 05 18:31:26 unbound-default[1267:0] debug: mesh_run: start
May 05 18:31:26 unbound-default[1267:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
May 05 18:31:26 unbound-default[1267:0] info: iterator operate: query www.startpuntgeldzaken.nl. A IN
May 05 18:31:26 unbound-default[1267:0] debug: process_response: new external response event
May 05 18:31:26 unbound-default[1267:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
May 05 18:31:26 unbound-default[1267:0] debug: query response was timeout
May 05 18:31:26 unbound-default[1267:0] debug: iter_handle processing q with state QUERY TARGETS STATE
May 05 18:31:26 unbound-default[1267:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 18:31:26 unbound-default[1267:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 2
May 05 18:31:26 unbound-default[1267:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (2 result, 0 avail) parentNS
May 05 18:31:26 unbound-default[1267:0] debug: ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:26 unbound-default[1267:0] debug: ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:26 unbound-default[1267:0] debug: attempt to get extra 3 targets
May 05 18:31:26 unbound-default[1267:0] debug: servselect ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:26 unbound-default[1267:0] debug: rtt=203
May 05 18:31:26 unbound-default[1267:0] debug: selrtt 203
May 05 18:31:26 unbound-default[1267:0] info: sending query: www.startpuntgeldzaken.nl. A IN
May 05 18:31:26 unbound-default[1267:0] debug: sending to target: <.> 9.9.9.9#53
May 05 18:31:26 unbound-default[1267:0] debug: dnssec status: not expected
May 05 18:31:26 unbound-default[1267:0] debug: EDNS lookup known=1 vs=0
May 05 18:31:26 unbound-default[1267:0] debug: serviced query UDP timeout=203 msec
May 05 18:31:26 unbound-default[1267:0] debug: inserted new pending reply id=fe52
May 05 18:31:26 unbound-default[1267:0] debug: opened UDP if=0 port=46237
May 05 18:31:26 unbound-default[1267:0] debug: comm point start listening 9 (-1 msec)
May 05 18:31:26 unbound-default[1267:0] debug: mesh_run: iterator module exit state is module_wait_reply
May 05 18:31:26 unbound-default[1267:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 2 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
May 05 18:31:26 unbound-default[1267:0] info: average recursion processing time 0.029573 sec
May 05 18:31:26 unbound-default[1267:0] info: histogram of recursion processing times
May 05 18:31:26 unbound-default[1267:0] info: [25%]=0 median[50%]=0 [75%]=0
May 05 18:31:26 unbound-default[1267:0] info: lower(secs) upper(secs) recursions
May 05 18:31:26 unbound-default[1267:0] info: 0.016384 0.032768 1
May 05 18:31:26 unbound-default[1267:0] info: 0.032768 0.065536 1
May 05 18:31:26 unbound-default[1267:0] info: 0RDd mod1 rep www.startpuntgeldzaken.nl. A IN
May 05 18:31:26 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30425 val=296000
May 05 18:31:26 unbound-default[1267:0] debug: svcd callbacks end
May 05 18:31:26 unbound-default[1267:0] debug: answer cb
May 05 18:31:26 unbound-default[1267:0] debug: Incoming reply id = fe52
May 05 18:31:26 unbound-default[1267:0] debug: Incoming reply addr = ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:26 unbound-default[1267:0] debug: lookup size is 1 entries
May 05 18:31:26 unbound-default[1267:0] debug: received udp reply.
May 05 18:31:26 unbound-default[1267:0] debug: udp message[974:0] FE5283A000010007000000010377777712737461727470756E7467656C647A616B656E026E6C0000010001C00C00050001000000360018056E696275640A7472756570656F706C6505737061636500C00C002E00010000003600A9000507020000003C609C6C006080BC80706412737461727470756E7467656C647A616B656E026E6C009220FA364B3D0C7EB0B2DF564EB8F5F9B32334C39EC2CB54EE9EADA58600CEA226EF0AE897B51597065DFA773C8A07346996C91A38A903CF7D5E7D94323E2C4EBEBB66A8E1F6198B38F3373C90CF30D252814B4ABBC6D5603E1518DF9C90F88F293236EDC189EC6BB82B01AF2A95B855D95C2BE84643508F49E46697
May 05 18:31:26 unbound-default[1267:0] debug: udp message[974:256] 77C0A8BDC00C002E0001000000360129000508020000003C609C6C006080BC80F14B12737461727470756E7467656C647A616B656E026E6C0064C40C418346200F0BFFC403EF28F9FC5EE97F0EB3870437410B8D6B4AB1E1EE54AF73DF47751E5CF0F9B0040A095F44AC0B5CCD59F3D988D638C2563E52AC4EC60A50CC65991DF41986536A0FCF3DEBDE725B6061ED70CDEF6CEA694F94889291088FBA600CFBC3DC77DF5E24E0101494DF409DCA35BC05BB17328F2DDDB6363A4CE4F5AB2E1F653C0DFD9092B59EB5489C73691897B7D05B16C124A8F6940662FC66034C012D63ADDA484081CBC1EC27602D2988BF4B8C17628046F3680D4309652132014736
May 05 18:31:26 unbound-default[1267:0] debug: udp message[974:512] 16C01EA7AACA89D31A257172944E98B382416BA3C17C4B1DE3EFA28CCAF71610E4D7A1F98DF9DE1F828097D54BA133EDF748B63B85B198E331C0370005000100000126000E0B74702D6E696275642D3031C03DC037002E00010000012600A4000507030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500A19B70EDA2BFD27C98CD4239E6386617570CDF6CF1EC15E7053F97420A8B0973C22E25025315B504D482ABAFAFA90E6127C680A33AB3ECAD6AE8B51608E7E1B3FDE7BE4D24E6411C21EE99B41C9884FA4AEA88F874D0B18CDF3F77CFF96D50C27000FF23CF905D6CF23A9538F9C0269C6A8635100D0F93120CB8A7BFF2
May 05 18:31:26 unbound-default[1267:0] debug: udp message[974:768] 73730CC24500010001000001260004541663B0C245002E00010000012600A4000107030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500539B832E5A40E412A9B67DC7CB3E3353210CB5A453B63E22FFAC9AAF4648F90079275886E92BAE6989435140E18FC822F37287654A6C4651DAF720B096C3254E66DC282506001EFC0E7351AE5B3F1F9612FB0ACD564D181641C8162E1A25F66EC686069F670677F90A9F34AC2879CF6D7B800D16B8A9AA245AE9BA9A2BD8526E00002904D0000080000000
May 05 18:31:26 unbound-default[1267:0] debug: outnet handle udp reply
May 05 18:31:26 unbound-default[1267:0] debug: measured roundtrip at 21 msec
May 05 18:31:26 unbound-default[1267:0] debug: initiate TCP query EDNS
May 05 18:31:26 unbound-default[1267:0] debug: close of port 46237
May 05 18:31:26 unbound-default[1267:0] debug: close fd 9
May 05 18:31:29 unbound-default[1267:0] debug: tcp error for address ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:29 unbound-default[1267:0] debug: svcd callbacks start
May 05 18:31:29 unbound-default[1267:0] debug: worker svcd callback for qstate 0x7fde48992690
May 05 18:31:29 unbound-default[1267:0] debug: mesh_run: start
May 05 18:31:29 unbound-default[1267:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
May 05 18:31:29 unbound-default[1267:0] info: iterator operate: query www.startpuntgeldzaken.nl. A IN
May 05 18:31:29 unbound-default[1267:0] debug: process_response: new external response event
May 05 18:31:29 unbound-default[1267:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
May 05 18:31:29 unbound-default[1267:0] debug: query response was timeout
May 05 18:31:29 unbound-default[1267:0] debug: iter_handle processing q with state QUERY TARGETS STATE
May 05 18:31:29 unbound-default[1267:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 18:31:29 unbound-default[1267:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 3
May 05 18:31:29 unbound-default[1267:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (2 result, 0 avail) parentNS
May 05 18:31:29 unbound-default[1267:0] debug: ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:29 unbound-default[1267:0] debug: ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:29 unbound-default[1267:0] debug: servselect ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:29 unbound-default[1267:0] debug: rtt=168
May 05 18:31:29 unbound-default[1267:0] debug: selrtt 168
May 05 18:31:29 unbound-default[1267:0] info: sending query: www.startpuntgeldzaken.nl. A IN
May 05 18:31:29 unbound-default[1267:0] debug: sending to target: <.> 149.112.112.112#53
May 05 18:31:29 unbound-default[1267:0] debug: dnssec status: not expected
May 05 18:31:29 unbound-default[1267:0] debug: EDNS lookup known=0 vs=0
May 05 18:31:29 unbound-default[1267:0] debug: serviced query UDP timeout=376 msec
May 05 18:31:29 unbound-default[1267:0] debug: inserted new pending reply id=cb35
May 05 18:31:29 unbound-default[1267:0] debug: opened UDP if=0 port=8076
May 05 18:31:29 unbound-default[1267:0] debug: comm point start listening 9 (-1 msec)
May 05 18:31:29 unbound-default[1267:0] debug: mesh_run: iterator module exit state is module_wait_reply
May 05 18:31:29 unbound-default[1267:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 2 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
May 05 18:31:29 unbound-default[1267:0] info: average recursion processing time 0.029573 sec
May 05 18:31:29 unbound-default[1267:0] info: histogram of recursion processing times
May 05 18:31:29 unbound-default[1267:0] info: [25%]=0 median[50%]=0 [75%]=0
May 05 18:31:29 unbound-default[1267:0] info: lower(secs) upper(secs) recursions
May 05 18:31:29 unbound-default[1267:0] info: 0.016384 0.032768 1
May 05 18:31:29 unbound-default[1267:0] info: 0.032768 0.065536 1
May 05 18:31:29 unbound-default[1267:0] info: 0RDd mod1 rep www.startpuntgeldzaken.nl. A IN
May 05 18:31:29 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30866 val=296000
May 05 18:31:29 unbound-default[1267:0] debug: svcd callbacks end
May 05 18:31:29 unbound-default[1267:0] debug: answer cb
May 05 18:31:29 unbound-default[1267:0] debug: Incoming reply id = cb35
May 05 18:31:29 unbound-default[1267:0] debug: Incoming reply addr = ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:29 unbound-default[1267:0] debug: lookup size is 1 entries
May 05 18:31:29 unbound-default[1267:0] debug: received udp reply.
May 05 18:31:29 unbound-default[1267:0] debug: udp message[974:0] CB3583A000010007000000010377777712737461727470756E7467656C647A616B656E026E6C0000010001C00C000500010000003C0018056E696275640A7472756570656F706C6505737061636500C00C002E00010000003C00A9000507020000003C609C6C006080BC80706412737461727470756E7467656C647A616B656E026E6C009220FA364B3D0C7EB0B2DF564EB8F5F9B32334C39EC2CB54EE9EADA58600CEA226EF0AE897B51597065DFA773C8A07346996C91A38A903CF7D5E7D94323E2C4EBEBB66A8E1F6198B38F3373C90CF30D252814B4ABBC6D5603E1518DF9C90F88F293236EDC189EC6BB82B01AF2A95B855D95C2BE84643508F49E46697
May 05 18:31:29 unbound-default[1267:0] debug: udp message[974:256] 77C0A8BDC00C002E00010000003C0129000508020000003C609C6C006080BC80F14B12737461727470756E7467656C647A616B656E026E6C0064C40C418346200F0BFFC403EF28F9FC5EE97F0EB3870437410B8D6B4AB1E1EE54AF73DF47751E5CF0F9B0040A095F44AC0B5CCD59F3D988D638C2563E52AC4EC60A50CC65991DF41986536A0FCF3DEBDE725B6061ED70CDEF6CEA694F94889291088FBA600CFBC3DC77DF5E24E0101494DF409DCA35BC05BB17328F2DDDB6363A4CE4F5AB2E1F653C0DFD9092B59EB5489C73691897B7D05B16C124A8F6940662FC66034C012D63ADDA484081CBC1EC27602D2988BF4B8C17628046F3680D4309652132014736
May 05 18:31:29 unbound-default[1267:0] debug: udp message[974:512] 16C01EA7AACA89D31A257172944E98B382416BA3C17C4B1DE3EFA28CCAF71610E4D7A1F98DF9DE1F828097D54BA133EDF748B63B85B198E331C037000500010000012C000E0B74702D6E696275642D3031C03DC037002E00010000012C00A4000507030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500A19B70EDA2BFD27C98CD4239E6386617570CDF6CF1EC15E7053F97420A8B0973C22E25025315B504D482ABAFAFA90E6127C680A33AB3ECAD6AE8B51608E7E1B3FDE7BE4D24E6411C21EE99B41C9884FA4AEA88F874D0B18CDF3F77CFF96D50C27000FF23CF905D6CF23A9538F9C0269C6A8635100D0F93120CB8A7BFF2
May 05 18:31:29 unbound-default[1267:0] debug: udp message[974:768] 73730CC245000100010000012C0004541663B0C245002E00010000012C00A4000107030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500539B832E5A40E412A9B67DC7CB3E3353210CB5A453B63E22FFAC9AAF4648F90079275886E92BAE6989435140E18FC822F37287654A6C4651DAF720B096C3254E66DC282506001EFC0E7351AE5B3F1F9612FB0ACD564D181641C8162E1A25F66EC686069F670677F90A9F34AC2879CF6D7B800D16B8A9AA245AE9BA9A2BD8526E00002904D0000080000000
May 05 18:31:29 unbound-default[1267:0] debug: outnet handle udp reply
May 05 18:31:29 unbound-default[1267:0] debug: serviced query: EDNS works for ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:29 unbound-default[1267:0] debug: measured roundtrip at 48 msec
May 05 18:31:29 unbound-default[1267:0] debug: initiate TCP query EDNS
May 05 18:31:29 unbound-default[1267:0] debug: close of port 8076
May 05 18:31:29 unbound-default[1267:0] debug: close fd 9
May 05 18:31:30 unbound-default[1267:0] info: 192.168.2.86 www.startpuntgeldzaken.nl. A IN
May 05 18:31:30 unbound-default[1267:0] debug: using localzone . transparent
May 05 18:31:30 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30866 val=296000
May 05 18:31:32 unbound-default[1267:0] debug: tcp error for address ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:32 unbound-default[1267:0] debug: svcd callbacks start
May 05 18:31:32 unbound-default[1267:0] debug: worker svcd callback for qstate 0x7fde48992690
May 05 18:31:32 unbound-default[1267:0] debug: mesh_run: start
May 05 18:31:32 unbound-default[1267:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
May 05 18:31:32 unbound-default[1267:0] info: iterator operate: query www.startpuntgeldzaken.nl. A IN
May 05 18:31:32 unbound-default[1267:0] debug: process_response: new external response event
May 05 18:31:32 unbound-default[1267:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
May 05 18:31:32 unbound-default[1267:0] debug: query response was timeout
May 05 18:31:32 unbound-default[1267:0] debug: iter_handle processing q with state QUERY TARGETS STATE
May 05 18:31:32 unbound-default[1267:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 18:31:32 unbound-default[1267:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 4
May 05 18:31:32 unbound-default[1267:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (2 result, 0 avail) parentNS
May 05 18:31:32 unbound-default[1267:0] debug: ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:32 unbound-default[1267:0] debug: ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:32 unbound-default[1267:0] debug: servselect ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:32 unbound-default[1267:0] debug: rtt=168
May 05 18:31:32 unbound-default[1267:0] debug: servselect ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:32 unbound-default[1267:0] debug: rtt=338
May 05 18:31:32 unbound-default[1267:0] debug: selrtt 168
May 05 18:31:32 unbound-default[1267:0] info: sending query: www.startpuntgeldzaken.nl. A IN
May 05 18:31:32 unbound-default[1267:0] debug: sending to target: <.> 9.9.9.9#53
May 05 18:31:32 unbound-default[1267:0] debug: dnssec status: not expected
May 05 18:31:32 unbound-default[1267:0] debug: EDNS lookup known=1 vs=0
May 05 18:31:32 unbound-default[1267:0] debug: serviced query UDP timeout=168 msec
May 05 18:31:32 unbound-default[1267:0] debug: inserted new pending reply id=979d
May 05 18:31:32 unbound-default[1267:0] debug: opened UDP if=0 port=18861
May 05 18:31:32 unbound-default[1267:0] debug: comm point start listening 9 (-1 msec)
May 05 18:31:32 unbound-default[1267:0] debug: mesh_run: iterator module exit state is module_wait_reply
May 05 18:31:32 unbound-default[1267:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 3 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
May 05 18:31:32 unbound-default[1267:0] info: average recursion processing time 0.029573 sec
May 05 18:31:32 unbound-default[1267:0] info: histogram of recursion processing times
May 05 18:31:32 unbound-default[1267:0] info: [25%]=0 median[50%]=0 [75%]=0
May 05 18:31:32 unbound-default[1267:0] info: lower(secs) upper(secs) recursions
May 05 18:31:32 unbound-default[1267:0] info: 0.016384 0.032768 1
May 05 18:31:32 unbound-default[1267:0] info: 0.032768 0.065536 1
May 05 18:31:32 unbound-default[1267:0] info: 0RDd mod1 rep www.startpuntgeldzaken.nl. A IN
May 05 18:31:32 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30866 val=296000
May 05 18:31:32 unbound-default[1267:0] debug: svcd callbacks end
May 05 18:31:32 unbound-default[1267:0] debug: answer cb
May 05 18:31:32 unbound-default[1267:0] debug: Incoming reply id = 979d
May 05 18:31:32 unbound-default[1267:0] debug: Incoming reply addr = ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:32 unbound-default[1267:0] debug: lookup size is 1 entries
May 05 18:31:32 unbound-default[1267:0] debug: received udp reply.
May 05 18:31:32 unbound-default[1267:0] debug: udp message[54:0] 979D83A000010000000000010377777712737461727470756E7467656C647A616B656E026E6C00000100010000290200000080000000
May 05 18:31:32 unbound-default[1267:0] debug: outnet handle udp reply
May 05 18:31:32 unbound-default[1267:0] debug: measured roundtrip at 61 msec
May 05 18:31:32 unbound-default[1267:0] debug: initiate TCP query EDNS
May 05 18:31:32 unbound-default[1267:0] debug: close of port 18861
May 05 18:31:32 unbound-default[1267:0] debug: close fd 9
May 05 18:31:35 unbound-default[1267:0] debug: tcp error for address ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:35 unbound-default[1267:0] debug: svcd callbacks start
May 05 18:31:35 unbound-default[1267:0] debug: worker svcd callback for qstate 0x7fde48992690
May 05 18:31:35 unbound-default[1267:0] debug: mesh_run: start
May 05 18:31:35 unbound-default[1267:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
May 05 18:31:35 unbound-default[1267:0] info: iterator operate: query www.startpuntgeldzaken.nl. A IN
May 05 18:31:35 unbound-default[1267:0] debug: process_response: new external response event
May 05 18:31:35 unbound-default[1267:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
May 05 18:31:35 unbound-default[1267:0] debug: query response was timeout
May 05 18:31:35 unbound-default[1267:0] debug: iter_handle processing q with state QUERY TARGETS STATE
May 05 18:31:35 unbound-default[1267:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 18:31:35 unbound-default[1267:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 5
May 05 18:31:35 unbound-default[1267:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (2 result, 0 avail) parentNS
May 05 18:31:35 unbound-default[1267:0] debug: ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:35 unbound-default[1267:0] debug: ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:35 unbound-default[1267:0] debug: servselect ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:35 unbound-default[1267:0] debug: rtt=338
May 05 18:31:35 unbound-default[1267:0] debug: servselect ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:35 unbound-default[1267:0] debug: rtt=182
May 05 18:31:35 unbound-default[1267:0] debug: selrtt 182
May 05 18:31:35 unbound-default[1267:0] info: sending query: www.startpuntgeldzaken.nl. A IN
May 05 18:31:35 unbound-default[1267:0] debug: sending to target: <.> 9.9.9.9#53
May 05 18:31:35 unbound-default[1267:0] debug: dnssec status: not expected
May 05 18:31:35 unbound-default[1267:0] debug: EDNS lookup known=1 vs=0
May 05 18:31:35 unbound-default[1267:0] debug: serviced query UDP timeout=182 msec
May 05 18:31:35 unbound-default[1267:0] debug: inserted new pending reply id=2840
May 05 18:31:35 unbound-default[1267:0] debug: opened UDP if=0 port=20260
May 05 18:31:35 unbound-default[1267:0] debug: comm point start listening 9 (-1 msec)
May 05 18:31:35 unbound-default[1267:0] debug: mesh_run: iterator module exit state is module_wait_reply
May 05 18:31:35 unbound-default[1267:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 3 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
May 05 18:31:35 unbound-default[1267:0] info: average recursion processing time 0.029573 sec
May 05 18:31:35 unbound-default[1267:0] info: histogram of recursion processing times
May 05 18:31:35 unbound-default[1267:0] info: [25%]=0 median[50%]=0 [75%]=0
May 05 18:31:35 unbound-default[1267:0] info: lower(secs) upper(secs) recursions
May 05 18:31:35 unbound-default[1267:0] info: 0.016384 0.032768 1
May 05 18:31:35 unbound-default[1267:0] info: 0.032768 0.065536 1
May 05 18:31:35 unbound-default[1267:0] info: 0RDd mod1 rep www.startpuntgeldzaken.nl. A IN
May 05 18:31:35 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30866 val=296000
May 05 18:31:35 unbound-default[1267:0] debug: svcd callbacks end
May 05 18:31:35 unbound-default[1267:0] debug: answer cb
May 05 18:31:35 unbound-default[1267:0] debug: Incoming reply id = 2840
May 05 18:31:35 unbound-default[1267:0] debug: Incoming reply addr = ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:35 unbound-default[1267:0] debug: lookup size is 1 entries
May 05 18:31:35 unbound-default[1267:0] debug: received udp reply.
May 05 18:31:35 unbound-default[1267:0] debug: udp message[974:0] 284083A000010007000000010377777712737461727470756E7467656C647A616B656E026E6C0000010001C00C00050001000000360018056E696275640A7472756570656F706C6505737061636500C00C002E00010000003600A9000507020000003C609C6C006080BC80706412737461727470756E7467656C647A616B656E026E6C009220FA364B3D0C7EB0B2DF564EB8F5F9B32334C39EC2CB54EE9EADA58600CEA226EF0AE897B51597065DFA773C8A07346996C91A38A903CF7D5E7D94323E2C4EBEBB66A8E1F6198B38F3373C90CF30D252814B4ABBC6D5603E1518DF9C90F88F293236EDC189EC6BB82B01AF2A95B855D95C2BE84643508F49E46697
May 05 18:31:35 unbound-default[1267:0] debug: udp message[974:256] 77C0A8BDC00C002E0001000000360129000508020000003C609C6C006080BC80F14B12737461727470756E7467656C647A616B656E026E6C0064C40C418346200F0BFFC403EF28F9FC5EE97F0EB3870437410B8D6B4AB1E1EE54AF73DF47751E5CF0F9B0040A095F44AC0B5CCD59F3D988D638C2563E52AC4EC60A50CC65991DF41986536A0FCF3DEBDE725B6061ED70CDEF6CEA694F94889291088FBA600CFBC3DC77DF5E24E0101494DF409DCA35BC05BB17328F2DDDB6363A4CE4F5AB2E1F653C0DFD9092B59EB5489C73691897B7D05B16C124A8F6940662FC66034C012D63ADDA484081CBC1EC27602D2988BF4B8C17628046F3680D4309652132014736
May 05 18:31:35 unbound-default[1267:0] debug: udp message[974:512] 16C01EA7AACA89D31A257172944E98B382416BA3C17C4B1DE3EFA28CCAF71610E4D7A1F98DF9DE1F828097D54BA133EDF748B63B85B198E331C0370005000100000126000E0B74702D6E696275642D3031C03DC037002E00010000012600A4000507030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500A19B70EDA2BFD27C98CD4239E6386617570CDF6CF1EC15E7053F97420A8B0973C22E25025315B504D482ABAFAFA90E6127C680A33AB3ECAD6AE8B51608E7E1B3FDE7BE4D24E6411C21EE99B41C9884FA4AEA88F874D0B18CDF3F77CFF96D50C27000FF23CF905D6CF23A9538F9C0269C6A8635100D0F93120CB8A7BFF2
May 05 18:31:35 unbound-default[1267:0] debug: udp message[974:768] 73730CC24500010001000001260004541663B0C245002E00010000012600A4000107030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500539B832E5A40E412A9B67DC7CB3E3353210CB5A453B63E22FFAC9AAF4648F90079275886E92BAE6989435140E18FC822F37287654A6C4651DAF720B096C3254E66DC282506001EFC0E7351AE5B3F1F9612FB0ACD564D181641C8162E1A25F66EC686069F670677F90A9F34AC2879CF6D7B800D16B8A9AA245AE9BA9A2BD8526E00002904D0000080000000
May 05 18:31:35 unbound-default[1267:0] debug: outnet handle udp reply
May 05 18:31:35 unbound-default[1267:0] debug: measured roundtrip at 24 msec
May 05 18:31:35 unbound-default[1267:0] debug: initiate TCP query EDNS
May 05 18:31:35 unbound-default[1267:0] debug: close of port 20260
May 05 18:31:35 unbound-default[1267:0] debug: close fd 9
May 05 18:31:39 unbound-default[1267:0] debug: tcp error for address ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:39 unbound-default[1267:0] debug: svcd callbacks start
May 05 18:31:39 unbound-default[1267:0] debug: worker svcd callback for qstate 0x7fde48992690
May 05 18:31:39 unbound-default[1267:0] debug: mesh_run: start
May 05 18:31:39 unbound-default[1267:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
May 05 18:31:39 unbound-default[1267:0] info: iterator operate: query www.startpuntgeldzaken.nl. A IN
May 05 18:31:39 unbound-default[1267:0] debug: process_response: new external response event
May 05 18:31:39 unbound-default[1267:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
May 05 18:31:39 unbound-default[1267:0] debug: query response was timeout
May 05 18:31:39 unbound-default[1267:0] debug: iter_handle processing q with state QUERY TARGETS STATE
May 05 18:31:39 unbound-default[1267:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 18:31:39 unbound-default[1267:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 6
May 05 18:31:39 unbound-default[1267:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (1 result, 0 avail) parentNS
May 05 18:31:39 unbound-default[1267:0] debug: ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:39 unbound-default[1267:0] debug: ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:39 unbound-default[1267:0] debug: servselect ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:39 unbound-default[1267:0] debug: rtt=338
May 05 18:31:39 unbound-default[1267:0] debug: selrtt 338
May 05 18:31:39 unbound-default[1267:0] info: sending query: www.startpuntgeldzaken.nl. A IN
May 05 18:31:39 unbound-default[1267:0] debug: sending to target: <.> 149.112.112.112#53
May 05 18:31:39 unbound-default[1267:0] debug: dnssec status: not expected
May 05 18:31:39 unbound-default[1267:0] debug: EDNS lookup known=1 vs=0
May 05 18:31:39 unbound-default[1267:0] debug: serviced query UDP timeout=338 msec
May 05 18:31:39 unbound-default[1267:0] debug: inserted new pending reply id=a451
May 05 18:31:39 unbound-default[1267:0] debug: opened UDP if=0 port=18897
May 05 18:31:39 unbound-default[1267:0] debug: comm point start listening 9 (-1 msec)
May 05 18:31:39 unbound-default[1267:0] debug: mesh_run: iterator module exit state is module_wait_reply
May 05 18:31:39 unbound-default[1267:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 3 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
May 05 18:31:39 unbound-default[1267:0] info: average recursion processing time 0.029573 sec
May 05 18:31:39 unbound-default[1267:0] info: histogram of recursion processing times
May 05 18:31:39 unbound-default[1267:0] info: [25%]=0 median[50%]=0 [75%]=0
May 05 18:31:39 unbound-default[1267:0] info: lower(secs) upper(secs) recursions
May 05 18:31:39 unbound-default[1267:0] info: 0.016384 0.032768 1
May 05 18:31:39 unbound-default[1267:0] info: 0.032768 0.065536 1
May 05 18:31:39 unbound-default[1267:0] info: 0RDd mod1 rep www.startpuntgeldzaken.nl. A IN
May 05 18:31:39 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30866 val=296000
May 05 18:31:39 unbound-default[1267:0] debug: svcd callbacks end
May 05 18:31:39 unbound-default[1267:0] debug: answer cb
May 05 18:31:39 unbound-default[1267:0] debug: Incoming reply id = a451
May 05 18:31:39 unbound-default[1267:0] debug: Incoming reply addr = ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:39 unbound-default[1267:0] debug: lookup size is 1 entries
May 05 18:31:39 unbound-default[1267:0] debug: received udp reply.
May 05 18:31:39 unbound-default[1267:0] debug: udp message[974:0] A45183A000010007000000010377777712737461727470756E7467656C647A616B656E026E6C0000010001C00C000500010000003C0018056E696275640A7472756570656F706C6505737061636500C00C002E00010000003C00A9000507020000003C609C6C006080BC80706412737461727470756E7467656C647A616B656E026E6C009220FA364B3D0C7EB0B2DF564EB8F5F9B32334C39EC2CB54EE9EADA58600CEA226EF0AE897B51597065DFA773C8A07346996C91A38A903CF7D5E7D94323E2C4EBEBB66A8E1F6198B38F3373C90CF30D252814B4ABBC6D5603E1518DF9C90F88F293236EDC189EC6BB82B01AF2A95B855D95C2BE84643508F49E46697
May 05 18:31:39 unbound-default[1267:0] debug: udp message[974:256] 77C0A8BDC00C002E00010000003C0129000508020000003C609C6C006080BC80F14B12737461727470756E7467656C647A616B656E026E6C0064C40C418346200F0BFFC403EF28F9FC5EE97F0EB3870437410B8D6B4AB1E1EE54AF73DF47751E5CF0F9B0040A095F44AC0B5CCD59F3D988D638C2563E52AC4EC60A50CC65991DF41986536A0FCF3DEBDE725B6061ED70CDEF6CEA694F94889291088FBA600CFBC3DC77DF5E24E0101494DF409DCA35BC05BB17328F2DDDB6363A4CE4F5AB2E1F653C0DFD9092B59EB5489C73691897B7D05B16C124A8F6940662FC66034C012D63ADDA484081CBC1EC27602D2988BF4B8C17628046F3680D4309652132014736
May 05 18:31:39 unbound-default[1267:0] debug: udp message[974:512] 16C01EA7AACA89D31A257172944E98B382416BA3C17C4B1DE3EFA28CCAF71610E4D7A1F98DF9DE1F828097D54BA133EDF748B63B85B198E331C037000500010000012C000E0B74702D6E696275642D3031C03DC037002E00010000012C00A4000507030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500A19B70EDA2BFD27C98CD4239E6386617570CDF6CF1EC15E7053F97420A8B0973C22E25025315B504D482ABAFAFA90E6127C680A33AB3ECAD6AE8B51608E7E1B3FDE7BE4D24E6411C21EE99B41C9884FA4AEA88F874D0B18CDF3F77CFF96D50C27000FF23CF905D6CF23A9538F9C0269C6A8635100D0F93120CB8A7BFF2
May 05 18:31:39 unbound-default[1267:0] debug: udp message[974:768] 73730CC245000100010000012C0004541663B0C245002E00010000012C00A4000107030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500539B832E5A40E412A9B67DC7CB3E3353210CB5A453B63E22FFAC9AAF4648F90079275886E92BAE6989435140E18FC822F37287654A6C4651DAF720B096C3254E66DC282506001EFC0E7351AE5B3F1F9612FB0ACD564D181641C8162E1A25F66EC686069F670677F90A9F34AC2879CF6D7B800D16B8A9AA245AE9BA9A2BD8526E00002904D0000080000000
May 05 18:31:39 unbound-default[1267:0] debug: outnet handle udp reply
May 05 18:31:39 unbound-default[1267:0] debug: measured roundtrip at 50 msec
May 05 18:31:39 unbound-default[1267:0] debug: initiate TCP query EDNS
May 05 18:31:39 unbound-default[1267:0] debug: close of port 18897
May 05 18:31:39 unbound-default[1267:0] debug: close fd 9
May 05 18:31:42 unbound-default[1267:0] debug: tcp error for address ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:42 unbound-default[1267:0] debug: svcd callbacks start
May 05 18:31:42 unbound-default[1267:0] debug: worker svcd callback for qstate 0x7fde48992690
May 05 18:31:42 unbound-default[1267:0] debug: mesh_run: start
May 05 18:31:42 unbound-default[1267:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
May 05 18:31:42 unbound-default[1267:0] info: iterator operate: query www.startpuntgeldzaken.nl. A IN
May 05 18:31:42 unbound-default[1267:0] debug: process_response: new external response event
May 05 18:31:42 unbound-default[1267:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
May 05 18:31:42 unbound-default[1267:0] debug: query response was timeout
May 05 18:31:42 unbound-default[1267:0] debug: iter_handle processing q with state QUERY TARGETS STATE
May 05 18:31:42 unbound-default[1267:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 18:31:42 unbound-default[1267:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 7
May 05 18:31:42 unbound-default[1267:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (1 result, 0 avail) parentNS
May 05 18:31:42 unbound-default[1267:0] debug: ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:42 unbound-default[1267:0] debug: ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:42 unbound-default[1267:0] debug: servselect ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:42 unbound-default[1267:0] debug: rtt=307
May 05 18:31:42 unbound-default[1267:0] debug: selrtt 307
May 05 18:31:42 unbound-default[1267:0] info: sending query: www.startpuntgeldzaken.nl. A IN
May 05 18:31:42 unbound-default[1267:0] debug: sending to target: <.> 149.112.112.112#53
May 05 18:31:42 unbound-default[1267:0] debug: dnssec status: not expected
May 05 18:31:42 unbound-default[1267:0] debug: EDNS lookup known=1 vs=0
May 05 18:31:42 unbound-default[1267:0] debug: serviced query UDP timeout=307 msec
May 05 18:31:42 unbound-default[1267:0] debug: inserted new pending reply id=25ad
May 05 18:31:42 unbound-default[1267:0] debug: opened UDP if=0 port=39592
May 05 18:31:42 unbound-default[1267:0] debug: comm point start listening 9 (-1 msec)
May 05 18:31:42 unbound-default[1267:0] debug: mesh_run: iterator module exit state is module_wait_reply
May 05 18:31:42 unbound-default[1267:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 3 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
May 05 18:31:42 unbound-default[1267:0] info: average recursion processing time 0.029573 sec
May 05 18:31:42 unbound-default[1267:0] info: histogram of recursion processing times
May 05 18:31:42 unbound-default[1267:0] info: [25%]=0 median[50%]=0 [75%]=0
May 05 18:31:42 unbound-default[1267:0] info: lower(secs) upper(secs) recursions
May 05 18:31:42 unbound-default[1267:0] info: 0.016384 0.032768 1
May 05 18:31:42 unbound-default[1267:0] info: 0.032768 0.065536 1
May 05 18:31:42 unbound-default[1267:0] info: 0RDd mod1 rep www.startpuntgeldzaken.nl. A IN
May 05 18:31:42 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30866 val=296000
May 05 18:31:42 unbound-default[1267:0] debug: svcd callbacks end
May 05 18:31:42 unbound-default[1267:0] debug: answer cb
May 05 18:31:42 unbound-default[1267:0] debug: Incoming reply id = 25ad
May 05 18:31:42 unbound-default[1267:0] debug: Incoming reply addr = ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:42 unbound-default[1267:0] debug: lookup size is 1 entries
May 05 18:31:42 unbound-default[1267:0] debug: received udp reply.
May 05 18:31:42 unbound-default[1267:0] debug: udp message[974:0] 25AD83A000010007000000010377777712737461727470756E7467656C647A616B656E026E6C0000010001C00C000500010000003C0018056E696275640A7472756570656F706C6505737061636500C00C002E00010000003C00A9000507020000003C609C6C006080BC80706412737461727470756E7467656C647A616B656E026E6C009220FA364B3D0C7EB0B2DF564EB8F5F9B32334C39EC2CB54EE9EADA58600CEA226EF0AE897B51597065DFA773C8A07346996C91A38A903CF7D5E7D94323E2C4EBEBB66A8E1F6198B38F3373C90CF30D252814B4ABBC6D5603E1518DF9C90F88F293236EDC189EC6BB82B01AF2A95B855D95C2BE84643508F49E46697
May 05 18:31:42 unbound-default[1267:0] debug: udp message[974:256] 77C0A8BDC00C002E00010000003C0129000508020000003C609C6C006080BC80F14B12737461727470756E7467656C647A616B656E026E6C0064C40C418346200F0BFFC403EF28F9FC5EE97F0EB3870437410B8D6B4AB1E1EE54AF73DF47751E5CF0F9B0040A095F44AC0B5CCD59F3D988D638C2563E52AC4EC60A50CC65991DF41986536A0FCF3DEBDE725B6061ED70CDEF6CEA694F94889291088FBA600CFBC3DC77DF5E24E0101494DF409DCA35BC05BB17328F2DDDB6363A4CE4F5AB2E1F653C0DFD9092B59EB5489C73691897B7D05B16C124A8F6940662FC66034C012D63ADDA484081CBC1EC27602D2988BF4B8C17628046F3680D4309652132014736
May 05 18:31:42 unbound-default[1267:0] debug: udp message[974:512] 16C01EA7AACA89D31A257172944E98B382416BA3C17C4B1DE3EFA28CCAF71610E4D7A1F98DF9DE1F828097D54BA133EDF748B63B85B198E331C037000500010000012C000E0B74702D6E696275642D3031C03DC037002E00010000012C00A4000507030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500A19B70EDA2BFD27C98CD4239E6386617570CDF6CF1EC15E7053F97420A8B0973C22E25025315B504D482ABAFAFA90E6127C680A33AB3ECAD6AE8B51608E7E1B3FDE7BE4D24E6411C21EE99B41C9884FA4AEA88F874D0B18CDF3F77CFF96D50C27000FF23CF905D6CF23A9538F9C0269C6A8635100D0F93120CB8A7BFF2
May 05 18:31:42 unbound-default[1267:0] debug: udp message[974:768] 73730CC245000100010000012C0004541663B0C245002E00010000012C00A4000107030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500539B832E5A40E412A9B67DC7CB3E3353210CB5A453B63E22FFAC9AAF4648F90079275886E92BAE6989435140E18FC822F37287654A6C4651DAF720B096C3254E66DC282506001EFC0E7351AE5B3F1F9612FB0ACD564D181641C8162E1A25F66EC686069F670677F90A9F34AC2879CF6D7B800D16B8A9AA245AE9BA9A2BD8526E00002904D0000080000000
May 05 18:31:42 unbound-default[1267:0] debug: outnet handle udp reply
May 05 18:31:42 unbound-default[1267:0] debug: measured roundtrip at 45 msec
May 05 18:31:42 unbound-default[1267:0] debug: initiate TCP query EDNS
May 05 18:31:42 unbound-default[1267:0] debug: close of port 39592
May 05 18:31:42 unbound-default[1267:0] debug: close fd 9
May 05 18:31:45 unbound-default[1267:0] debug: tcp error for address ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:45 unbound-default[1267:0] debug: svcd callbacks start
May 05 18:31:45 unbound-default[1267:0] debug: worker svcd callback for qstate 0x7fde48992690
May 05 18:31:45 unbound-default[1267:0] debug: mesh_run: start
May 05 18:31:45 unbound-default[1267:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
May 05 18:31:45 unbound-default[1267:0] info: iterator operate: query www.startpuntgeldzaken.nl. A IN
May 05 18:31:45 unbound-default[1267:0] debug: process_response: new external response event
May 05 18:31:45 unbound-default[1267:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
May 05 18:31:45 unbound-default[1267:0] debug: query response was timeout
May 05 18:31:45 unbound-default[1267:0] debug: iter_handle processing q with state QUERY TARGETS STATE
May 05 18:31:45 unbound-default[1267:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 18:31:45 unbound-default[1267:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 8
May 05 18:31:45 unbound-default[1267:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (1 result, 0 avail) parentNS
May 05 18:31:45 unbound-default[1267:0] debug: ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:45 unbound-default[1267:0] debug: ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:45 unbound-default[1267:0] debug: servselect ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:45 unbound-default[1267:0] debug: rtt=271
May 05 18:31:45 unbound-default[1267:0] debug: selrtt 271
May 05 18:31:45 unbound-default[1267:0] info: sending query: www.startpuntgeldzaken.nl. A IN
May 05 18:31:45 unbound-default[1267:0] debug: sending to target: <.> 149.112.112.112#53
May 05 18:31:45 unbound-default[1267:0] debug: dnssec status: not expected
May 05 18:31:45 unbound-default[1267:0] debug: EDNS lookup known=1 vs=0
May 05 18:31:45 unbound-default[1267:0] debug: serviced query UDP timeout=271 msec
May 05 18:31:45 unbound-default[1267:0] debug: inserted new pending reply id=f7a1
May 05 18:31:45 unbound-default[1267:0] debug: opened UDP if=0 port=31844
May 05 18:31:45 unbound-default[1267:0] debug: comm point start listening 9 (-1 msec)
May 05 18:31:45 unbound-default[1267:0] debug: mesh_run: iterator module exit state is module_wait_reply
May 05 18:31:45 unbound-default[1267:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 3 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
May 05 18:31:45 unbound-default[1267:0] info: average recursion processing time 0.029573 sec
May 05 18:31:45 unbound-default[1267:0] info: histogram of recursion processing times
May 05 18:31:45 unbound-default[1267:0] info: [25%]=0 median[50%]=0 [75%]=0
May 05 18:31:45 unbound-default[1267:0] info: lower(secs) upper(secs) recursions
May 05 18:31:45 unbound-default[1267:0] info: 0.016384 0.032768 1
May 05 18:31:45 unbound-default[1267:0] info: 0.032768 0.065536 1
May 05 18:31:45 unbound-default[1267:0] info: 0RDd mod1 rep www.startpuntgeldzaken.nl. A IN
May 05 18:31:45 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30866 val=296000
May 05 18:31:45 unbound-default[1267:0] debug: svcd callbacks end
May 05 18:31:45 unbound-default[1267:0] debug: answer cb
May 05 18:31:45 unbound-default[1267:0] debug: Incoming reply id = f7a1
May 05 18:31:45 unbound-default[1267:0] debug: Incoming reply addr = ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:45 unbound-default[1267:0] debug: lookup size is 1 entries
May 05 18:31:45 unbound-default[1267:0] debug: received udp reply.
May 05 18:31:45 unbound-default[1267:0] debug: udp message[974:0] F7A183A000010007000000010377777712737461727470756E7467656C647A616B656E026E6C0000010001C00C000500010000002C0018056E696275640A7472756570656F706C6505737061636500C00C002E00010000002C00A9000507020000003C609C6C006080BC80706412737461727470756E7467656C647A616B656E026E6C009220FA364B3D0C7EB0B2DF564EB8F5F9B32334C39EC2CB54EE9EADA58600CEA226EF0AE897B51597065DFA773C8A07346996C91A38A903CF7D5E7D94323E2C4EBEBB66A8E1F6198B38F3373C90CF30D252814B4ABBC6D5603E1518DF9C90F88F293236EDC189EC6BB82B01AF2A95B855D95C2BE84643508F49E46697
May 05 18:31:45 unbound-default[1267:0] debug: udp message[974:256] 77C0A8BDC00C002E00010000002C0129000508020000003C609C6C006080BC80F14B12737461727470756E7467656C647A616B656E026E6C0064C40C418346200F0BFFC403EF28F9FC5EE97F0EB3870437410B8D6B4AB1E1EE54AF73DF47751E5CF0F9B0040A095F44AC0B5CCD59F3D988D638C2563E52AC4EC60A50CC65991DF41986536A0FCF3DEBDE725B6061ED70CDEF6CEA694F94889291088FBA600CFBC3DC77DF5E24E0101494DF409DCA35BC05BB17328F2DDDB6363A4CE4F5AB2E1F653C0DFD9092B59EB5489C73691897B7D05B16C124A8F6940662FC66034C012D63ADDA484081CBC1EC27602D2988BF4B8C17628046F3680D4309652132014736
May 05 18:31:45 unbound-default[1267:0] debug: udp message[974:512] 16C01EA7AACA89D31A257172944E98B382416BA3C17C4B1DE3EFA28CCAF71610E4D7A1F98DF9DE1F828097D54BA133EDF748B63B85B198E331C037000500010000011C000E0B74702D6E696275642D3031C03DC037002E00010000011C00A4000507030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500A19B70EDA2BFD27C98CD4239E6386617570CDF6CF1EC15E7053F97420A8B0973C22E25025315B504D482ABAFAFA90E6127C680A33AB3ECAD6AE8B51608E7E1B3FDE7BE4D24E6411C21EE99B41C9884FA4AEA88F874D0B18CDF3F77CFF96D50C27000FF23CF905D6CF23A9538F9C0269C6A8635100D0F93120CB8A7BFF2
May 05 18:31:45 unbound-default[1267:0] debug: udp message[974:768] 73730CC245000100010000011C0004541663B0C245002E00010000011C00A4000107030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500539B832E5A40E412A9B67DC7CB3E3353210CB5A453B63E22FFAC9AAF4648F90079275886E92BAE6989435140E18FC822F37287654A6C4651DAF720B096C3254E66DC282506001EFC0E7351AE5B3F1F9612FB0ACD564D181641C8162E1A25F66EC686069F670677F90A9F34AC2879CF6D7B800D16B8A9AA245AE9BA9A2BD8526E00002904D0000080000000
May 05 18:31:45 unbound-default[1267:0] debug: outnet handle udp reply
May 05 18:31:45 unbound-default[1267:0] debug: measured roundtrip at 22 msec
May 05 18:31:45 unbound-default[1267:0] debug: initiate TCP query EDNS
May 05 18:31:45 unbound-default[1267:0] debug: close of port 31844
May 05 18:31:45 unbound-default[1267:0] debug: close fd 9
May 05 18:31:48 unbound-default[1267:0] debug: tcp error for address ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:48 unbound-default[1267:0] debug: svcd callbacks start
May 05 18:31:48 unbound-default[1267:0] debug: worker svcd callback for qstate 0x7fde48992690
May 05 18:31:48 unbound-default[1267:0] debug: mesh_run: start
May 05 18:31:48 unbound-default[1267:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
May 05 18:31:48 unbound-default[1267:0] info: iterator operate: query www.startpuntgeldzaken.nl. A IN
May 05 18:31:48 unbound-default[1267:0] debug: process_response: new external response event
May 05 18:31:48 unbound-default[1267:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
May 05 18:31:48 unbound-default[1267:0] debug: query response was timeout
May 05 18:31:48 unbound-default[1267:0] debug: iter_handle processing q with state QUERY TARGETS STATE
May 05 18:31:48 unbound-default[1267:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 18:31:48 unbound-default[1267:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 9
May 05 18:31:48 unbound-default[1267:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (1 result, 0 avail) parentNS
May 05 18:31:48 unbound-default[1267:0] debug: ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:48 unbound-default[1267:0] debug: ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:48 unbound-default[1267:0] debug: servselect ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:48 unbound-default[1267:0] debug: rtt=215
May 05 18:31:48 unbound-default[1267:0] debug: selrtt 215
May 05 18:31:48 unbound-default[1267:0] info: sending query: www.startpuntgeldzaken.nl. A IN
May 05 18:31:48 unbound-default[1267:0] debug: sending to target: <.> 149.112.112.112#53
May 05 18:31:48 unbound-default[1267:0] debug: dnssec status: not expected
May 05 18:31:48 unbound-default[1267:0] debug: EDNS lookup known=1 vs=0
May 05 18:31:48 unbound-default[1267:0] debug: serviced query UDP timeout=215 msec
May 05 18:31:48 unbound-default[1267:0] debug: inserted new pending reply id=a750
May 05 18:31:48 unbound-default[1267:0] debug: opened UDP if=0 port=51837
May 05 18:31:48 unbound-default[1267:0] debug: comm point start listening 9 (-1 msec)
May 05 18:31:48 unbound-default[1267:0] debug: mesh_run: iterator module exit state is module_wait_reply
May 05 18:31:48 unbound-default[1267:0] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 3 waiting replies, 2 recursion replies sent, 0 replies dropped, 0 states jostled out
May 05 18:31:48 unbound-default[1267:0] info: average recursion processing time 0.029573 sec
May 05 18:31:48 unbound-default[1267:0] info: histogram of recursion processing times
May 05 18:31:48 unbound-default[1267:0] info: [25%]=0 median[50%]=0 [75%]=0
May 05 18:31:48 unbound-default[1267:0] info: lower(secs) upper(secs) recursions
May 05 18:31:48 unbound-default[1267:0] info: 0.016384 0.032768 1
May 05 18:31:48 unbound-default[1267:0] info: 0.032768 0.065536 1
May 05 18:31:48 unbound-default[1267:0] info: 0RDd mod1 rep www.startpuntgeldzaken.nl. A IN
May 05 18:31:48 unbound-default[1267:0] debug: cache memory msg=296476 rrset=296684 infra=30866 val=296000
May 05 18:31:48 unbound-default[1267:0] debug: svcd callbacks end
May 05 18:31:48 unbound-default[1267:0] debug: answer cb
May 05 18:31:48 unbound-default[1267:0] debug: Incoming reply id = a750
May 05 18:31:48 unbound-default[1267:0] debug: Incoming reply addr = ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:48 unbound-default[1267:0] debug: lookup size is 1 entries
May 05 18:31:48 unbound-default[1267:0] debug: received udp reply.
May 05 18:31:48 unbound-default[1267:0] debug: udp message[974:0] A75083A000010007000000010377777712737461727470756E7467656C647A616B656E026E6C0000010001C00C00050001000000200018056E696275640A7472756570656F706C6505737061636500C00C002E00010000002000A9000507020000003C609C6C006080BC80706412737461727470756E7467656C647A616B656E026E6C009220FA364B3D0C7EB0B2DF564EB8F5F9B32334C39EC2CB54EE9EADA58600CEA226EF0AE897B51597065DFA773C8A07346996C91A38A903CF7D5E7D94323E2C4EBEBB66A8E1F6198B38F3373C90CF30D252814B4ABBC6D5603E1518DF9C90F88F293236EDC189EC6BB82B01AF2A95B855D95C2BE84643508F49E46697
May 05 18:31:48 unbound-default[1267:0] debug: udp message[974:256] 77C0A8BDC00C002E0001000000200129000508020000003C609C6C006080BC80F14B12737461727470756E7467656C647A616B656E026E6C0064C40C418346200F0BFFC403EF28F9FC5EE97F0EB3870437410B8D6B4AB1E1EE54AF73DF47751E5CF0F9B0040A095F44AC0B5CCD59F3D988D638C2563E52AC4EC60A50CC65991DF41986536A0FCF3DEBDE725B6061ED70CDEF6CEA694F94889291088FBA600CFBC3DC77DF5E24E0101494DF409DCA35BC05BB17328F2DDDB6363A4CE4F5AB2E1F653C0DFD9092B59EB5489C73691897B7D05B16C124A8F6940662FC66034C012D63ADDA484081CBC1EC27602D2988BF4B8C17628046F3680D4309652132014736
May 05 18:31:48 unbound-default[1267:0] debug: udp message[974:512] 16C01EA7AACA89D31A257172944E98B382416BA3C17C4B1DE3EFA28CCAF71610E4D7A1F98DF9DE1F828097D54BA133EDF748B63B85B198E331C0370005000100000110000E0B74702D6E696275642D3031C03DC037002E00010000011000A4000507030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500A19B70EDA2BFD27C98CD4239E6386617570CDF6CF1EC15E7053F97420A8B0973C22E25025315B504D482ABAFAFA90E6127C680A33AB3ECAD6AE8B51608E7E1B3FDE7BE4D24E6411C21EE99B41C9884FA4AEA88F874D0B18CDF3F77CFF96D50C27000FF23CF905D6CF23A9538F9C0269C6A8635100D0F93120CB8A7BFF2
May 05 18:31:48 unbound-default[1267:0] debug: udp message[974:768] 73730CC24500010001000001100004541663B0C245002E00010000011000A4000107030000012C609C6C006080BC809CA10A7472756570656F706C6505737061636500539B832E5A40E412A9B67DC7CB3E3353210CB5A453B63E22FFAC9AAF4648F90079275886E92BAE6989435140E18FC822F37287654A6C4651DAF720B096C3254E66DC282506001EFC0E7351AE5B3F1F9612FB0ACD564D181641C8162E1A25F66EC686069F670677F90A9F34AC2879CF6D7B800D16B8A9AA245AE9BA9A2BD8526E00002904D0000080000000
May 05 18:31:48 unbound-default[1267:0] debug: outnet handle udp reply
May 05 18:31:48 unbound-default[1267:0] debug: measured roundtrip at 24 msec
May 05 18:31:48 unbound-default[1267:0] debug: initiate TCP query EDNS
May 05 18:31:48 unbound-default[1267:0] debug: close of port 51837
May 05 18:31:48 unbound-default[1267:0] debug: close fd 9
May 05 18:31:51 unbound-default[1267:0] debug: tcp error for address ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:51 unbound-default[1267:0] debug: svcd callbacks start
May 05 18:31:51 unbound-default[1267:0] debug: worker svcd callback for qstate 0x7fde48992690
May 05 18:31:51 unbound-default[1267:0] debug: mesh_run: start
May 05 18:31:51 unbound-default[1267:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_noreply
May 05 18:31:51 unbound-default[1267:0] info: iterator operate: query www.startpuntgeldzaken.nl. A IN
May 05 18:31:51 unbound-default[1267:0] debug: process_response: new external response event
May 05 18:31:51 unbound-default[1267:0] debug: iter_handle processing q with state QUERY RESPONSE STATE
May 05 18:31:51 unbound-default[1267:0] debug: query response was timeout
May 05 18:31:51 unbound-default[1267:0] debug: iter_handle processing q with state QUERY TARGETS STATE
May 05 18:31:51 unbound-default[1267:0] info: processQueryTargets: www.startpuntgeldzaken.nl. A IN
May 05 18:31:51 unbound-default[1267:0] debug: processQueryTargets: targetqueries 0, currentqueries 0 sentcount 10
May 05 18:31:51 unbound-default[1267:0] info: DelegationPoint<.>: 0 names (0 missing), 2 addrs (0 result, 0 avail) parentNS
May 05 18:31:51 unbound-default[1267:0] debug: ip4 149.112.112.112 port 53 (len 16)
May 05 18:31:51 unbound-default[1267:0] debug: ip4 9.9.9.9 port 53 (len 16)
May 05 18:31:51 unbound-default[1267:0] debug: No more query targets, attempting last resort
May 05 18:31:51 unbound-default[1267:0] debug: configured stub or forward servers failed – returning SERVFAIL
May 05 18:31:51 unbound-default[1267:0] debug: store error response in message cache
May 05 18:31:51 unbound-default[1267:0] debug: return error response SERVFAIL
May 05 18:31:51 unbound-default[1267:0] debug: mesh_run: iterator module exit state is module_finished
May 05 18:31:51 unbound-default[1267:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone
May 05 18:31:51 unbound-default[1267:0] info: validator operate: query www.startpuntgeldzaken.nl. A IN
May 05 18:31:51 unbound-default[1267:0] debug: validator: nextmodule returned
May 05 18:31:51 unbound-default[1267:0] debug: cannot validate non-answer, rcode SERVFAIL
May 05 18:31:51 unbound-default[1267:0] debug: mesh_run: validator module exit state is module_finished
May 05 18:31:51 unbound-default[1267:0] debug: query took 20.839862 sec
May 05 18:31:51 unbound-default[1267:0] debug: query took 25.845004 sec
May 05 18:31:51 unbound-default[1267:0] debug: query took 30.844610 sec
May 05 18:31:51 unbound-default[1267:0] info: mesh_run: end 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 5 recursion replies sent, 0 replies dropped, 0 states jostled out
May 05 18:31:51 unbound-default[1267:0] info: average recursion processing time 15.517724 sec
May 05 18:31:51 unbound-default[1267:0] info: histogram of recursion processing times
May 05 18:31:51 unbound-default[1267:0] info: [25%]=0.04096 median[50%]=18.6667 [75%]=25.3333
May 05 18:31:51 unbound-default[1267:0] info: lower(secs) upper(secs) recursions
May 05 18:31:51 unbound-default[1267:0] info: 0.016384 0.032768 1
May 05 18:31:51 unbound-default[1267:0] info: 0.032768 0.065536 1
May 05 18:31:51 unbound-default[1267:0] info: 16.000000 32.000000 3
May 05 18:31:51 unbound-default[1267:0] debug: cache memory msg=296863 rrset=296684 infra=30866 val=296000
May 05 18:31:51 unbound-default[1267:0] debug: svcd callbacks end

Gerben Wierda (LinkedIn)
R&A Enterprise Architecture (main site)
Book: Chess and the Art of Enterprise Architecture
Book: Mastering ArchiMate

Olivier_Benghozi · May 5, 2021, 7:33pm

Seems to me that this domain has some transient issues, independent of Unbound:

% dig www.startpuntgeldzaken.nl @9.9.9.9

; <<>> DiG 9.10.6 <<>> www.startpuntgeldzaken.nl @9.9.9.9
;; global options: +cmd
;; connection timed out; no servers could be reached

% dig www.startpuntgeldzaken.nl @8.8.8.8

; <<>> DiG 9.10.6 <<>> www.startpuntgeldzaken.nl @8.8.8.8
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: SERVFAIL, id: 47521
;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 512
;; QUESTION SECTION:
;www.startpuntgeldzaken.nl. IN A

;; Query time: 61 msec
;; SERVER: 8.8.8.8#53(8.8.8.8)
;; WHEN: Wed May 05 21:29:40 CEST 2021
;; MSG SIZE rcvd: 54

Gerben_Wierda · May 5, 2021, 8:15pm

What I see is this (reliably)

When asking 8.8.8.8 or 9.9.9.9 directly, the name is resolved.

But when unbound forwards to 8.8.8.8 or 9.9.9.9, it fails.

hermione:~ gerben$ nslookup

server 8.8.8.8
Default server: 8.8.8.8
Address: 8.8.8.8#53
www.startpuntgeldzaken.nl
Server: 8.8.8.8
Address: 8.8.8.8#53

Non-authoritative answer:
www.startpuntgeldzaken.nl canonical name = nibud.truepeople.space.
nibud.truepeople.space canonical name = tp-nibud-01.truepeople.space.
Name: tp-nibud-01.truepeople.space
Address: 84.22.99.176

server 9.9.9.9
Default server: 9.9.9.9
Address: 9.9.9.9#53
www.startpuntgeldzaken.nl
Server: 9.9.9.9
Address: 9.9.9.9#53

Non-authoritative answer:
www.startpuntgeldzaken.nl canonical name = nibud.truepeople.space.
nibud.truepeople.space canonical name = tp-nibud-01.truepeople.space.
Name: tp-nibud-01.truepeople.space
Address: 84.22.99.176

server 192.168.2.86
Default server: 192.168.2.86
Address: 192.168.2.86#53
www.startpuntgeldzaken.nl
;; connection timed out; no servers could be reached

In other words: I can realiable ask 9.9.9.9 for www.startpuntgeldzaken.nl but I cannot get unbound to get that same info via a forward. See:

$ unbound-control lookup www.startpuntgeldzaken.nl
The following name servers are used for lookup of www.startpuntgeldzaken.nl.
forwarding request:
Delegation with 0 names, of which 0 can be examined to query further addresses.
It provides 2 IP addresses.
9.9.9.9 rto 103 msec, ttl 299, ping 35 var 17 rtt 103, tA 0, tAAAA 0, tother 0, EDNS 0 probed.
149.112.112.112 rto 92 msec, ttl 293, ping 28 var 16 rtt 92, tA 0, tAAAA 0, tother 0, EDNS 0 probed.

and

$ dig @9.9.9.9 www.startpuntgeldzaken.nl; dig @192.168.2.86 www.startpuntgeldzaken.nl

; <<>> DiG 9.10.6 <<>> @9.9.9.9 www.startpuntgeldzaken.nl
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 62765
;; flags: qr rd ra ad; QUERY: 1, ANSWER: 3, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1232
;; QUESTION SECTION:
;www.startpuntgeldzaken.nl. IN A

;; ANSWER SECTION:
www.startpuntgeldzaken.nl. 60 IN CNAME nibud.truepeople.space.
nibud.truepeople.space. 300 IN CNAME tp-nibud-01.truepeople.space.
tp-nibud-01.truepeople.space. 300 IN A 84.22.99.176

;; Query time: 36 msec
;; SERVER: 9.9.9.9#53(9.9.9.9)
;; WHEN: Wed May 05 22:11:32 CEST 2021
;; MSG SIZE rcvd: 132

; <<>> DiG 9.10.6 <<>> @192.168.2.86 www.startpuntgeldzaken.nl
; (1 server found)
;; global options: +cmd
;; connection timed out; no servers could be reached

It is that reliable difference between asking 9.9.9.9 (or 8.8.8.8, or 1.1.1.1) directly and doing the same via unbound that forwards that bothersd me. Direct always succeeds. Forward always fails.

Gerben Wierda (LinkedIn)
R&A Enterprise Architecture (main site)
Book: Chess and the Art of Enterprise Architecture
Book: Mastering ArchiMate

Gerben_Wierda · May 5, 2021, 8:23pm

What I see is this (reliably)

When asking 8.8.8.8 or 9.9.9.9 directly, the name is resolved.

But when unbound forwards to 8.8.8.8 or 9.9.9.9, it fails.

In other words: I can realiable ask 9.9.9.9 for www.startpuntgeldzaken.nl but I cannot get unbound to get that same info via a forward. See:

$ unbound-control lookup www.startpuntgeldzaken.nl
The following name servers are used for lookup of www.startpuntgeldzaken.nl.
forwarding request:
Delegation with 0 names, of which 0 can be examined to query further addresses.
It provides 2 IP addresses.
9.9.9.9 rto 103 msec, ttl 299, ping 35 var 17 rtt 103, tA 0, tAAAA 0, tother 0, EDNS 0 probed.
149.112.112.112 rto 92 msec, ttl 293, ping 28 var 16 rtt 92, tA 0, tAAAA 0, tother 0, EDNS 0 probed.

and

$ dig @9.9.9.9 www.startpuntgeldzaken.nl; dig @192.168.2.86 www.startpuntgeldzaken.nl

; <<>> DiG 9.10.6 <<>> @9.9.9.9 www.startpuntgeldzaken.nl
; (1 server found)
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 62765
;; flags: qr rd ra ad; QUERY: 1, ANSWER: 3, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1232
;; QUESTION SECTION:
;www.startpuntgeldzaken.nl. IN A

;; ANSWER SECTION:
www.startpuntgeldzaken.nl. 60 IN CNAME nibud.truepeople.space.
nibud.truepeople.space. 300 IN CNAME tp-nibud-01.truepeople.space.
tp-nibud-01.truepeople.space. 300 IN A 84.22.99.176

;; Query time: 36 msec
;; SERVER: 9.9.9.9#53(9.9.9.9)
;; WHEN: Wed May 05 22:11:32 CEST 2021
;; MSG SIZE rcvd: 132

; <<>> DiG 9.10.6 <<>> @192.168.2.86 www.startpuntgeldzaken.nl
; (1 server found)
;; global options: +cmd
;; connection timed out; no servers could be reached

It is that reliable difference between asking 9.9.9.9 (or 8.8.8.8, or 1.1.1.1) directly and doing the same via unbound that forwards that bothers me. Direct always succeeds. Forward always fails.

Gerben

jtodd · May 5, 2021, 9:04pm

(disclaimer: I work for Quad9.)

For clarification on this: Quad9 uses both unbound and PowerDNS recursor (and on some addresses, BIND) to serve queries so it is somewhat random which resolver may receive any particular attempt. I did however try manually to query unbound and PowerDNS recursor separately in our infrastructure, and both are able to resolve the domain in question from the POP in which my attempts were made, so I suspect this is a transient problem.

DNSViz shows nothing horribly wrong (https://dnsviz.net/d/www.startpuntgeldzaken.nl/dnssec/) but it is a wildcard entry with some minor warnings. This domain is served exclusively by TransIP.

Viktor Dukhovni mentioned in the DNS-OARC chat room today that “I’m now seeing poor results for DANE survey lookups of many .NL domains hosted by TransIP, with Google sometimes returning REFUSED and overall an atypically high SERVFAIL rate.” His remarks were in reference to DoT to auth servers, which Quad9 is currently not using, so I’m not sure if those are related issues, but it does seem that there are anecdotal problems with .nl domains and TransIP authoritative servers so that would be the path you may want to pursue first for additional debugging.

JT

Joe_Abley · May 5, 2021, 9:41pm

My instinct is that this has nothing to do with the domain name in question, nothing to do with what is happening at 8.8.8.8 or 9.9.9.9 and nothing to do with where that domain name is hosted.

I think if you look at the packets on the wire you will find either (a) the source address of upstream queries sent from your unbound instance is not reachable across the Internet, e.g. you're missing a NAT or you have multiple interfaces on the host running unbound, and the outbound interface is filtered or otherwise not as functional as you expect, or (b) you have firewall rules or other device permission constraints on the host running unbound that are different from what happens when you run dig.

If I'm wrong I'll buy you a beer the next time we are all allowed to meet in person.

Joe

Gerben_Wierda · May 5, 2021, 10:01pm

What I see is this (reliably)

When asking 8.8.8.8 or 9.9.9.9 directly, the name is resolved.

But when unbound forwards to 8.8.8.8 or 9.9.9.9, it fails.

In other words: I can realiable ask 9.9.9.9 for www.startpuntgeldzaken.nl but I cannot get unbound to get that same info via a forward.

My instinct is that this has nothing to do with the domain name in question, nothing to do with what is happening at 8.8.8.8 or 9.9.9.9 and nothing to do with where that domain name is hosted.

I think if you look at the packets on the wire you will find either (a) the source address of upstream queries sent from your unbound instance is not reachable across the Internet, e.g. you’re missing a NAT or you have multiple interfaces on the host running unbound, and the outbound interface is filtered or otherwise not as functional as you expect, or (b) you have firewall rules or other device permission constraints on the host running unbound that are different from what happens when you run dig.

Is this a possible scenario when for 99.9% of queries there is no problem at all? Basically, when I query for about everything else it just works.

If I’m wrong I’ll buy you a beer the next time we are all allowed to meet in person.

Hmmmmmm

I’ll buy you one (or two, three) if I find out what is happening here and we meet. Seriously, I would not even be able to receive your mail when my DNS was so horribly broken.

I ran this:

bash-3.2# unbound-control -c unbound-noforwarders.conf verbosity 4; dig @192.168.2.66 -p 1053 www.startpuntgeldzaken.nl; unbound-control -c unbound-noforwarders.conf verbosity 2

and it gives me a lot of debugging from my unbound instance that is doing no forwarding at all (I have a special nonforwarding instance listening at port 1053 especially for rspamd). I can share that with someone who understands it.

G

Joe_Abley · May 5, 2021, 10:10pm

Is this a possible scenario when for 99.9% of queries there is no problem at all? Basically, when I query for about everything else it just works.

Oh, well that's brand new information, or at least information that I managed not to read, earlier. Never mind, then!

If I'm wrong I'll buy you a beer the next time we are all allowed to meet in person.

Hmmmmmm

Yeah, I know, there is no more in-person. Those days are over.

Joe

Willy_Manga · May 6, 2021, 8:37am

Hi

Renaud_Allard · May 6, 2021, 8:43am

The domain you are testing uses DNSSEC with RSASHA256, you should probably enable do-tcp.

Jaap · May 6, 2021, 8:54am

Gerben Wierda via Unbound-users writes:
> <SNIP>
>
> $ dig @9.9.9.9 www.startpuntgeldzaken.nl; dig @192.168.2.86 =

Note the second dig. The address is a non-routable addres thus ...

> <SNIP>
>
> ; <<>> DiG 9.10.6 <<>> @192.168.2.86 www.startpuntgeldzaken.nl
> ; (1 server found)
> ;; global options: +cmd
> ;; connection timed out; no servers could be reached

...this server cannot be reached. Use a reachable server and try again.

jaap

PS. It seems that Joe Abley insticnt was right.

Gerben_Wierda · May 6, 2021, 9:25am

And that solved it. NAT, FW etc was not the issue. Turning do-tcp on makes resolving this domain work.

Ah. I was under the impression that I could have a setup that doesn’t do TCP at all, but it seems that these days, TCP is a requirement.

Basically, do-tcp must be a yes to be able to resolve the entire internet. do-tcp: no means some names will not resolve. And this will become worse over time. Setting do-tcp to no might come with a decent warning, then.

Thanks, all.

G

Gerben_Wierda · May 6, 2021, 9:53am

I use quad9 as it blocks resolving of bad guys. This is an extra protection measure.

G

Gerben_Wierda · May 6, 2021, 9:59am

Gerben Wierda via Unbound-users writes:

<SNIP>

$ dig @9.9.9.9 www.startpuntgeldzaken.nl; dig @192.168.2.86 =

Note the second dig. The address is a non-routable addres thus ...

No, that unbound is in fact running locally and can be reached fine.

<SNIP>

; <<>> DiG 9.10.6 <<>> @192.168.2.86 www.startpuntgeldzaken.nl
; (1 server found)
;; global options: +cmd
;; connection timed out; no servers could be reached

...this server cannot be reached. Use a reachable server and try again.

jaap

PS. It seems that Joe Abley insticnt was right.

No and yes. It was not a matter of routing and NAT/FW/etc. It was do-tcp set to no and upstream requirig TCP to deliver an answer. Unbound then tries to do TCP even if do-tcp is set to no and that times out. So, yes it has to do with TCP, but no it is not something that happens outside of unbound as Joe suggested.

As soon as I set do-tcp to yes, everything worked fine.

G

anandb · May 6, 2021, 10:37am

TCP has been a requirement for a long time.

Perhaps unbound should drop the "do-tcp" option altogether. I don't
really see a need to disable TCP, and providing such an option just
allows naive users to shoot themselves in the foot.

Regards,
Anand

Willy_Manga · May 6, 2021, 10:46am

.

Gerben_Wierda · May 6, 2021, 1:44pm

That is also a good option. It really surprised me as I did not know that TCP was a hard requirement for queries. In my old know how, TCP was for zone transfers, but not for queries, but I admit I never dove into it extremely deep. Naive, no, but lacking knowledge, yes (those are not the same...).

Joe_Abley · May 6, 2021, 1:48pm

This seems like a good opportunity to recommend this document, which was written precisely to address this kind of thing from an operational perspective:

https://tools.ietf.org/html/draft-ietf-dnsop-dns-tcp-requirements-07

I’m sure the authors would welcome feedback if you have any. It’s a good read, even if you don’t

Joe

Renaud_Allard · May 6, 2021, 2:02pm

The problem you have mainly lies within DNSSEC (especially when using non EC signatures). As DNS UDP datagrams are limited to 512 bytes (RFC1035), responses including DNSSEC security RRs have a high probability of resulting in a truncated response being returned and the resolver will be retrying the query using TCP.