In article <gjdv84$5i...@sf1.isc.org>, David Porsche' <da...@from525.com> wrote: >All, > >I have installed a caching only instance of BIND (9.2.4) on a CentOS >machine on my internal network. I have noticed that initial DNS requests >against the server take a rather large amount of time (usually around 7 >seconds). I have done some basic troubleshooting and I am coming up at a >loss. I think my ISP might be doing something "funny" but I am not sure >how to test any further. > >I have captured BIND debug info at a trace level of 3 (posted bellow). I >have also captured snoop data via tcpdump. From what I can tell; it seems >as if responses are taking a "long" time to come back. The same behavior >is exhibited for any domain or host I attempt to lookup. > >To be clear, everything is working, just much slower than it should for >initial queries. Any help troubleshooting would be greatly appreciated.
I used to notice the same thing when I was running earlier versions of bind than I am now. I can't remember at which version the slowness disappeared, but I think that bind 9.4.* did not show the slowness. 9.2.4 is an ancient version considering that 9.6.0 was just released. I am running 9.5.1 here. > >BIND DEBUG DATA > >Dec 29 18:14:32.772 client: debug 3: client 192.168.1.136#48327: UDP request >Dec 29 18:14:32.772 security: debug 3: client 192.168.1.136#48327: request >is not signed >Dec 29 18:14:32.772 security: debug 3: client 192.168.1.136#48327: >recursion available: approved >Dec 29 18:14:32.772 client: debug 3: client 192.168.1.136#48327: query >Dec 29 18:14:32.772 security: debug 3: client 192.168.1.136#48327: query >(cache) approved >Dec 29 18:14:32.772 client: debug 3: client 192.168.1.136#48327: replace >Dec 29 18:14:32.772 general: debug 3: clientmgr @0x9b68380: createclients >Dec 29 18:14:32.772 general: debug 3: clientmgr @0x9b68380: recycle >Dec 29 18:14:32.772 resolver: debug 1: createfetch: speedr.com A >Dec 29 18:14:32.772 resolver: debug 3: fctx 0xb609e8a0: create >Dec 29 18:14:32.772 resolver: debug 3: fctx 0xb609e8a0: join >Dec 29 18:14:32.772 resolver: debug 3: fetch 0xb60368b8 (fctx 0xb609e8a0): >created >Dec 29 18:14:32.772 client: debug 3: client @0xb60710f8: udprecv >Dec 29 18:14:32.772 resolver: debug 3: fctx 0xb609e8a0: start >Dec 29 18:14:32.772 resolver: debug 3: fctx 0xb609e8a0: try >Dec 29 18:14:32.772 resolver: debug 3: fctx 0xb609e8a0: cancelqueries >Dec 29 18:14:32.772 resolver: debug 3: fctx 0xb609e8a0: getaddresses >Dec 29 18:14:32.773 resolver: debug 3: fctx 0xb609e8a0: query >Dec 29 18:14:32.773 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): send >Dec 29 18:14:32.773 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): sent >Dec 29 18:14:32.773 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): senddone >Dec 29 18:14:32.773 resolver: debug 3: fctx 0xb609e8a0: cancelquery >Dec 29 18:14:34.775 resolver: debug 3: fctx 0xb609e8a0: timeout >Dec 29 18:14:34.775 resolver: debug 3: fctx 0xb609e8a0: try >Dec 29 18:14:34.775 resolver: debug 3: fctx 0xb609e8a0: query >Dec 29 18:14:34.775 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): send >Dec 29 18:14:34.775 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): sent >Dec 29 18:14:34.775 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): senddone >Dec 29 18:14:34.775 resolver: debug 3: fctx 0xb609e8a0: cancelquery >Dec 29 18:14:36.776 resolver: debug 3: fctx 0xb609e8a0: timeout >Dec 29 18:14:36.776 resolver: debug 3: fctx 0xb609e8a0: try >Dec 29 18:14:36.776 resolver: debug 3: fctx 0xb609e8a0: query >Dec 29 18:14:36.776 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): send >Dec 29 18:14:36.776 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): sent >Dec 29 18:14:36.776 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): senddone >Dec 29 18:14:36.791 client: debug 3: client 192.26.92.30#53: UDP request >Dec 29 18:14:36.792 client: debug 3: client 192.26.92.30#53: next >Dec 29 18:14:36.792 client: debug 3: client 192.26.92.30#53: endrequest >Dec 29 18:14:36.792 client: debug 3: client @0xb60710f8: udprecv >Dec 29 18:14:36.792 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): response >Dec 29 18:14:36.792 resolver: debug 3: fctx 0xb609e8a0: noanswer_response >Dec 29 18:14:36.792 resolver: debug 3: fctx 0xb609e8a0: cache_message >Dec 29 18:14:36.792 resolver: debug 3: fctx 0xb609e8a0: cancelquery >Dec 29 18:14:36.792 resolver: debug 3: fctx 0xb609e8a0: cancelqueries >Dec 29 18:14:36.792 resolver: debug 3: fctx 0xb609e8a0: try >Dec 29 18:14:36.792 resolver: debug 3: fctx 0xb609e8a0: cancelqueries >Dec 29 18:14:36.792 resolver: debug 3: fctx 0xb609e8a0: getaddresses >Dec 29 18:14:36.792 resolver: debug 3: fctx 0xb609e8a0: query >Dec 29 18:14:36.792 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): send >Dec 29 18:14:36.792 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): sent >Dec 29 18:14:36.792 resolver: debug 3: resquery 0xb6094940 (fctx >0xb609e8a0): senddone >Dec 29 18:14:37.773 client: debug 3: client 192.168.1.136#48327: UDP request >Dec 29 18:14:37.773 security: debug 3: client 192.168.1.136#48327: request >is not signed >Dec 29 18:14:37.773 security: debug 3: client 192.168.1.136#48327: >recursion available: approved >Dec 29 18:14:37.773 client: debug 3: client 192.168.1.136#48327: query >Dec 29 18:14:37.773 security: debug 3: client 192.168.1.136#48327: query >(cache) approved >Dec 29 18:14:37.773 client: debug 3: client 192.168.1.136#48327: replace >Dec 29 18:14:37.773 general: debug 3: clientmgr @0x9b68380: createclients >Dec 29 18:14:37.773 general: debug 3: clientmgr @0x9b68380: recycle >Dec 29 18:14:37.773 resolver: debug 1: createfetch: speedr.com A >Dec 29 18:14:37.773 resolver: debug 3: fctx 0xb609e8a0: join >Dec 29 18:14:37.773 resolver: debug 3: fetch 0xb608e830 (fctx 0xb609e8a0): >created >Dec 29 18:14:37.773 client: debug 3: client @0xb6060ea0: udprecv >Dec 29 18:14:38.794 resolver: debug 3: fctx 0xb609e8a0: timeout >Dec 29 18:14:38.794 resolver: debug 3: fctx 0xb609e8a0: try >Dec 29 18:14:38.794 resolver: debug 3: fctx 0xb609e8a0: query >Dec 29 18:14:38.794 resolver: debug 3: resquery 0xb60e4298 (fctx >0xb609e8a0): send >Dec 29 18:14:38.794 resolver: debug 3: resquery 0xb60e4298 (fctx >0xb609e8a0): sent >Dec 29 18:14:38.794 resolver: debug 3: resquery 0xb60e4298 (fctx >0xb609e8a0): senddone >Dec 29 18:14:38.817 client: debug 3: client 128.121.3.72#53: UDP request >Dec 29 18:14:38.817 client: debug 3: client 128.121.3.72#53: next >Dec 29 18:14:38.817 client: debug 3: client 128.121.3.72#53: endrequest >Dec 29 18:14:38.817 client: debug 3: client @0xb6060ea0: udprecv >Dec 29 18:14:38.817 resolver: debug 3: resquery 0xb60e4298 (fctx >0xb609e8a0): response >Dec 29 18:14:38.817 resolver: debug 3: fctx 0xb609e8a0: answer_response >Dec 29 18:14:38.817 resolver: debug 3: fctx 0xb609e8a0: cache_message >Dec 29 18:14:38.817 resolver: debug 3: fctx 0xb609e8a0: cancelquery >Dec 29 18:14:38.817 resolver: debug 3: fctx 0xb609e8a0: done >Dec 29 18:14:38.817 resolver: debug 3: fctx 0xb609e8a0: stopeverything >Dec 29 18:14:38.817 resolver: debug 3: fctx 0xb609e8a0: cancelqueries >Dec 29 18:14:38.817 resolver: debug 3: fctx 0xb609e8a0: cancelquery >Dec 29 18:14:38.817 resolver: debug 3: fctx 0xb609e8a0: sendevents >Dec 29 18:14:38.817 resolver: debug 3: fetch 0xb60368b8 (fctx 0xb609e8a0): >destroyfetch >Dec 29 18:14:38.817 client: debug 3: client 192.168.1.136#48327: send >Dec 29 18:14:38.817 client: debug 3: client 192.168.1.136#48327: sendto >Dec 29 18:14:38.817 client: debug 3: client 192.168.1.136#48327: senddone >Dec 29 18:14:38.817 client: debug 3: client 192.168.1.136#48327: next >Dec 29 18:14:38.817 client: debug 3: client 192.168.1.136#48327: endrequest >Dec 29 18:14:38.817 resolver: debug 3: fetch 0xb608e830 (fctx 0xb609e8a0): >destroyfetch >Dec 29 18:14:38.817 resolver: debug 3: fctx 0xb609e8a0: shutdown >Dec 29 18:14:38.817 client: debug 3: client 192.168.1.136#48327: send >Dec 29 18:14:38.818 client: debug 3: client 192.168.1.136#48327: sendto >Dec 29 18:14:38.818 client: debug 3: client 192.168.1.136#48327: senddone >Dec 29 18:14:38.818 client: debug 3: client 192.168.1.136#48327: next >Dec 29 18:14:38.818 client: debug 3: client 192.168.1.136#48327: endrequest >Dec 29 18:14:38.818 resolver: debug 3: fctx 0xb609e8a0: doshutdown >Dec 29 18:14:38.818 resolver: debug 3: fctx 0xb609e8a0: stopeverything >Dec 29 18:14:38.818 resolver: debug 3: fctx 0xb609e8a0: cancelqueries >Dec 29 18:14:38.818 resolver: debug 3: fctx 0xb609e8a0: destroy >_______________________________________________ >bind-users mailing list >bind-users@lists.isc.org >https://lists.isc.org/mailman/listinfo/bind-users -- Tom Schulz sch...@adi.com _______________________________________________ bind-users mailing list bind-users@lists.isc.org https://lists.isc.org/mailman/listinfo/bind-users
