What happens
readPrefixed in proxy/servertcp.go reads the 2-byte DNS-over-TCP length
prefix with a single conn.Read and discards the returned count:
func readPrefixed(conn net.Conn) (b []byte, err error) {
l := make([]byte, 2)
_, err = conn.Read(l) // <-- returns n == 1 if only one byte has arrived
if err != nil {
return nil, fmt.Errorf("reading len: %w", err)
}
packetLen := binary.BigEndian.Uint16(l)
...
b = make([]byte, packetLen)
_, err = io.ReadFull(conn, b) // <-- the payload read gets this right
...
}
TCP is a byte stream with no message boundaries, so a client is free to deliver
those two bytes in two segments. When that happens, conn.Read returns after
the first byte, l is [0x00, 0x00], packetLen becomes 0, the following
io.ReadFull returns immediately with an empty buffer, and req.Unpack fails
on the empty message:
[error] dnsproxy: handling tcp; unpacking msg err="bad header id: dns: overflow unpacking uint16"
The connection is then closed. Whether this happens is a race: if the
reading goroutine is scheduled before the second segment arrives, conn.Read
returns 1 byte and the query fails; if both bytes are already in the socket
buffer, it returns 2 and the very same query is served normally.
I caught both outcomes 2 ms apart, same client, same byte pattern:
# connection A - one prefix byte, then the payload -> failure
12:19:07.079750 192.168.2.1.55647 > .210.53: P. length 1 [DNS over TCP: length 1 < 2]
12:19:07.080203 log: handling tcp; unpacking msg err="bad header id: dns: overflow unpacking uint16"
12:19:07.080285 192.168.2.1.55647 > .210.53: P. length 36
12:19:07.080323 .210.53 > 192.168.2.1.55647: F. connection closed
# connection B, 0.9 ms later - identical split -> served
12:19:07.081939 192.168.2.1.48233 > .210.53: P. length 1 [DNS over TCP: length 1 < 2]
12:19:07.082285 192.168.2.1.48233 > .210.53: P. length 36
12:19:07.084082 .210.53 > 192.168.2.1.48233: P. length 53 1/0/0 A 0.0.0.0
Note that the payload read two lines further down already uses io.ReadFull —
only the prefix read does not. (Incidentally, tcpdump's own dissector makes the
same assumption per segment, which is why it prints prefix length(9175) != length(34) for the second segment.)
Reproducer
The sleep is what makes it deterministic — it guarantees losing the race
described above. Without it the same script fails only intermittently. The
query itself is valid and identical in both runs. Against AdGuard Home
v0.107.79 (which vendors dnsproxy), plain DNS on port 53:
import socket, struct, time
qname = b"\x06events\x06mapbox\x03com\x00"
msg = struct.pack(">HHHHHH", 0x1234, 0x0100, 1, 0, 0, 0) + qname + b"\x00\x01\x00\x01"
prefix = struct.pack(">H", len(msg))
s = socket.create_connection(("192.0.2.1", 53), timeout=5)
s.setsockopt(socket.IPPROTO_TCP, socket.TCP_NODELAY, 1)
s.sendall(prefix[:1]) # first prefix byte on its own
time.sleep(0.05) # force a separate segment
s.sendall(prefix[1:] + msg) # second prefix byte + payload
print(s.recv(2))
split prefix -> b'' connection closed, one "bad header id" line in the log
single sendall -> 51-byte answer, rcode=0
Suggested fix
io.ReadFull(conn, l) instead of conn.Read(l), matching what the payload
read already does.
How this shows up in practice
This is not a synthetic edge case. My consumer router — the DNS forwarder for
the whole LAN — writes the prefix separately as a matter of course, so every
one of its TCP queries enters the race. Losing it means a closed connection and
a retry, and since the retry usually goes through, nothing user-visible ever
breaks. What it does produce is log volume: on bad days tens of thousands of
lines, 56,415 in a single day at a steady ~5,000/hour around the clock, with
quiet weeks in between. The bursts line up with load, which fits a scheduling
race rather than a client that intermittently sends garbage.
Because nothing visibly breaks, this reads as harmless log noise, which I
suspect is why it tends to be attributed to the client. Some data points, in
case they save someone else the tcpdump session:
- Not an attack or a scan: 53/tcp, 853/tcp and 784/udp are not reachable from
the internet on my setup; the source is a LAN device.
- Resolution is not broken, so "does DNS still work?" does not catch it.
#198 reports the same code path (handling tcp; unpacking msg) with
dns: buffer size too small instead — that is the same bug with the prefix
split at a different offset, giving a different bogus packetLen. It was
answered with "it just means that an invalid query is written by the client".
I think that is worth revisiting: the query is well-formed, only its
segmentation is unusual — and segmentation is not something a client controls
or a receiver may assume.
- Related-looking issues such as AdGuardHome#8312, dnsproxy#282 and
dnsproxy#299 are about the UDP path and are, as far as I can tell, unrelated.
Environment
- dnsproxy as vendored in AdGuard Home v0.107.79 (also reproduced on v0.107.76)
- Linux arm64, Docker, Raspberry Pi
- Client: consumer router acting as a DNS forwarder, using DNS-0x20 case
randomisation (visible as eVEnts.MaPBox.COM in the capture)
What happens
readPrefixedinproxy/servertcp.goreads the 2-byte DNS-over-TCP lengthprefix with a single
conn.Readand discards the returned count:TCP is a byte stream with no message boundaries, so a client is free to deliver
those two bytes in two segments. When that happens,
conn.Readreturns afterthe first byte,
lis[0x00, 0x00],packetLenbecomes0, the followingio.ReadFullreturns immediately with an empty buffer, andreq.Unpackfailson the empty message:
The connection is then closed. Whether this happens is a race: if the
reading goroutine is scheduled before the second segment arrives,
conn.Readreturns 1 byte and the query fails; if both bytes are already in the socket
buffer, it returns 2 and the very same query is served normally.
I caught both outcomes 2 ms apart, same client, same byte pattern:
Note that the payload read two lines further down already uses
io.ReadFull—only the prefix read does not. (Incidentally, tcpdump's own dissector makes the
same assumption per segment, which is why it prints
prefix length(9175) != length(34)for the second segment.)Reproducer
The
sleepis what makes it deterministic — it guarantees losing the racedescribed above. Without it the same script fails only intermittently. The
query itself is valid and identical in both runs. Against AdGuard Home
v0.107.79 (which vendors dnsproxy), plain DNS on port 53:
Suggested fix
io.ReadFull(conn, l)instead ofconn.Read(l), matching what the payloadread already does.
How this shows up in practice
This is not a synthetic edge case. My consumer router — the DNS forwarder for
the whole LAN — writes the prefix separately as a matter of course, so every
one of its TCP queries enters the race. Losing it means a closed connection and
a retry, and since the retry usually goes through, nothing user-visible ever
breaks. What it does produce is log volume: on bad days tens of thousands of
lines, 56,415 in a single day at a steady ~5,000/hour around the clock, with
quiet weeks in between. The bursts line up with load, which fits a scheduling
race rather than a client that intermittently sends garbage.
Because nothing visibly breaks, this reads as harmless log noise, which I
suspect is why it tends to be attributed to the client. Some data points, in
case they save someone else the tcpdump session:
the internet on my setup; the source is a LAN device.
#198reports the same code path (handling tcp; unpacking msg) withdns: buffer size too smallinstead — that is the same bug with the prefixsplit at a different offset, giving a different bogus
packetLen. It wasanswered with "it just means that an invalid query is written by the client".
I think that is worth revisiting: the query is well-formed, only its
segmentation is unusual — and segmentation is not something a client controls
or a receiver may assume.
dnsproxy#299 are about the UDP path and are, as far as I can tell, unrelated.
Environment
randomisation (visible as
eVEnts.MaPBox.COMin the capture)