Bind dont forward to secondary dns server as specified in "forwarders" under named.options.conf

Question

I have bind9 setup to forward dns queries to machines connected localy trough the 192.168.1/24 network.

The ip's that I forward the queries to are also my internet gateways. Sometimes one of the gateways will loose its internet connection. bind will for some reason not forward the query to the second dns server.

Here are my named.options.conf

options {
        directory "/var/cache/bind";


        forwarders {
                192.168.7.17;192.168.7.16;
        };
        recursion yes;
        allow-recursion {any;};
        auth-nxdomain no;    # conform to RFC1035
        listen-on-v6 { any; };
        listen-on port 53 {any;};
        allow-query {any;};
        dnssec-validation no;

        # Expire negative answer ASAP.
        # i.e. Do not cache DNS query failure.
        max-ncache-ttl 3; # 3 seconds

       # Disable non-relevant operations
       allow-transfer { none; };
       allow-update-forwarding { none; };
       allow-notify { none; };
};

Here are tcpdump (simply "tcpdump -A" in the cli ) of everything on port53 on my machine. It shows that the dns query only is sent to 192.168.7.16 and not 192.168.7.17 in a case when I removed the WAN cable from 192.168.7.16:

16:26:29.238717 IP 192.168.7.1.34503 > 192.168.7.16.domain: 57293+% [1au] A? hostname.com. (41)
E..E....@.<Y...........5.1[..............hostname.com.......)........
16:26:29.240172 IP 192.168.7.16.domain > 192.168.7.1.34503: 57293 0/0/0 (41)
E..E..@[email protected].......)........

Here are named trace retrieved with "nrtpd trace 9" on a failed query to "hostname.com". Any suggestions how to force the query to move on to the secondary server in this case would be appreciated!

04-Dec-2014 16:23:25.417 client 127.0.0.1#36476: UDP request
04-Dec-2014 16:23:25.417 client 127.0.0.1#36476: using view '_default'
04-Dec-2014 16:23:25.417 client 127.0.0.1#36476: request is not signed
04-Dec-2014 16:23:25.417 client 127.0.0.1#36476: recursion available
04-Dec-2014 16:23:25.417 client 127.0.0.1#36476: query
04-Dec-2014 16:23:25.417 client 127.0.0.1#36476: query (cache) '107.103.225.122.in-addr.arpa/PTR/IN' approved
04-Dec-2014 16:23:25.417 client 127.0.0.1#36476: replace
04-Dec-2014 16:23:25.417 clientmgr @0xb75871e0: createclients
04-Dec-2014 16:23:25.417 clientmgr @0xb75871e0: recycle
04-Dec-2014 16:23:25.417 client @0xb4bee008: udprecv
04-Dec-2014 16:23:25.417 createfetch: 107.103.225.122.in-addr.arpa PTR
04-Dec-2014 16:23:25.417 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): create
04-Dec-2014 16:23:25.417 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): join
04-Dec-2014 16:23:25.417 fetch 0xb7568150 (fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR)): created
04-Dec-2014 16:23:25.417 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): start
04-Dec-2014 16:23:25.417 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): try
04-Dec-2014 16:23:25.417 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): cancelqueries
04-Dec-2014 16:23:25.418 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): getaddresses
04-Dec-2014 16:23:25.418 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): query
04-Dec-2014 16:23:25.418 resquery 0xb4dfc008 (fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR)): send
04-Dec-2014 16:23:25.418 resquery 0xb4dfc008 (fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR)): sent
04-Dec-2014 16:23:25.418 resquery 0xb4dfc008 (fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR)): udpconnected
04-Dec-2014 16:23:25.418 resquery 0xb4dfc008 (fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR)): senddone
04-Dec-2014 16:23:25.420 resquery 0xb4dfc008 (fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR)): response
04-Dec-2014 16:23:25.420 message has 11 byte(s) of trailing garbage
04-Dec-2014 16:23:25.420 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): noanswer_response
04-Dec-2014 16:23:25.420 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): ncache_message
04-Dec-2014 16:23:25.420 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): clone_results
04-Dec-2014 16:23:25.420 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): cancelquery
04-Dec-2014 16:23:25.420 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): done
04-Dec-2014 16:23:25.420 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): stopeverything
04-Dec-2014 16:23:25.420 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): cancelqueries
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f7fcc8
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f84008
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f7f2b0
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f7fdd8
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f7f008
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f84090
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f7fee8
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f7f448
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f7f1a0
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f7fbb8
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f7f4d0
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f7f338
04-Dec-2014 16:23:25.420 dns_adb_destroyfind on find 0xb4f7f118
04-Dec-2014 16:23:25.421 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): sendevents
04-Dec-2014 16:23:25.421 client 127.0.0.1#36476: send
04-Dec-2014 16:23:25.421 client 127.0.0.1#36476: sendto
04-Dec-2014 16:23:25.421 client 127.0.0.1#36476: senddone
04-Dec-2014 16:23:25.421 client 127.0.0.1#36476: next
04-Dec-2014 16:23:25.421 client 127.0.0.1#36476: endrequest
04-Dec-2014 16:23:25.421 fetch completed at resolver.c:6859 for 107.103.225.122.in-addr.arpa/PTR in 0.003287: success/success [domain:.,referral:0,restart:1,qrysent:1,timeout:0,lame:0,neterr:0,badresp:0,adberr:0,findfail:0,valfail:0]
04-Dec-2014 16:23:25.421 fetch 0xb7568150 (fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR)): destroyfetch
04-Dec-2014 16:23:25.421 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): shutdown
04-Dec-2014 16:23:25.421 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): doshutdown
04-Dec-2014 16:23:25.421 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): stopeverything
04-Dec-2014 16:23:25.421 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): cancelqueries
04-Dec-2014 16:23:25.421 fctx 0xb4df6008(107.103.225.122.in-addr.arpa/PTR'): destroy
04-Dec-2014 16:23:25.534 client 127.0.0.1#58196: UDP request
04-Dec-2014 16:23:25.535 client 127.0.0.1#58196: using view '_default'
04-Dec-2014 16:23:25.535 client 127.0.0.1#58196: request is not signed
04-Dec-2014 16:23:25.535 client 127.0.0.1#58196: recursion available
04-Dec-2014 16:23:25.535 client 127.0.0.1#58196: query
04-Dec-2014 16:23:25.535 client 127.0.0.1#58196: query (cache) 'hostname.com/A/IN' approved
04-Dec-2014 16:23:25.535 client 127.0.0.1#58196: replace
04-Dec-2014 16:23:25.535 clientmgr @0xb75871e0: createclients
04-Dec-2014 16:23:25.535 clientmgr @0xb75871e0: recycle
04-Dec-2014 16:23:25.535 client @0xb544f008: udprecv
04-Dec-2014 16:23:25.535 createfetch: hostname.com A
04-Dec-2014 16:23:25.535 fctx 0xb49e5008(hostname.com/A'): create
04-Dec-2014 16:23:25.536 fctx 0xb49e5008(hostname.com/A'): join
04-Dec-2014 16:23:25.536 fetch 0xb7568150 (fctx 0xb49e5008(hostname.com/A)): created
04-Dec-2014 16:23:25.536 fctx 0xb49e5008(hostname.com/A'): start
04-Dec-2014 16:23:25.536 fctx 0xb49e5008(hostname.com/A'): try
04-Dec-2014 16:23:25.536 fctx 0xb49e5008(hostname.com/A'): cancelqueries
04-Dec-2014 16:23:25.536 fctx 0xb49e5008(hostname.com/A'): getaddresses
04-Dec-2014 16:23:25.536 fctx 0xb49e5008(hostname.com/A'): query
04-Dec-2014 16:23:25.536 resquery 0xb49eb008 (fctx 0xb49e5008(hostname.com/A)): send
04-Dec-2014 16:23:25.537 resquery 0xb49eb008 (fctx 0xb49e5008(hostname.com/A)): sent
04-Dec-2014 16:23:25.537 resquery 0xb49eb008 (fctx 0xb49e5008(hostname.com/A)): udpconnected
04-Dec-2014 16:23:25.537 resquery 0xb49eb008 (fctx 0xb49e5008(hostname.com/A)): senddone
04-Dec-2014 16:23:25.538 resquery 0xb49eb008 (fctx 0xb49e5008(hostname.com/A)): response
04-Dec-2014 16:23:25.538 message has 11 byte(s) of trailing garbage
04-Dec-2014 16:23:25.538 fctx 0xb49e5008(hostname.com/A'): noanswer_response
04-Dec-2014 16:23:25.538 fctx 0xb49e5008(hostname.com/A'): ncache_message
04-Dec-2014 16:23:25.538 fctx 0xb49e5008(hostname.com/A'): clone_results
04-Dec-2014 16:23:25.538 fctx 0xb49e5008(hostname.com/A'): cancelquery
04-Dec-2014 16:23:25.538 fctx 0xb49e5008(hostname.com/A'): done
04-Dec-2014 16:23:25.539 fctx 0xb49e5008(hostname.com/A'): stopeverything
04-Dec-2014 16:23:25.539 fctx 0xb49e5008(hostname.com/A'): cancelqueries
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f7f338
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f84090
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f7f008
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f7f4d0
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f7fee8
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f7f2b0
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f7f118
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f7fdd8
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f7f1a0
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f7f448
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f7fbb8
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f84008
04-Dec-2014 16:23:25.539 dns_adb_destroyfind on find 0xb4f7fcc8
04-Dec-2014 16:23:25.539 fctx 0xb49e5008(hostname.com/A'): sendevents
04-Dec-2014 16:23:25.539 client 127.0.0.1#58196: send
04-Dec-2014 16:23:25.539 client 127.0.0.1#58196: sendto
04-Dec-2014 16:23:25.539 client 127.0.0.1#58196: senddone
04-Dec-2014 16:23:25.539 client 127.0.0.1#58196: next
04-Dec-2014 16:23:25.539 client 127.0.0.1#58196: endrequest
04-Dec-2014 16:23:25.540 fetch completed at resolver.c:6859 for hostname.com/A in 0.003534: success/success [domain:.,referral:0,restart:1,qrysent:1,timeout:0,lame:0,neterr:0,badresp:0,adberr:0,findfail:0,valfail:0]
04-Dec-2014 16:23:25.540 fetch 0xb7568150 (fctx 0xb49e5008(hostname.com/A)): destroyfetch
04-Dec-2014 16:23:25.540 fctx 0xb49e5008(hostname.com/A'): shutdown
04-Dec-2014 16:23:25.540 fctx 0xb49e5008(hostname.com/A'): doshutdown
04-Dec-2014 16:23:25.540 fctx 0xb49e5008(hostname.com/A'): stopeverything
04-Dec-2014 16:23:25.540 fctx 0xb49e5008(hostname.com/A'): cancelqueries
04-Dec-2014 16:23:25.540 fctx 0xb49e5008(hostname.com/A'): destroy

Answer 1

If a DNS server responds, then bind is usually happy. NXDOMAIN is NXDOMAIN, and that's an answer bind is content to use. I don't see in the logs exactly what response bind is getting back, but from the symptoms it seems that this is the case.

You may want to set up a scripted action on the gateway to turn off its DNS service if it loses WAN connection. That way, bind won't think everything is hunky-dory when it queries that server.

Answer 2

Hyppy is correct, your packet capture shows that the remote server responded. Whether that response is NXDOMAIN or a SERVFAIL, there is no need for BIND to continue. A retry will only be attempted in the event of total communication failure.

Honestly, if you're worried about one of your upstream connections dropping on you I'd just remove the forwarder statement entirely and let BIND perform its own recursion. So long as port 53 bidirectional is being allowed between that server and the internet, BIND will be perfectly happy with that configuration.