Skip to content

TCP: readPrefixed uses conn.Read for the 2-byte length prefix and ignores the byte count #523

Description

@dotgerph

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)

Metadata

Metadata

Assignees

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions