Hi Guys, Is anyone else experiencing intermittent DNS issues with bodybuilding.com? With verbosity set to 99, here's what I see in our logs: === Jan 06 12:59:37 unbound[16172:0] debug: remote control operation completed Jan 06 12:59:37 unbound[16172:0] debug: close fd 25 Jan 06 12:59:37 unbound[16172:1] debug: answer from the cache failed Jan 06 12:59:37 unbound[16172:1] debug: udp request from ip4 127.0.0.1 port 39580 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: mesh_run: start Jan 06 12:59:37 unbound[16172:1] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Jan 06 12:59:37 unbound[16172:1] info: validator operate: query <bodybuilding.com. ANY IN> Jan 06 12:59:37 unbound[16172:1] debug: validator: pass to next module Jan 06 12:59:37 unbound[16172:1] debug: mesh_run: validator module exit state is module_wait_module Jan 06 12:59:37 unbound[16172:1] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Jan 06 12:59:37 unbound[16172:1] debug: process_request: new external request event Jan 06 12:59:37 unbound[16172:1] debug: iter_handle processing q with state INIT REQUEST STATE Jan 06 12:59:37 unbound[16172:1] info: resolving <bodybuilding.com. ANY IN> Jan 06 12:59:37 unbound[16172:1] debug: request has dependency depth of 0 Jan 06 12:59:37 unbound[16172:1] debug: cache delegation returns delegpt Jan 06 12:59:37 unbound[16172:1] info: DelegationPoint<bodybuilding.com.>: 5 names (5 missing), 5 addrs (0 result, 5 avail) Jan 06 12:59:37 unbound[16172:1] info: ns4.bodybuilding.com. A Jan 06 12:59:37 unbound[16172:1] info: ns1.bodybuilding.com. A Jan 06 12:59:37 unbound[16172:1] info: ns3.bodybuilding.com. A Jan 06 12:59:37 unbound[16172:1] info: ns5.bodybuilding.com. A Jan 06 12:59:37 unbound[16172:1] info: ns2.bodybuilding.com. A Jan 06 12:59:37 unbound[16172:1] debug: ip4 208.80.124.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: ip4 208.80.127.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: ip4 208.80.126.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: ip4 208.94.148.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: ip4 208.80.125.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: iter_handle processing q with state INIT REQUEST STATE (stage 2) Jan 06 12:59:37 unbound[16172:1] info: resolving (init part 2): <bodybuilding.com. ANY IN> Jan 06 12:59:37 unbound[16172:1] debug: iter_handle processing q with state INIT REQUEST STATE (stage 3) Jan 06 12:59:37 unbound[16172:1] info: resolving (init part 3): <bodybuilding.com. ANY IN> Jan 06 12:59:37 unbound[16172:1] debug: iter_handle processing q with state QUERY TARGETS STATE Jan 06 12:59:37 unbound[16172:1] info: processQueryTargets: <bodybuilding.com. ANY IN> Jan 06 12:59:37 unbound[16172:1] debug: processQueryTargets: targetqueries 0, currentqueries 0 Jan 06 12:59:37 unbound[16172:1] info: DelegationPoint<bodybuilding.com.>: 5 names (5 missing), 5 addrs (0 result, 5 avail) Jan 06 12:59:37 unbound[16172:1] info: ns4.bodybuilding.com. A Jan 06 12:59:37 unbound[16172:1] info: ns1.bodybuilding.com. A Jan 06 12:59:37 unbound[16172:1] info: ns3.bodybuilding.com. A Jan 06 12:59:37 unbound[16172:1] info: ns5.bodybuilding.com. A Jan 06 12:59:37 unbound[16172:1] info: ns2.bodybuilding.com. A Jan 06 12:59:37 unbound[16172:1] debug: ip4 208.80.124.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: ip4 208.80.127.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: ip4 208.80.126.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: ip4 208.94.148.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: ip4 208.80.125.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: attempt to get extra 3 targets Jan 06 12:59:37 unbound[16172:1] debug: servselect ip4 208.94.148.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: rtt=201 Jan 06 12:59:37 unbound[16172:1] debug: servselect ip4 208.80.126.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: rtt=628 Jan 06 12:59:37 unbound[16172:1] debug: servselect ip4 208.80.127.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: rtt=632 Jan 06 12:59:37 unbound[16172:1] debug: servselect ip4 208.80.124.4 port 53 (len 16) Jan 06 12:59:37 unbound[16172:1] debug: rtt=619 Jan 06 12:59:37 unbound[16172:1] debug: Bad choices, trying to get more choice Jan 06 12:59:37 unbound[16172:1] debug: querying for next missing target Jan 06 12:59:37 unbound[16172:1] debug: out of query targets -- returning SERVFAIL Jan 06 12:59:37 unbound[16172:1] debug: store error response in message cache Jan 06 12:59:37 unbound[16172:1] debug: return error response SERVFAIL Jan 06 12:59:37 unbound[16172:1] debug: mesh_run: iterator module exit state is module_finished Jan 06 12:59:37 unbound[16172:1] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Jan 06 12:59:37 unbound[16172:1] info: validator operate: query <bodybuilding.com. ANY IN> Jan 06 12:59:37 unbound[16172:1] debug: validator: nextmodule returned Jan 06 12:59:37 unbound[16172:1] debug: cannot validate non-answer, rcode SERVFAIL Jan 06 12:59:37 unbound[16172:1] debug: mesh_run: validator module exit state is module_finished Jan 06 12:59:37 unbound[16172:1] debug: query took 0.000000 sec Jan 06 12:59:37 unbound[16172:1] info: mesh_run: end 1 recursion states (1 with reply, 0 detached), 33 waiting replies, 221508645 recursion replies sent, 0 replies dropped, 0 states jostled out Jan 06 12:59:37 unbound[16172:1] info: average recursion processing time 3.264751 sec Jan 06 12:59:37 unbound[16172:1] info: histogram of recursion processing times Jan 06 12:59:37 unbound[16172:1] info: [25%]=0.00063075 median[50%]=0.0491874 [75%]=0.124386 Jan 06 12:59:37 unbound[16172:1] info: lower(secs) upper(secs) recursions Jan 06 12:59:37 unbound[16172:1] info: 0.000000 0.000001 2546906 Jan 06 12:59:37 unbound[16172:1] info: 0.000002 0.000004 2 Jan 06 12:59:37 unbound[16172:1] info: 0.000004 0.000008 41028 Jan 06 12:59:37 unbound[16172:1] info: 0.000008 0.000016 7927 Jan 06 12:59:37 unbound[16172:1] info: 0.000016 0.000032 5838 Jan 06 12:59:37 unbound[16172:1] info: 0.000032 0.000064 1954651 Jan 06 12:59:37 unbound[16172:1] info: 0.000064 0.000128 1440477 Jan 06 12:59:37 unbound[16172:1] info: 0.000128 0.000256 688009 Jan 06 12:59:37 unbound[16172:1] info: 0.000256 0.000512 360727 Jan 06 12:59:37 unbound[16172:1] info: 0.000512 0.001024 28173322 Jan 06 12:59:37 unbound[16172:1] info: 0.001024 0.002048 14329361 Jan 06 12:59:37 unbound[16172:1] info: 0.002048 0.004096 5632398 Jan 06 12:59:37 unbound[16172:1] info: 0.004096 0.008192 1276142 Jan 06 12:59:37 unbound[16172:1] info: 0.008192 0.016384 6026449 Jan 06 12:59:37 unbound[16172:1] info: 0.016384 0.032768 7256098 Jan 06 12:59:37 unbound[16172:1] info: 0.032768 0.065536 2984875 Jan 06 12:59:37 unbound[16172:1] info: 0.065536 0.131072 1808063 Jan 06 12:59:37 unbound[16172:1] info: 0.131072 0.262144 96522535 Jan 06 12:59:37 unbound[16172:1] info: 0.262144 0.524288 26305628 Jan 06 12:59:37 unbound[16172:1] info: 0.524288 1.000000 5902840 Jan 06 12:59:37 unbound[16172:1] info: 1.000000 2.000000 4107265 Jan 06 12:59:37 unbound[16172:1] info: 2.000000 4.000000 4740679 Jan 06 12:59:37 unbound[16172:1] info: 4.000000 8.000000 3821946 Jan 06 12:59:37 unbound[16172:1] info: 8.000000 16.000000 1337149 Jan 06 12:59:37 unbound[16172:1] info: 16.000000 32.000000 759638 Jan 06 12:59:37 unbound[16172:1] info: 32.000000 64.000000 782507 Jan 06 12:59:37 unbound[16172:1] info: 64.000000 128.000000 1019874 Jan 06 12:59:37 unbound[16172:1] info: 128.000000 256.000000 1015930 Jan 06 12:59:37 unbound[16172:1] info: 256.000000 512.000000 477832 Jan 06 12:59:37 unbound[16172:1] info: 512.000000 1024.000000 159123 Jan 06 12:59:37 unbound[16172:1] info: 1024.000000 2048.000000 23345 Jan 06 12:59:37 unbound[16172:1] info: 2048.000000 4096.000000 81 Jan 06 12:59:37 unbound[16172:1] info: 0RDd mod1 rep <190.133.198.69.in-addr.arpa. PTR IN> Jan 06 12:59:37 unbound[16172:0] debug: new control connection from ip4 127.0.0.1 port 45700 (len 16) Jan 06 12:59:37 unbound[16172:0] debug: comm point stop listening 25 Jan 06 12:59:37 unbound[16172:0] debug: comm point start listening 25 Jan 06 12:59:37 unbound[16172:1] debug: cache memory msg=958398477 rrset=1916797124 infra=4299409 val=1088875 Jan 06 12:59:37 unbound[16172:0] debug: remote control connection authenticated Jan 06 12:59:37 unbound[16172:0] info: control cmd: verbosity 0 === Any ideas on what is happening? Delegation seems correct, domain doesn't seem to be misconfigured from what I can see. Thanks in advance. Regards, Haw -- Haw Loeung Systems Administrator TPG Internet http://www.tpg.com.au _______________________________________________________________________ -------------- next part -------------- A non-text attachment was scrubbed... Name: not available Type: application/pgp-signature Size: 490 bytes Desc: This is a digitally signed message part. URL: <http://unbound.nlnetlabs.nl/pipermail/unbound-users/attachments/20100106/b6bab9e4/attachment.pgp>