SOFT_RESET requests may overlap and get stuck

[keeshux]

Summary

If both client and server initiate a SOFT_RESET at about the same time, the renegotiation may time out.

Steps to reproduce

Set the renegotiation interval for client and server to differ by 1 second. Connect and wait for SOFT_RESET, but bug occurrence depends on timing.

What is the current bug behavior?

Renegotiation times out and the VPN disconnects.

What is the expected correct behavior?

The VPN renegotiates a new key and stays connected.

Relevant logs and/or screenshots

19:15:53 - Renegotiating after 3600.0010030269623 seconds
19:15:53 - Send soft reset
19:15:53 - Negotiation key index is 2
19:15:53 - Control: Enqueued 1 packet [0]
19:15:53 - Control: Write control packet {SOFT_RESET_V1 | 2, sid: 56371b7a3f629a10, pid: 0, [0 bytes]}
19:15:53 - Send control packet (14 bytes): 1a56371b7a3f629a100000000000
19:15:53 - Control: Try read packet with code ACK_V1 and key 2
19:15:53 - Control: Read packet {ACK_V1 | 2, sid: 54bc53d5e0e824c0, acks: {[0], 56371b7a3f629a10}}
19:17:08 - Control: Try read packet with code HARD_RESET_SERVER_V2 and key 0
19:17:08 - Control: Read packet {HARD_RESET_SERVER_V2 | 0, sid: 0a318589291a2664, pid: 0}
19:17:08 - Send ack for received packetId 0
19:17:08 - Control: Write ack packet {ACK_V1 | 0, sid: 56371b7a3f629a10, acks: {[0], 0a318589291a2664}}
19:17:08 - Bad key in control packet (0 != 2)
19:17:08 - Ack successfully written to LINK for packetId 0
19:17:10 - Control: Try read packet with code HARD_RESET_SERVER_V2 and key 0
19:17:10 - Control: Read packet {HARD_RESET_SERVER_V2 | 0, sid: 0a318589291a2664, pid: 0}
19:17:10 - Send ack for received packetId 0
19:17:10 - Control: Write ack packet {ACK_V1 | 0, sid: 56371b7a3f629a10, acks: {[0], 0a318589291a2664}}
19:17:10 - Ack successfully written to LINK for packetId 0
19:17:14 - Control: Try read packet with code HARD_RESET_SERVER_V2 and key 0
19:17:14 - Control: Read packet {HARD_RESET_SERVER_V2 | 0, sid: 0a318589291a2664, pid: 0}
19:17:14 - Send ack for received packetId 0
19:17:14 - Control: Write ack packet {ACK_V1 | 0, sid: 56371b7a3f629a10, acks: {[0], 0a318589291a2664}}
19:17:14 - Ack successfully written to LINK for packetId 0
19:17:22 - Control: Try read packet with code HARD_RESET_SERVER_V2 and key 0
19:17:22 - Control: Read packet {HARD_RESET_SERVER_V2 | 0, sid: 0a318589291a2664, pid: 0}
19:17:22 - Send ack for received packetId 0
19:17:22 - Control: Write ack packet {ACK_V1 | 0, sid: 56371b7a3f629a10, acks: {[0], 0a318589291a2664}}
19:17:22 - Ack successfully written to LINK for packetId 0
19:17:38 - Control: Try read packet with code HARD_RESET_SERVER_V2 and key 0
19:17:38 - Control: Read packet {HARD_RESET_SERVER_V2 | 0, sid: 0a318589291a2664, pid: 0}
19:17:38 - Send ack for received packetId 0
19:17:38 - Control: Write ack packet {ACK_V1 | 0, sid: 56371b7a3f629a10, acks: {[0], 0a318589291a2664}}
19:17:38 - Ack successfully written to LINK for packetId 0
19:17:53 - Trigger shutdown (error: negotiationTimeout)
19:17:53 - Session did stop

Possible fixes suggested remediation

Prevent negotiation from overlapping/interleaving in case one is already in progress.