connection migration demo

[Rouzip]

Hello, I have read the demo code in quinn examples. And it just rebinds the address before web request. In the #1160 (comment), Ralith said A client implicitly migrates to whatever address it sends packets from. No manual action at the application layer is needed.. Can I migrate connection during web request? (rebind the client socket?)

[Ralith]

Yep! For typical use you shouldn't need to rebind anything, though it might make sense if you have a device with multiple simultaneously-valid WAN interfaces and you want the application to explicitly switch between them for some reason.

[Rouzip]

Yep! For typical use you shouldn't need to rebind anything, though it might make sense if you have a device with multiple simultaneously-valid WAN interfaces and you want the application to explicitly switch between them for some reason.

Yes, I want to switch multiple sockets explicitly. However, after rebind the socket, original send&receive stream cannot send/receive data.

server: 
Oct 21 21:58:48.351 ERROR proxy_test: connection failed: timed out
Oct 21 21:58:48.406 ERROR connection{remote=127.0.0.1:56844 protocol=hq-29}:request: proxy_test: failed: failed to send response: connection closed: timed out
^C

I found that connection was initialized by old address. And rebind function just changes endpoint inner socket, which means original connection and send/receive stream cannot reuse.
Any suggestions about my question? thanks!

[Ralith]

Outgoing connections/streams from an endpoint should not fail when that endpoint's socket is rebound so long as the remote server supports migration, which is the default. If this doesn't seem to be working for you, please share trace logs from both sides.

[Rouzip]

Outgoing connections/streams from an endpoint should not fail when that endpoint's socket is rebound so long as the remote server supports migration, which is the default. If this doesn't seem to be working for you, please share trace logs from both sides.

Sorry for late response. Based on the example code in quinn example, I added rebind function after a sleep.

    tokio::spawn(async move {
        sleep(Duration::from_millis(8000)).await;
        let new_socket = std::net::UdpSocket::bind("127.0.0.1:62213").unwrap();  // original port is 62212
        let addr = new_socket.local_addr().unwrap();
        eprintln!("rebinding to {}", addr);
        endpoint.rebind(new_socket).expect("rebind failed!");
    });

This is server log:

2021-10-29T03:30:37.042437Z TRACE drive{id=0}:send{space=Data pn=4898}: quinn_proto::connection: ACK ArrayRangeSet([72..74]), Delay = 0us
2021-10-29T03:30:37.042505Z TRACE drive{id=0}:send{space=Data pn=4898}: quinn_proto::connection::streams::state: STREAM id=client bidirectional stream 0 off=5628557 len=1157 fin=false
2021-10-29T03:30:37.042624Z TRACE drive{id=0}:send{space=Data pn=4899}: quinn_proto::connection: ACK ArrayRangeSet([72..74]), Delay = 0us
2021-10-29T03:30:37.042672Z TRACE drive{id=0}:send{space=Data pn=4899}: quinn_proto::connection::streams::state: STREAM id=client bidirectional stream 0 off=5629714 len=1157 fin=false
2021-10-29T03:30:37.042781Z TRACE drive{id=0}:send{space=Data pn=4900}: quinn_proto::connection: ACK ArrayRangeSet([72..74]), Delay = 0us
2021-10-29T03:30:37.042827Z TRACE drive{id=0}:send{space=Data pn=4900}: quinn_proto::connection::streams::state: STREAM id=client bidirectional stream 0 off=5630871 len=1157 fin=false
2021-10-29T03:30:37.042934Z TRACE drive{id=0}:send{space=Data pn=4901}: quinn_proto::connection: ACK ArrayRangeSet([72..74]), Delay = 0us
2021-10-29T03:30:37.042980Z TRACE drive{id=0}:send{space=Data pn=4901}: quinn_proto::connection::streams::state: STREAM id=client bidirectional stream 0 off=5632028 len=1157 fin=false
2021-10-29T03:30:37.043059Z TRACE drive{id=0}: quinn_proto::connection: sending 12000 bytes in 10 datagrams
2021-10-29T03:30:37.044365Z TRACE drive{id=0}:send{space=Data pn=4902}: quinn_proto::connection: ACK ArrayRangeSet([72..74]), Delay = 0us
2021-10-29T03:30:37.044448Z TRACE drive{id=0}:send{space=Data pn=4902}: quinn_proto::connection::streams::state: STREAM id=client bidirectional stream 0 off=5633185 len=303 fin=false
2021-10-29T03:30:37.044564Z TRACE drive{id=0}: quinn_proto::connection: sending 348 bytes in 1 datagrams
2021-10-29T03:30:37.044642Z TRACE drive{id=0}: quinn_proto::connection: timeout timer=Pacing
2021-10-29T03:30:37.044676Z TRACE drive{id=0}: quinn_proto::connection: pacing timer expired
2021-10-29T03:30:39.868020Z TRACE drive{id=0}: quinn_proto::connection: timeout timer=LossDetection
2021-10-29T03:30:39.868098Z TRACE drive{id=0}: quinn_proto::connection: PTO fired in_flight=1284348 count=0 space=Data
2021-10-29T03:30:39.868617Z TRACE drive{id=0}:send{space=Data pn=4903}: quinn_proto::connection: PING
2021-10-29T03:30:39.868671Z TRACE drive{id=0}:send{space=Data pn=4903}: quinn_proto::connection: ACK ArrayRangeSet([72..74]), Delay = 0us
2021-10-29T03:30:39.868807Z TRACE drive{id=0}: quinn_proto::connection: sending 38 bytes in 1 datagrams
2021-10-29T03:30:39.869208Z TRACE drive{id=0}:send{space=Data pn=4904}: quinn_proto::connection: PING
2021-10-29T03:30:39.869254Z TRACE drive{id=0}:send{space=Data pn=4904}: quinn_proto::connection: ACK ArrayRangeSet([72..74]), Delay = 0us
2021-10-29T03:30:39.869384Z TRACE drive{id=0}: quinn_proto::connection: sending 38 bytes in 1 datagrams
2021-10-29T03:30:45.515232Z TRACE drive{id=0}: quinn_proto::connection: timeout timer=LossDetection
2021-10-29T03:30:45.515322Z TRACE drive{id=0}: quinn_proto::connection: PTO fired in_flight=1284424 count=1 space=Data
2021-10-29T03:30:45.515830Z TRACE drive{id=0}:send{space=Data pn=4905}: quinn_proto::connection: PING
2021-10-29T03:30:45.515883Z TRACE drive{id=0}:send{space=Data pn=4905}: quinn_proto::connection: ACK ArrayRangeSet([72..74]), Delay = 0us
2021-10-29T03:30:45.516022Z TRACE drive{id=0}: quinn_proto::connection: sending 38 bytes in 1 datagrams
2021-10-29T03:30:45.516388Z TRACE drive{id=0}:send{space=Data pn=4906}: quinn_proto::connection: PING
2021-10-29T03:30:45.516432Z TRACE drive{id=0}:send{space=Data pn=4906}: quinn_proto::connection: ACK ArrayRangeSet([72..74]), Delay = 0us
2021-10-29T03:30:45.516533Z TRACE drive{id=0}: quinn_proto::connection: sending 38 bytes in 1 datagrams
2021-10-29T03:30:46.742345Z TRACE drive{id=0}: quinn_proto::connection: timeout timer=Idle
2021-10-29T03:30:46.742432Z TRACE drive{id=0}: quinn_proto::connection: connection closed
2021-10-29T03:30:46.742639Z ERROR server: connection failed: timed out
2021-10-29T03:30:46.779537Z ERROR connection{remote=127.0.0.1:62212 protocol=hq-29}:request: server: failed: failed to send response: connection closed: timed out
2021-10-29T03:30:47.303044Z DEBUG quinn_proto::endpoint: sending stateless reset for 1ef55343b6c45a7e to 127.0.0.1:62213
2021-10-29T03:30:47.304273Z DEBUG quinn_proto::endpoint: sending stateless reset for 1ef55343b6c45a7e to 127.0.0.1:62213

And this is part of client log(just the tail part):

2021-10-29T03:30:47.301566Z TRACE drive{id=0}: quinn_proto::connection: got Data packet (38 bytes) from 127.0.0.1:4433 using id 3ce795069c3f2612
2021-10-29T03:30:47.301649Z TRACE drive{id=0}:recv{space=Data pn=4906}: quinn_proto::connection: got frame Ping
2021-10-29T03:30:47.301743Z TRACE drive{id=0}:recv{space=Data pn=4906}: quinn_proto::connection: got frame Ack(Ack { largest: 73, delay: 0, ecn: Some(EcnCounts { ect0: 74, ect1: 0, ce: 0 }), ranges: "[72..=73]" })
2021-10-29T03:30:47.301872Z TRACE drive{id=0}:send{space=Data pn=74}: quinn_proto::connection: ACK ArrayRangeSet([3832..4907]), Delay = 0us
2021-10-29T03:30:47.301970Z TRACE drive{id=0}: quinn_proto::connection: sending 37 bytes in 1 datagrams
2021-10-29T03:30:47.303854Z TRACE drive{id=0}:send{space=Data pn=75}: quinn_proto::connection: ACK ArrayRangeSet([3832..4907]), Delay = 0us
2021-10-29T03:30:47.303934Z TRACE drive{id=0}:send{space=Data pn=75}: quinn_proto::connection::streams::state: MAX_STREAM_DATA stream=client bidirectional stream 0 max=5800233
2021-10-29T03:30:47.304031Z TRACE drive{id=0}: quinn_proto::connection: sending 43 bytes in 1 datagrams
2021-10-29T03:30:47.304530Z TRACE drive{id=0}: quinn_proto::connection: got Data packet (36 bytes) from 127.0.0.1:4433 using id 8357aa623db3c2c9
2021-10-29T03:30:47.305458Z TRACE drive{id=0}: quinn_proto::connection: decryption failed with packet number 2228646361
2021-10-29T03:30:47.305501Z DEBUG drive{id=0}: quinn_proto::connection: got stateless reset
2021-10-29T03:30:47.305536Z TRACE drive{id=0}: quinn_proto::connection: connection closed
2021-10-29T03:30:47.305579Z TRACE drive{id=0}: quinn_proto::connection: got Data packet (41 bytes) from 127.0.0.1:4433 using id 8d5d8b0a63ad89ec
2021-10-29T03:30:47.305621Z TRACE drive{id=0}: quinn_proto::connection: decryption failed with packet number 21167
2021-10-29T03:30:47.305647Z DEBUG drive{id=0}: quinn_proto::connection: got stateless reset
ERROR: failed to read response: read error: connection closed: reset by peer

It seems that I have rebind successfully? However, PTO fired made RST? Is my usage correct? If not, how can I use connection migration? Thanks!

[Ralith]

You're sleeping for 8 seconds, and the default idle timeout is 10 seconds. Is the client performing any other activity during that period, aside from waiting until it should rebind? A client that is inactive for 10 seconds for any reason will legitimately time out, unless a shorter keep_alive_interval has been set by either side.

If the client is sending no data itself but should be receiving data from the server, the server will not automatically become aware of the migration. If the client has a reasonable keep_alive_interval configured, this should resolve itself in due course; otherwise, you can get the server's attention by performing any transmit. We should probably do this automatically with a PING frame; I'll look into that, but in the meantime you can use Connection::send_datagram as a quick hack.

If neither of these accounts for your issue, please include client logs going back to at least its final transmit before sleeping and indicate when precisely the rebinding occurs, or alternatively provide complete code to reproduce the issue.

[Rouzip]

You're sleeping for 8 seconds, and the default idle timeout is 10 seconds. Is the client performing any other activity during that period, aside from waiting until it should rebind? A client that is inactive for 10 seconds for any reason will legitimately time out, unless a shorter keep_alive_interval has been set by either side.

If the client is sending no data itself but should be receiving data from the server, the server will not automatically become aware of the migration. If the client has a reasonable keep_alive_interval configured, this should resolve itself in due course; otherwise, you can get the server's attention by performing any transmit. We should probably do this automatically with a PING frame; I'll look into that, but in the meantime you can use Connection::send_datagram as a quick hack.

If neither of these accounts for your issue, please include client logs going back to at least its final transmit before sleeping and indicate when precisely the rebinding occurs, or alternatively provide complete code to reproduce the issue.

Yes, you are right. If I create new connection in the new address, I can rebind successfully. Thanks for your advise!

[Ralith]

To be clear, there is no requirement to create a new connection. The existing connection should migrate gracefully, so long it has reason to transmit something before the idle timeout period elapses.

[Ralith]

#1217 should resolve the suspected issue.