Shutdown endpoint without waiting for full draining period

[colinmarc]

Websocket setup time (for the relay) can significantly influence the first RTT sample for the relay path. This affects both smoothed_rtt and rttvar, leading to inflated PTO calculation and slow teardown (possibly related to #3875).

The symptom I'm seeing is ~5s teardown on a short-lived, relatively high latency (100ms rtt) connection. Adding lots of print statements helped me realize that QUIC packets have send_time set at poll_transmit time, but this might not correspond with when the packet is actually sent, depending on the transport. However, the original (incorrect) send_time gets used to measure RTT.

For naked UDP, obviously, writes to the socket are going to happen pretty soon after the packet is created. But with Iroh's websocket transport, the initial packets seem to end up queued and therefore unacked for a long time (~200ms) before they actually get sent. Near as I can tell, this is because the websocket setup (TLS handshake) is still happening.

Here's an unscientific sample of my println debugging from today:

[pkt_sent] cid=e386b8ae47eb214f space=Initial pn=0 now=Instant { tv_sec: 1489788, tv_nsec: 391310583 } size=1200
[relay_send] dst=6200475a87aa253ccee51ff70b231fee890a3c00f59a30179152a9ae770047d9 len=1200 at Instant { tv_sec: 1489788, tv_nsec: 559251166 }
[rtt_sample] cid=e386b8ae47eb214f space=Initial path=PathId(0) sent_at=Instant { tv_sec: 1489788, tv_nsec: 391310583 } rtt=459.655458ms
<snip>
[set_close_timer] cid=e386b8ae47eb214f 3*pto=4.445353683s rtt=RttEstimator { latest:
 108.060125ms, smoothed: Some(415.706041ms), var: 260.26963ms, min: 108.060125ms }

You can see a ~170ms delay in between the first handshake packet and the first actual write over the websocket, and that delay gets added to the rtt measurement. Shortly afterwards, on disconnect, rttvar is very high because of that first sample, and rttvar ends up added 12x to the drain timeout.

From RFC 9002 6.2.1:

PTO = smoothed_rtt + max(4*rttvar, kGranularity) + max_ack_delay

And draining takes 3x PTO. All together, that looks suspiciously like the ~5s of draining that I'm seeing.

Iroh

Version:

0.97 (3d6e26b1182ecf63ce273793d44b3908117211e1)

[colinmarc]

I wanted to see if I could submit a fix for this, but it seems pretty gnarly.

• It seems like iroh::sockets::transport::Sender could return Poll::Pending for poll_send if the websocket is still being set up, but it just stuffs the packet into the channel for the RelayActor to send.
• However, even if it did, in noq, time_sent is set on the packet regardless of whether the packet is actually sendable on the socket yet, because those things are handled by different layers; noq-proto tracks the time sent, but noq buffers the actual datagram until the "socket" is writable.

https://github.com/n0-computer/noq/blob/98e626f6e0c42e7098b001d863b01323d954c27a/noq/src/connection.rs#L1511-L1514

[matheus23]

However, even if it did, in noq, time_sent is set on the packet regardless of whether the packet is actually sendable on the socket yet, because those things are handled by different layers; noq-proto tracks the time sent, but noq buffers the actual datagram until the "socket" is writable.

This is probably the closest thing to making this fixable: Figure out a way to get more accurate timing on when stuff was actually sent on the socket into noq-proto.
Not sure how we'd do that yet.

Thank you for investigating this!

[flub]

Ugh, yeah this is gnarly. I'm not sure how much can be done about this right now. It is not entirely wrong from from the view of the QUIC stack either, because this is the time it took for this packet to be ACKed. And the RTT speeding up later is fine as correction. But it is annoying for anything external that uses this RTT.

I can think of a whole bunch of future work that would make this possible, but that's so far in the future it's not even scheduled yet:

• Split off relay addressing in iroh to be per-endpoint-per-relay. Currently it is only per-endpoint-any-relay.
• Make noq itself aware of multiple transports, so that one transport can be pending while another can send stuff.
• If all that exists a relay transport that's not connected could return Pending and noq would not yet build/send the packet until it can actually do so.

Thanks for figuring this out btw! I never fully realised this was happening, but it totally is.

[matheus23]

As a temporary (hehe) workaround, could we perhaps instruct noq to ignore the draining period for the websocket/relay transport?
The reasoning here would be similar to what RFC9000 says about skipping draining when you can close sockets:

Endpoints that have some alternative means to ensure that late-arriving packets do not induce a response, such as those that are able to close the UDP socket, MAY end these states earlier to allow for faster resource recovery. Servers that retain an open socket for accepting new connections SHOULD NOT end the closing or draining state early.

Maybe we can ensure that there won't be any late-arriving packets when a relay connection is re-established somehow? This way, we could skip draining the relay transport at least.

[colinmarc]

Sorry if I'm missing something, but if I (as a client) intend to drop the Endpoint anyway, why should I have to wait for 3xPTO at all? The preceding paragraph seems to suggest that the drain period is to ensure that I don't send a stateless reset to any peers, but if I drop the Endpoint then that won't happen anyway, right?

[matheus23]

We don't know if you're going to re-create an Endpoint with the same port just shortly after, unfortunately.

The alternative is to make the user make this choice by exposing e.g. a close_quickly, or somehow making sure that an drop(endpoint) will do a best-effort AsyncUdpSocket::poll_send at least once to ensure you send CONNECTION_CLOSE out.
Then the user would simply either just drop the Endpoint without Endpoint::close, or they would call some kind of close_quickly that would send out the CONNECTION_CLOSE frame without waiting for the draining period.

[colinmarc]

I like the drop(endpoint) solution personally, because async cleanup is hard :) but it looks like noq spawns ConnectionDriver on a separate runtime task, which makes reaching into that task to do a poll_send().now_or_never() impossible afaict.

[matheus23]

noq::Endpoint contains an EndpointRef which in turn ends up storing a sender: Pin<Box<dyn UdpSender>> eventually.
In theory it's possible to make it call poll_send().now_or_never(), but that would need some careful consideration.

And the other question would be whether we'd want this last-minute Transmit to come from noq_proto::Connection::poll_transmit or some other way.