Handshake timeout

[ManickaP]

On the listener side, I receive a new connection (NEW_CONNECTION event), I set the callback handler via SetCallbackHandler and return success from the listener event. Now, I take time to search for a certificate and thus setting up the configuration, i.e. delaying call to ConnectionSetConfiguration.

I'd expected HandshakeIdleTimeoutMs (with 10s default) to kill the connection between SetCallbackHandler and ConnectionSetConfiguration, but it seems like the connection is sending frames every 0.25 seconds thus resetting the idle timeout.

Is this expected behavior? Is there any timeout to set the server side certificate for the connection?

[nibanks]

Please collect logs and share them.

[ManickaP]

msquic.log

[ManickaP]

It correlates with these events:

12:33:38.2079655[Info] sender: [api][0x7F40740039B0], message: MsQuicSafeHandle created
12:33:38.2094369[Info] sender: [list][0x7F40740DC470], message: MsQuicSafeHandle created
12:33:38.2138579[Info] sender: [conn][0x7F4074183C30], message: MsQuicSafeHandle created
12:33:38.2180476[Info] sender: [cfg][0x7F4078004E90], message: MsQuicSafeHandle created
12:33:38.2252379[Info] sender: [list][0x7F40740DC470], message: Received event NEW_CONNECTION
12:33:38.2265632[Info] sender: [conn][0x7F40380014C0], message: MsQuicSafeHandle created
12:33:38.2302990[Info] sender: [conn][0x7F40380014C0], message: Received event IDEAL_PROCESSOR_CHANGED

1 minute delay before providing certificate in SetConfiguration

12:34:38.2701784[Info] sender: [cfg][0x7F40B000A880], message: MsQuicSafeHandle created
12:34:38.2970453[Info] sender: [conn][0x7F4074183C30], message: Received event PEER_CERTIFICATE_RECEIVED
12:34:38.2973329[Info] sender: [conn][0x7F4074183C30], message: Received event STREAMS_AVAILABLE
12:34:38.2973671[Info] sender: [conn][0x7F4074183C30], message: Received event DATAGRAM_STATE_CHANGED
12:34:38.2973870[Info] sender: [conn][0x7F4074183C30], message: Received event CONNECTED
12:34:38.2982561[Info] sender: [conn][0x7F40380014C0], message: Received event CONNECTED
12:34:38.2986387[Info] sender: [conn][0x7F40380014C0], message: Received event SHUTDOWN_INITIATED_BY_PEER
12:34:38.2987095[Info] sender: [conn][0x7F40380014C0], message: Received event SHUTDOWN_COMPLETE
12:34:38.2987518[Info] sender: [conn][0x7F4074183C30], message: Received event SHUTDOWN_COMPLETE
12:34:38.2998421[Info] sender: [conn][0x7F40380014C0], message: MsQuicSafeHandle created
12:34:38.3004930[Info] sender: [cfg][0x7F40B000A880], message: MsQuicSafeHandle created
12:34:38.3013113[Info] sender: [conn][0x7F4074183C30], message: MsQuicSafeHandle created
12:34:38.3013326[Info] sender: [cfg][0x7F4078004E90], message: MsQuicSafeHandle created
12:34:38.3021933[Info] sender: [list][0x7F40740DC470], message: Received event STOP_COMPLETE
12:34:38.3023481[Info] sender: [list][0x7F40740DC470], message: MsQuicSafeHandle created

[nibanks]

The client continues to send packets because of the logic here. Essentially, the client needs to keep sending data to ensure the server has enough window not to be blocked by amplification protection. This does have the downside of the connection never going idle while in this state. I'm not sure of how to cause the connection to timeout here. Perhaps we should have a timer specifically for the length of the handshake. If it doesn't complete within the time limit we abandon.

[nibanks]

Or we don't reset the idle timer just because of initial packets.

[ManickaP]

Honestly, I don't know what the right behavior here is. I was surprised that it didn't timeout, but I think we can live with that (now that we know it) and set our own timer.