[sctp] Rare failure to establish connection

[spencercw]

I am running some load tests and have come across a rare case where SCTP fails to establish a connection. If I start 1000 PeerConnections in parallel, roughly 0.5% of the connections will fail in this way. I think the problem is down to packets being delivered out of order. The ChunkInit packet is received after the cookie exchange has already completed, resulting in an ErrHandleInitState error in AssociationInternal::handle_init. See trace log data below. Both sides of the connection are using webrtc-rs 0.7.1.

2023-03-03T18:11:52.087Z TRACE [webrtc_sctp::association::association_internal] [] updated cwnd=4380 ssthresh=0 inflight=0 (INI)
2023-03-03T18:11:52.087Z DEBUG [webrtc_sctp::association::association_internal] [] state change: 'Closed' => 'CookieWait'
2023-03-03T18:11:52.087Z DEBUG [webrtc_sctp::association::association_internal] [] sending INIT
2023-03-03T18:11:52.087Z DEBUG [webrtc_sctp::association] [] read_loop entered
2023-03-03T18:11:52.087Z DEBUG [webrtc_sctp::association] [] write_loop entered
2023-03-03T18:11:52.087Z DEBUG [webrtc_sctp::association] [] recving 76 bytes
2023-03-03T18:11:52.087Z DEBUG [webrtc_sctp::association::association_internal] [] chunkInitAck received in state 'CookieWait'
2023-03-03T18:11:52.087Z DEBUG [webrtc_sctp::association::association_internal] [] initial rwnd=1048576
2023-03-03T18:11:52.087Z TRACE [webrtc_sctp::association::association_internal] [] updated cwnd=4380 ssthresh=1048576 inflight=0 (INI)
2023-03-03T18:11:52.087Z DEBUG [webrtc_sctp::association::association_internal] [] use ForwardTSN (on initAck)
2023-03-03T18:11:52.087Z DEBUG [webrtc_sctp::association::association_internal] [] sending COOKIE-ECHO
2023-03-03T18:11:52.087Z DEBUG [webrtc_sctp::association::association_internal] [] state change: 'CookieWait' => 'CookieEchoed'
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association] [] recving 16 bytes
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association::association_internal] [] COOKIE-ACK received in state 'CookieEchoed'
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association::association_internal] [] state change: 'CookieEchoed' => 'Established'
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association] [] recving 40 bytes
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association::association_internal] [] chunkInit received in state 'Established'
2023-03-03T18:11:52.088Z WARN  [webrtc_sctp::association] [] failed to handle_inbound: ErrHandleInitState
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association::association_internal] [] state change: 'Established' => 'Closed'
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association::association_internal] [] closing association..
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association::association_internal] [] association closed
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association::association_internal] [] stats nDATAs (in) : 0
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association::association_internal] [] stats nSACKs (in) : 0
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association::association_internal] [] stats nT3Timeouts : 0
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association::association_internal] [] stats nAckTimeouts: 0
2023-03-03T18:11:52.088Z DEBUG [webrtc_sctp::association::association_internal] [] stats nFastRetrans: 0
2023-03-03T18:11:52.089Z DEBUG [webrtc_sctp::association] [] read_loop exited
2023-03-03T18:11:52.089Z DEBUG [webrtc_sctp::association] [] write_loop exited