This error check was meant to terminate sendLoop and cause it to return
with the error from WriteTo. (Except for the special case where the
error is a net.Error that is also Temporary(), in which case we merely
logged the error and continued running sendLoop.)
Errors from WriteTo (whether Temporary() or not) were rare. I managed to
get one line this after several days' uptime on a server with heavy use:
sendLoop: write udp [::]:5300->X.X.X.X:YYYYY: sendto: operation not permitted
The above dnstt-server error was accompanied by a Linux kernel log
message:
nf_conntrack: nf_conntrack: table full, dropping packet
What happened is the conntrack table filled and failed to track the
state of some UDP exchanges. A UDP 4-tuple lost the RELATED state and
and outbound packet was blocked by the local firewall ("operation not
permitted").
This may not be the only way a non-Temporary() WriteTo error could
happen. But in any case, when one did happen, it would cause sendLoop to
return and the server to stop processing traffic. (Before
37129955de, this was especially bad,
because the return of sendLoop would not terminate the program: it would
keep running and receiving queries, but never send any responses. Now,
at least, the program terminates, so the failure is immediately
detectable.)
Now we simply log errors from WriteTo, as if they were always temporary.
The only exception is net.ErrClosed, which causes sendLoop to terminate
as before.
Background on the net.Error Temporary() pattern:
* "Use net.Error to distinguish temporary Accept errors."
https://gitlab.torproject.org/tpo/anti-censorship/pluggable-transports/goptlib/-/commit/3030f080eecf72b0e896236fca5fabd245c00bdb
* "Don't report errors that are not caused by Accept in AcceptSocks."
https://gitlab.torproject.org/tpo/anti-censorship/pluggable-transports/goptlib/-/commit/50b39b746c6ff34bf31977b658848d876ee84fbf
* https://go.dev/blog/error-handling-and-go#the-error-type
net.Error.Temporary was deprecated in go1.18:
* "net: deprecate Temporary error status"
https://github.com/golang/go/issues/45729
* https://go.dev/doc/go1.18#netpkgnet
See also:
* "net/http: server.Serve() uses deprecated net.Error.Temporary()"
https://github.com/golang/go/issues/66208
* "proposal: net: add ErrRetryableAcceptError"
https://github.com/golang/go/issues/66252
For now, though, even though I'm removing the Temporary() check on
WriteTo errors, I'm keeping it for KCP AcceptKCP and AcceptStream. It
may still be the right thing for an accept loop; cf.
https://groups.google.com/g/golang-nuts/c/-JcZzOkyqYI/m/wp_5G8LmAwAJ:
While the whole suite of Temporary errors isn't really coherent,
the issue is that a small subset of Temporary is still useful
for Accept loops and it doesn't have a non-deprecated
replacement. As a case in point, I presume that http.Server is
going to keep using Temporary indefinitely.
Without sendLoop, the program can no longer make progress. Treat
sendLoop and recvLoop as peer goroutines, instead of having recvLoop on
the main class stack and sendLoop as a goroutine.
Before go1.23, calling Stop, and draining the channel if the timer did
not already fire, is necessary before calling Reset:
https://pkg.go.dev/time@go1.22.12#Timer.Reset
This changed in go1.23: now Reset automatically effectively drains the
channel, and calling Stop is no longer necessary.
https://pkg.go.dev/time@go1.23.9#Timer.Reset
However, the changes in go1.23 only take effect if go.mod specifies
1.23 or later. We currently specify 1.21.
https://go.dev/doc/go1.23#timer-changes
For compatibility, do the Stop/drain procedure before calling Reset. We
were already doing this for pollTimer in DNSPacketConn) sendLoop in
dnstt-client.
This change may not have any observable effect. The duration we Reset
the timer to was 0, so if there had been a stale value in the channel
because of a failure to drain it, the effect would be the same as
waiting 0 seconds. We were already calling Stop when finished with the
timer, so it would have been garbage-collectable even before go1.23.
The dnstt-server log line "NXDOMAIN: not authoritative for %s" copied
bytes directly from an attacker-controlled DNS name to the log. Because
DNS labels may contain any byte values, this made possible various
injection attacks, for example:
* A label containing a newline byte could break the format of a log
file, or be used to inject false log lines.
* If the log output were going to a terminal (as it does by default), a
DNS name could affect the terminal by including escape sequences.
* A DNS label containing the dot character (\x2e) could give a
misleading impression of the contents of a query; for example the
names ["a" "example" "com"] and ["a\x2eexample" "com"] would both be
logged as "a.example.com".
The former ambiguity with the dot character might have confused the name
compressor in messageBuilder.WriteName, but I do not think any of
dnstt's uses of messageBuilder could have been affected.
The Name.String method now does backslash hex escaping of unusual bytes
in labels.
This vulnerability was called to mind by "Injection Attacks Reloaded:
Tunnelling Malicious Payloads over DNS" by Jeitner and Shulman. See
particularly Section 3.2 for \x2e injection.
https://www.usenix.org/conference/usenixsecurity21/presentation/jeitner
I was still getting "io: read/write on closed pipe" errors in the logs,
even after comparing errors against io.ErrClosedPipe to skip logging
them. It turns out that kcp-go wraps many of its errors in another type.
The actual type of the errors was *errors.withStack, where errors is
https://github.com/pkg/errors. We can use the go1.13 errors interface
(https://blog.golang.org/go1.13-errors) to get at the value inside.
This enlarges a few buffers and windows, with the goal of improving
download performance. kcp's SetWindowSize controls the number of
unacknowledged packets that are allowed. smux's MaxStreamBuffer is
another kind of "receive window" that is advertised to the peer of how
much we are willing to receive at once. The default MaxStreamBuffer is
64 KB, but kcptun overrides the default to 2 MB. turbotunnel's QueueSize
is the size of internal buffers in QueuePacketConn and RemoteMap;
empirically I found that the server would sometimes fill its outgoing
buffer if SetWindowSize and QueueSize were equal, so I set QueueSize to
be twice SetWindowSize.
https://lists.torproject.org/pipermail/anti-censorship-team/2021-July/000178.htmlhttps://gitlab.torproject.org/tpo/anti-censorship/pluggable-transports/snowflake/-/merge_requests/48
The changes have a large effect on a direct -udp connection without a
recursive resolver—which, however, is a discouraged configuration.
Through a recursive resolver, the improvements are more modest. If I
really crank up the buffer sizes, I can get surprisingly fast downloads
over a direct -udp connection (over 1 MB/s), but a connection through a
resolver doesn't keep getting faster and may even get slower. I want to
avoid a bufferbloat situation with oversized buffers, too. I manually
explored a small neighborhood of parameter values and picked some
settings that looked reasonable.
The tables below show the test results. The test is downloading 10 MiB
between two servers with 100 ms RTT between them. Server:
dnstt-server -udp :53 -privkey-file server.key t.example.com 127.0.0.1:9321
ncat -l -k -v 9321 --send-only --sh-exec 'dd bs=1M count=10 if=/dev/urandom'
Client:
dnstt-client -pubkey-file server.pub t.example.com 127.0.0.1:7000
ncat --recv-only 127.0.0.1 7000 | pv -t -r -a -b -i 0.2 > /dev/null
I did the download under every treatment twice and recorded the download
rate in KiB/s. "Server drops" comes from hacking some log messages to
turbotunnel.QueuePacketConn to track how often the "Drop the incoming
packet" (QueueIncoming method) and "Drop the outgoing packet" (WriteTo)
cases happen.
resolver method QueueSize MaxStreamBuffer SetWindowSize KiB/s KiB/s
-------- ------ --------- --------------- ------------- ----- -----
direct udp 64 64*1024 (32, 32) 169 173 (status before this commit)
dns.google udp 64 64*1024 (32, 32) 63.8 64.3 (status before this commit)
dns.google doh 64 64*1024 (32, 32) 125 122 (status before this commit)
resolver method QueueSize MaxStreamBuffer SetWindowSize KiB/s KiB/s
-------- ------ --------- --------------- ------------- ----- -----
direct udp 64 1*1024*1024 (32, 32) 172 174
dns.google udp 64 1*1024*1024 (32, 32) 57.3 58.4 server drops
dns.google doh 64 1*1024*1024 (32, 32) 128 128
resolver method QueueSize MaxStreamBuffer SetWindowSize KiB/s KiB/s
-------- ------ --------- --------------- ------------- ----- -----
direct udp 64 1*1024*1024 (64, 64) 322 305
dns.google udp 64 1*1024*1024 (64, 64) 72.5 70.9 server drops
dns.google doh 64 1*1024*1024 (64, 64) 136 139 server drops
resolver method QueueSize MaxStreamBuffer SetWindowSize KiB/s KiB/s
-------- ------ --------- --------------- ------------- ----- -----
direct udp 128 1*1024*1024 (64, 64) 321 325 (this commit)
dns.google udp 128 1*1024*1024 (64, 64) 82.5 78.5 (this commit)
dns.google doh 128 1*1024*1024 (64, 64) 129 131 (this commit)
resolver method QueueSize MaxStreamBuffer SetWindowSize KiB/s KiB/s
-------- ------ --------- --------------- ------------- ----- -----
direct udp 2048 4*1024*1024 (1024, 1024) 1240 1060 server drops
dns.google udp 2048 4*1024*1024 (1024, 1024) 73.5 81.4
dns.google doh 2048 4*1024*1024 (1024, 1024) 115 129
When the timer is expired, we want to continue packing as long as
additional packets are available with zero waiting. I'm not sure about
deferring the nextReq break, but we expect packet packing to be a quick
operation.
In my testing locally, these dials would time out after about 30 seconds
anyway:
2021/04/20 23:26:46 begin session 54cafb53
2021/04/20 23:26:47 begin stream 54cafb53:3
2021/04/20 23:27:19 stream 54cafb53:3 handleStream: stream 54cafb53:3 connect upstream: dial tcp X.X.X.X:YYYY: connect: connection timed out
2021/04/20 23:27:19 end stream 54cafb53:3
Which is in line with the documentation for net.Dialer:
https://golang.org/pkg/net/#Dialer
With or without a timeout, the operating system may impose its
own earlier timeout. For instance, TCP timeouts are often around
3 minutes.
But may as well be explicit.
This commit has the side effect of changing the error message from
"connection timed out" to "i/o timeout".
2021/04/20 23:28:08 begin session 05b0a46e
2021/04/20 23:28:09 begin stream 05b0a46e:3
2021/04/20 23:28:39 stream 05b0a46e:3 handleStream: stream 05b0a46e:3 connect upstream: dial tcp X.X.X.X:YYYY: i/o timeout
2021/04/20 23:28:39 end stream 05b0a46e:3
The usual use case for upstream is that it is a localhost IP address and
port, but it may also be a hostname and port. net.DialTCP resolves the
hostname once and for all, and only uses one of the hostname's IP
addresses if there are more than one. net.Dial will try all the IP
addresses in turn until it is able to establish a connection.
Now upstream is kept as a string variable all the way through the call
chain. For the sake of usability, we try resolving the address with
net.ResolveTCPAddr in main, to emit an error or warning right away,
rather than deferring it to the first stream.
This log line would formerly be emitted for a query with 0 questions:
FORMERR: too many questions (0)
The Nmap DNSStatusRequest probe is a query with 0 questions.
There was a logic error in the code. The nextP variable was used to
store the packet that was too big to pack into the most recent DNS
response. But nextP was not tied to any particular ClientID; instead it
would be sent to whatever client happened to be the recipient of the
next response.
The confusion didn't cause connections to fail completely; any
misdirected packets were treated as out-of-sequence garbage by KCP and
dropped. But it hurt performance a lot: I saw a download go from 300
KB/s to 50 KB/s just by connecting a second client with a different
ClientID (not even sending or receiving with the second client). The
reason is that a fraction of the packets intended for the downloading
client were instead sent to the idle client, which to the downloading
client looks like a packet drop, requiring a retransmission by the
server.
We fix it by placing the leftover packet in a per-ClientID stash, rather
than a variable shared by all ClientIDs.
I don't know what I was thinking in
f1ee951fd6. The way it was written, if
there were not immediately additional packets to pack into the
downstream, it would stop trying to pack and would instead wait until
the maxResponseDelay or another response to send. What I meant is that
the timer and the next-response channel should have priority, if either
of those is true *and* there is additional downstream available to pack.
Only when both of those are false should we try to pack downstream data.
The server would log "NXDOMAIN: 0 bytes are too short to contain a
ClientID" even in the common cases where it got an A or NS query from
the resolver (possibly from QNAME minimization).
Previously I had maxEncodedPayload hard-coded as a separate constant,
but it is completely dependent on maxUDPPayload. We compute it by
actually constructing wire-format packets and taking their length, which
should be less fragile than the formula I previously had commented,
though it requires some synchronization between the sendLoop and
computeMaxEncodedPayload functions.
Formerly this was split into two pieces: one that did the domain check
and set the AA bit, and another that checked the AA bit and returned an
error if it was not set. It was done in two parts because the check for
UDP payload size occurred in the middle. Since 59f03791 the payload
check is moved to the end, so we can do the authoritative domain check
in one piece.
smux Stream.WriteTo may return io.EOF, which breaks the contract of
io.Copy that says it should not return io.EOF. smux.Stream doesn't have
a unidirectional shutdown, so we always end up slamming it shut in both
directions and leave the other direction with a broken pipe.
Benjamin Erhart