Some more transient transmit errors have been observed. E.g. for some
peers transmission failed with
```
error: Os { code: 101, kind: Other, message: "Network is unreachable" }
```
That lead the endpoint to shut down and not process any messages for any
other clients.
To prevent this, this changes the behavior to ignore errors inside the endpoint.
In order to not lose all visibility, the change however adds low frequency
logging for the errors.
When the connection is closed while some ACKs are outstanding,
the peer might have a more pessimistic impression of what was actually
processed and e.g. report various requests that run to completion as failed.
To improve this, we send all pending ACKs as part of the
CONNECTION_CLOSE frame.
This change enables reporting ack delay to the peer, which will give the peer
a better estimate about actual path latency. The actual delay will later on be be
be determined between the time we first receive a packet and an event
(eg another packet or a timer) unblocked the ACK. This part is not yet implemented,
so the delay is 0 for now.
To enable sending ACK delay information, the default TransportParameters
has been changed to use a non 0 max ack delay value (since otherwise that
value will be picked up).
This also fixes a tiny bug where ack_delay wasn't considered in the path for
a RTT of 0ns.
When packets failed to transmit - e.g. due to being blocked by iptables - the
quinn endpoint kept them around and tried to retransmit them later on. This
usually failed for the same reason, which resulted in an infinitely growing list
of packets to transmit.
To prevent this, this change drops all packets where sending fails for a
a non-fatal reason.
The priority-based send state implementation had an issue where if returned
`self.can_send() == true` even if no data was available for sending.
This condition lead the `poll_transmit` method to initiate a transmission which
passed the ACK-only check since it assumed there was stream data to send.
However when trying to write stream frames no actual stream data could be
written.
The reason for this was that the `can_send()` condition only checked for the
length of the binary heap. However the length of this one was only reduced
in `write_stream_frames()` when the level was inspected the next time, and
not after data of one level was actually written.
This change fixes that, and drops the unused levels immediately after data
was written. There is on exception however: If only one level is left, it is
kept around and reused for future transmits to avoid deallocating and
reallocating the transmit queue continuously. However the `can_send` check
was updated to account for the empty level.
I also added some additional debug asserts which cross-checks
if an operation which announced to write more than just ACKs
still ended up only writing ACKs. That should make it easier to
determine similar issues in the future.
**Ack only transmissions in benchmark before change:** 1462
**Ack only transmissions in benchmark after change:** 45
As described in https://github.com/quinn-rs/quinn/issues/1082,
the current version of the anti-ampflication check is extremely strict
and usually only allows 2 outgoing datagrams to be sent during a handshake
due to rounding down.
This change relaxes the check to allow sending another datagram if any
anti-amplification budget is left. This method is used by a variety of
other implementations too.
Fixes#1082
This change adds a `WorkLimiter` component, which measures the amount of
time required to perform some work items and will limit work based on time
instead of pure iterations.
It also changes the `Endpoint`s `drive_recv` method to limit receive operations
based on the amount of spent time (to 50µs) using the `WorkLimiter`, instead
of using the hardcoded `IO_LOOP_BOUND` counter.
Performance differences are negligible on this machine (probably because
`IO_LOOP_BOUND` was set to a number which works for it), but it can improve
things on less known environments.
I instrumented the endpoints receive method to see how much time it spends
on average in `drive_recv`.
**Baseline:**
```
Recv time: AvgTime { total: 3.280880841s, calls: 34559, avg: 94.935µs, min: 3.146µs, max: 312.574µs }
path: PathStats {
rtt: 511.656µs,
```
**With this change:**
```
Recv time: AvgTime { total: 3.333642823s, calls: 54627, avg: 61.024µs, min: 2.645µs, max: 319.147µs }
path: PathStats {
rtt: 446.641µs,
```
Note that 50µs are not reached because a single `recvmmsg` batch takes about 30µs, so this is just rounding up to 2 batches.
**When set to 200µs (for comparison purposes):**
```
Recv time: AvgTime { total: 3.243954076s, calls: 19558, avg: 165.862µs, min: 2.525µs, max: 358.711µs }
path: PathStats {
rtt: 700.34µs,
}
```
The response body in those tests was never read. Therefore it was possible
for the test to drop the connection before the stream was actually read to
completion.
When path migration happened, the data received was accounted for
the old path, and provided the server less anti-amplification budget
to respond to the client.
By accessing path only after the first packet had been processed and
migration was initiated we make sure the new path gets the budget.
Creating datagrams using `poll_transmit` is rather CPU intensive,
and while doing that no other events can be handled (e.g. processing new
incoming ACKs). This change places an upper bound on the amount of
datagrams produced.
This significantly reduces RTT for a loopback connection since the connection
is no longer busy producing packets.
Raw throughput can be a bit slower since a lot more ACK packets are now
processed in the loopback test. However RTT is halfed. The difference
in ACK packets (7200 vs 83000) and RTT (800us vs 400us) is very
visible in the benchmark:
**Before:**
```
Overall stats:
Sent 1073741824 bytes on 1 streams in 1.70s (603.88 MiB/s)
Server connection stats:
ConnectionStats {
frame_tx: FrameStats {
ACK: 7199,
},
frame_rx: FrameStats {
ACK: 903129,
},
path: PathStats {
rtt: 459.755µs,
cwnd: 12320,
},
}
Client connection stats:
ConnectionStats {
frame_tx: FrameStats {
ACK: 903129,
},
frame_rx: FrameStats {
ACK: 7199,
},
path: PathStats {
rtt: 769.84µs,
cwnd: 1094264975,
},
}
```
**After:**
```
Sent 5389680640 bytes on 1 streams in 8.51s (603.90 MiB/s)
Server connection stats:
ConnectionStats {
frame_tx: FrameStats {
ACK: 83555,
},
frame_rx: FrameStats {
ACK: 4563602,
STREAM: 4562497,
},
path: PathStats {
rtt: 205.582µs,
cwnd: 12320,
},
}
Client connection stats:
ConnectionStats {
frame_tx: FrameStats {
ACK: 4563602,
STREAM: 4562497,
},
frame_rx: FrameStats {
ACK: 83555,
},
path: PathStats {
rtt: 393.448µs,
cwnd: 495821204,
},
}
```
This places a bound on the mount of events handled in `Endpoint::handle_events`.
It equals the amount of send events, because thats the upper limit
of packets that are transmitteable per iteration anyway.
As long as there is data to send or receive the `Endpoint` `Future`
will currently continue to execute and thereby retain the eventloop.
In order to allow other code to execute in between we yield back
to the executor after each iteration. Instead of doing mulitiple
iterations in one `EndpointDriver::poll` call we can just increase the
maximum amount of packets to send or receive in a single iteration
and pick a number which optimizes performance.
Therefore the loop gets completely removed.
The endpoint driver is currently utilizing a different behavior for transmits and receives:
- For receives it allows a certain number of datagrams to be received per Endpoint iteration
- For transmits it allows a certain number of transmit calls to be issued per Endpoint iteration.
Each transmit call can transmit up to `BATCH_SIZE` transmits. Those might
contain even more datagrams due to GSO.
This change unifies the behavior, and the bound will always limit the amount
of datagrams instead of `sendmsg/sendmmsg/recvmsg/recvmmsg` calls.
Given that a `sendmmsg` call for N datagrams is still roughly N times as
expensive as a sending a single datagram this makes sense.
The overall `IO_LOOP_BOUND` was adjusted to accomodate the new behavior.
`BATCH_SIZE` was modified to
When reading CIDs from packets the current code makes some short-lived
allocations due to the use of `copy_to_bytes`, which allocate for 1.5% of
CPU samples. This change avoids this.
**Before:**
```
Sent 1073741824 bytes on 1 streams in 1.72s (594.74 MiB/s)
```
**After:**
```
Sent 1073741824 bytes on 1 streams in 1.70s (602.78 MiB/s)
```
This seems slightly more efficient than extending a `Vec`.
Would probably be even more efficient if there would be an intersection
method on `SentMap` insert of returning packet numbers one by one.
Peak perf before:
```
Sent 1073741824 bytes on 1 streams in 1.77s (577.02 MiB/s)
```
After:
```
Sent 1073741824 bytes on 1 streams in 1.75s (584.25 MiB/s)
```
This change increases the amount of `CRYPTO` data sent in packets during handshakes.
Instead of reserving a fixed amount of 17 bytes for frame overhead,
we reserve the exactly required amount of bytes to encode frame type
and offset, and only 2 bytes for the frame length. This leads to an
additional 12-13 bytes of payload data being used.
The current implementation continously resizes the datagram buffer if
GSO is enabled and further datagrams are appended. Some benchmarking
and profiling showed that this doesn't have too much of an impact with
the glibc allocator, the strategy proved rather inefficient with pooling
memory allocators like jemalloc and mimalloc. For those, the cost of
calling `realloc` is rather high.
I benchmarked a bunch of strategies to determine the most efficient way forward:
1. Continously resize output buffer (Current approach)
2. Reserve maximum buffer size upfront
3. Reserve space for a single datagram to minimize over-allocation for
tiny transmits. If this is not enough, reallocate once for maximum size
Based on the results of those, I am proposing to go for approach 2) and
simply allocate the maximum buffer size upfront, which yields maximum
efficiency for mimalloc + jemalloc.
## Benchmark results
### Glibc:
Baseline:
> Sent 1073741824 bytes on 1 streams in 1.79s (572.62 MiB/s)
Allocate for 1 MTU, then for `max_datagrams`:
> Sent 1073741824 bytes on 1 streams in 1.78s (576.31 MiB/s)
Allocate for `max_datagrams` upfront:
> Sent 1073741824 bytes on 1 streams in 1.79s (572.28 MiB/s)
### Mimalloc:
Baseline:
> Sent 1073741824 bytes on 1 streams in 1.84s (557.34 MiB/s)
Allocate for 1 MTU, then for `max_datagrams`:
> Sent 1073741824 bytes on 1 streams in 1.74s (587.76 MiB/s)
Allocate for `max_datagrams` upfront:
> Sent 1073741824 bytes on 1 streams in 1.71s (600.06 MiB/s)
### Jemalloc:
Baseline:
> Sent 1073741824 bytes on 1 streams in 1.86s (551.75 MiB/s)
Allocate for 1 MTU, then for `max_datagrams`:
> Sent 1073741824 bytes on 1 streams in 1.73s (592.50 MiB/s)
Allocate for `max_datagrams` upfront:
> Sent 1073741824 bytes on 1 streams in 1.72s (596.29 MiB/s)
Wesley Rosenblum