BIND ignores "packets received correctly"

Bernardo bernardo.pons at gmail.com
Sun Jan 10 13:33:23 UTC 2021


The problem of BIND ignoring "packets received correctly" has definitely
something to do with queries using UDP packets.

Here's an example:

# dig +nssearch EXAMPLE.COM
SOA ns1.DOMAIN.com. hostmaster.DOMAIN.com. 2021010707 3600 600 2419200 600
from server M.N.O.P in 3 ms.
SOA ns1.DOMAIN.com. hostmaster.DOMAIN.com. 2021010707 3600 600 2419200 600
from server Q.R.S.T in 3 ms.
SOA ns1.DOMAIN.com. hostmaster.DOMAIN.com. 2021010707 3600 600 2419200 600
from server U.V.W.X in 3 ms.
;; no response from A.B.C.D

Forcing queries to use TCP makes BIND not to ignore any QUERY (never)

# dig +tcp +nssearch EXAMPLE.COM
SOA ns1.DOMAIN.com. hostmaster.DOMAIN.com. 2021010707 3600 600 2419200 600
from server A.B.C.D in 0 ms.
SOA ns1.DOMAIN.com. hostmaster.DOMAIN.com. 2021010707 3600 600 2419200 600
from server E.F.G.H in 0 ms.
SOA ns1.DOMAIN.com. hostmaster.DOMAIN.com. 2021010707 3600 600 2419200 600
from server I.J.K.L in 0 ms.
SOA ns1.DOMAIN.com. hostmaster.DOMAIN.com. 2021010707 3600 600 2419200 600
from server M.N.O.P in 3 ms.
SOA ns1.DOMAIN.com. hostmaster.DOMAIN.com. 2021010707 3600 600 2419200 600
from server Q.R.S.T in 3 ms.
SOA ns1.DOMAIN.com. hostmaster.DOMAIN.com. 2021010707 3600 600 2419200 600
from server U.V.W.X in 3 ms.

Again, I would appreciate if anybody can help with this or give some hint.

<https://www.avast.com/sig-email?utm_medium=email&utm_source=link&utm_campaign=sig-email&utm_content=webmail>
Libre
de virus. www.avast.com
<https://www.avast.com/sig-email?utm_medium=email&utm_source=link&utm_campaign=sig-email&utm_content=webmail>
<#DAB4FAD8-2DD7-40BB-A1B8-4E2AA1F9FDF2>

El jue, 7 ene 2021 a las 16:56, - (<bernardo.pons at gmail.com>) escribió:

> Hi all,
>
> We are running BIND 9.16.6 DNS servers that are receiving queries from
> clients but randomly ignore "packets received correctly" as shown in this
> logs.
>
> When the DNS server answers the query, BIND is logging this:
>
> 30-Dec-2020 10:16:55.071 client: debug 3: client @0x7f9808000c80
> A.B.C.D#47290: UDP request
> 30-Dec-2020 10:16:55.071 client: debug 5: client @0x7f9808000c80
> A.B.C.D#47290: using view '_default'
> 30-Dec-2020 10:16:55.071 security: debug 3: client @0x7f9808000c80
> A.B.C.D#47290: request is not signed
> 30-Dec-2020 10:16:55.071 security: debug 3: client @0x7f9808000c80
> A.B.C.D#47290: recursion available
> 30-Dec-2020 10:16:55.071 queries: info: client @0x7f9808000c80
> A.B.C.D#47290 (EXAMPLE.COM): query: EXAMPLE.COM IN SOA -E(0)K (E.F.G.H)
> 30-Dec-2020 10:16:55.071 security: debug 3: client @0x7f9808000c80
> A.B.C.D#47290 (EXAMPLE.COM): query 'EXAMPLE.COM/SOA/IN' approved
> 30-Dec-2020 10:16:55.071 rate-limit: debug 99: client @0x7f9808000c80
> A.B.C.D#47290 (EXAMPLE.COM): rrl=0x7f9810365a20, HAVECOOKIE=0,
> result=ISC_R_SUCCESS, fname=0x7f9814d523d0(1), is_zone=1, RECURSIONOK=0,
> query.rpz_st=(nil)(0), RRL_CHECKED=0
> 30-Dec-2020 10:16:55.071 security: debug 3: client @0x7f9808000c80
> A.B.C.D#47290 (EXAMPLE.COM): reset client
>
> while TCPDUMP output (command "tcpdump -i eth0 port 53 -n -vvv") is
> showing this:
>
> A.B.C.D.47290 > E.F.G.H.53: [udp sum ok] 47783 [1au] SOA? EXAMPLE.COM.
> ar: . OPT UDPsize=4096 (49)
> E.F.G.H.53 > A.B.C.D.47290: [bad udp cksum 0x3f6d -> 0x7b61!] 47783* q:
> SOA? EXAMPLE.COM. 1/6/1 EXAMPLE.COM. [1h] SOA ns1.DOMAIN.COM.
> dns.DOMAIN.COM. 2020122901 3600 600 2419200 600 ns: EXAMPLE.COM. [1d] NS
> ns3.DOMAIN.NET., EXAMPLE.COM. [1d] NS ns2.DOMAIN.NET., EXAMPLE.COM. [1d]
> NS ns1.DOMAIN.COM., EXAMPLE.COM. [1d] NS ns3.DOMAIN.COM., EXAMPLE.COM.
> [1d] NS ns1.DOMAIN.NET., EXAMPLE.COM. [1d] NS ns2.DOMAIN.COM. ar: . OPT
> UDPsize=4096 (246)
>
> So far, everything's fine.
>
> But, when the DNS server doesn't answer the query, BIND is logging this:
>
> 30-Dec-2020 10:16:47.487 general: debug 60: socket 0x7f9815aa2178
> A.B.C.D#36113: packet received correctly
> 30-Dec-2020 10:16:48.487 general: debug 60: socket 0x7f9815aa2178
> A.B.C.D#36113: packet received correctly
> 30-Dec-2020 10:16:48.487 general: debug 60: socket 0x7f9815aa2178
> A.B.C.D#36113: packet received correctly
> 30-Dec-2020 10:16:49.491 general: debug 60: socket 0x7f9815aa2178
> A.B.C.D#36113: packet received correctly
>
> while TCPDUMP output is showing this:
>
> A.B.C.D.36113 > E.F.G.H.53: [udp sum ok] 13628 [1au] SOA? EXAMPLE.COM.
> ar: . OPT UDPsize=4096 (49)
> A.B.C.D.36113 > E.F.G.H.53: [udp sum ok] 13628 [1au] SOA? EXAMPLE.COM.
> ar: . OPT UDPsize=4096 (49)
> A.B.C.D.36113 > E.F.G.H.53: [udp sum ok] 13628 [1au] SOA? EXAMPLE.COM.
> ar: . OPT UDPsize=4096 (49)
> A.B.C.D.36113 > E.F.G.H.53: [udp sum ok] 13628 [1au] SOA? EXAMPLE.COM.
> ar: . OPT UDPsize=4096 (49)
>
> UDP packets received in both cases are the same but BIND randomly ignores
> them sometimes (causing the client to query again) and finally it never
> answers the query received in the first time.
>
> The host CPU, memory and NIC utilization are low so it's very unlikely
> that computing resource bottlenecks are causing packets to be dumped.
> In fact, command "netstat -suna" shows that apparently the host has no
> problem processing UDP packets.
>
> Udp:
>     1349954 packets received
>     27 packets to unknown port received
>     0 packet receive errors
>     631757 packets sent
>     0 receive buffer errors
>     0 send buffer errors
>
> It's a little bit surprising that "packet received correctly" is only
> being logged when things go wrong.
> The only place in the code that I've found where "packet received
> correctly" is being logged is here at socket.c
>
>         /*
>          * On TCP and UNIX sockets, zero length reads indicate EOF,
>          * while on UDP sockets, zero length reads are perfectly valid,
>          * although strange.
>          */
>         switch (sock->type) {
>         case isc_sockettype_tcp:
>         case isc_sockettype_unix:
>                 if (cc == 0) {
>                         return (DOIO_EOF);
>                 }
>                 break;
>         case isc_sockettype_udp:
>         case isc_sockettype_raw:
>                 break;
>         default:
>                 INSIST(0);
>                 ISC_UNREACHABLE();
>         }
>
>         if (sock->type == isc_sockettype_udp) {
>                 dev->address.length = msghdr.msg_namelen;
>                 if (isc_sockaddr_getport(&dev->address) == 0) {
>                         if (isc_log_wouldlog(isc_lctx, IOEVENT_LEVEL)) {
>                                 socket_log(sock, &dev->address, IOEVENT,
>                                            "dropping source port zero
> packet");
>                         }
>                         return (DOIO_SOFT);
>                 }
>                 /*
>                  * Simulate a firewall blocking UDP responses bigger than
>                  * 'maxudp' bytes.
>                  */
>                 if (sock->manager->maxudp != 0 &&
>                     cc > (int)sock->manager->maxudp) {
>                         return (DOIO_SOFT);
>                 }
>         }
>
>         socket_log(sock, &dev->address, IOEVENT, "packet received
> correctly");
>
>
> I'd rather avoid having to dive deeper in the code to understand what
> conditions can cause BIND to ignore "packets received correctly" that seems
> to happen when this socket_log function is called.
>
> I would appreciate if anybody can help with this or give some hint.
>
> Thank you,
>
> --
> Bernardo
>
>
> <https://www.avast.com/sig-email?utm_medium=email&utm_source=link&utm_campaign=sig-email&utm_content=webmail> Libre
> de virus. www.avast.com
> <https://www.avast.com/sig-email?utm_medium=email&utm_source=link&utm_campaign=sig-email&utm_content=webmail>
> <#m_393155279868745731_DAB4FAD8-2DD7-40BB-A1B8-4E2AA1F9FDF2>
>


-- 
Bernardo
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.isc.org/pipermail/bind-users/attachments/20210110/08f3fb19/attachment.htm>


More information about the bind-users mailing list