Project

General

Profile

Issue #1422

IKEv1: IKE_SA reauth vs. CHILD_SA rekey race prevents IKE_SA reauthentication in time

Added by Daniel Gollub over 4 years ago. Updated over 4 years ago.

Status:
Feedback
Priority:
Normal
Assignee:
-
Category:
libcharon
Affected version:
5.3.5
Resolution:

Description

With a very low ikelifetime (60s) and keylife (300s) (just for testing) I managed to hit this:

(grouped by threads)

Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 11[IKE] <peer-10.10.2.2-tunnel-vti|937> initiator did not reauthenticate as requested
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 11[IKE] <peer-10.10.2.2-tunnel-vti|937> reauthenticating IKE_SA peer-10.10.2.2-tunnel-vti[937] actively
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 11[IKE] <peer-10.10.2.2-tunnel-vti|937> initiating Main Mode IKE_SA peer-10.10.2.2-tunnel-vti[939] to 10.10.2.2
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 11[ENC] <peer-10.10.2.2-tunnel-vti|937> generating ID_PROT request 0 [ SA V V V V ]
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 11[NET] <peer-10.10.2.2-tunnel-vti|937> sending packet: from 10.10.2.3[500] to 10.10.2.2[500] (228 bytes)

Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[NET] <peer-10.10.2.2-tunnel-vti|939> received packet: from 10.10.2.2[500] to 10.10.2.3[500] (136 bytes)
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[ENC] <peer-10.10.2.2-tunnel-vti|939> parsed ID_PROT response 0 [ SA V V V ]
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[IKE] <peer-10.10.2.2-tunnel-vti|939> received XAuth vendor ID
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[IKE] <peer-10.10.2.2-tunnel-vti|939> received DPD vendor ID
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[IKE] <peer-10.10.2.2-tunnel-vti|939> received NAT-T (RFC 3947) vendor ID
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[ENC] <peer-10.10.2.2-tunnel-vti|939> generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[NET] <peer-10.10.2.2-tunnel-vti|939> sending packet: from 10.10.2.3[500] to 10.10.2.2[500] (372 bytes)
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 14[NET] <peer-10.10.2.2-tunnel-vti|938> received packet: from 10.10.2.2[500] to 10.10.2.3[500] (444 bytes)
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 14[ENC] <peer-10.10.2.2-tunnel-vti|938> parsed QUICK_MODE request 3053859028 [ HASH SA No KE ID ID ]
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 09[NET] <peer-10.10.2.2-tunnel-vti|939> received packet: from 10.10.2.2[500] to 10.10.2.3[500] (372 bytes)
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 09[ENC] <peer-10.10.2.2-tunnel-vti|939> parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 09[ENC] <peer-10.10.2.2-tunnel-vti|939> generating ID_PROT request 0 [ ID HASH ]
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 09[NET] <peer-10.10.2.2-tunnel-vti|939> sending packet: from 10.10.2.3[500] to 10.10.2.2[500] (76 bytes)
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 14[IKE] <peer-10.10.2.2-tunnel-vti|938> detected rekeying of CHILD_SA peer-10.10.2.2-tunnel-vti{28}
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 14[ENC] <peer-10.10.2.2-tunnel-vti|938> generating QUICK_MODE response 3053859028 [ HASH SA No KE ID ID ]
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 14[NET] <peer-10.10.2.2-tunnel-vti|938> sending packet: from 10.10.2.3[500] to 10.10.2.2[500] (444 bytes)

"Old" CHILD_SA {28} has state CHILD_REKEYING.

Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[NET] <peer-10.10.2.2-tunnel-vti|939> received packet: from 10.10.2.2[500] to 10.10.2.3[500] (76 bytes)
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[ENC] <peer-10.10.2.2-tunnel-vti|939> parsed ID_PROT response 0 [ ID HASH ]
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[IKE] <peer-10.10.2.2-tunnel-vti|938> detected reauth of existing IKE_SA, adopting 1 children and 0 virtual IPs
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[IKE] <peer-10.10.2.2-tunnel-vti|939> IKE_SA peer-10.10.2.2-tunnel-vti[939] established between 10.10.2.3[10.10.2.3]...10.10.2.2[10.10.2.2]
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[IKE] <peer-10.10.2.2-tunnel-vti|939> scheduling reauthentication in 5s
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 08[IKE] <peer-10.10.2.2-tunnel-vti|939> maximum IKE_SA lifetime 34s

Here only one child seems to get adopted by the IKE re-authentication (adopting from IKE_SA 938 to 939).

But there is a second CHILD_SA on thread 09 in preparation ... (CHILD_SA {29}) ... which is not getting adopted by IKE_SA 939:

Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 09[NET] <peer-10.10.2.2-tunnel-vti|938> received packet: from 10.10.2.2[500] to 10.10.2.3[500] (60 bytes)
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 09[ENC] <peer-10.10.2.2-tunnel-vti|938> parsed QUICK_MODE request 3053859028 [ HASH ]
Apr 12 22:42:13 vm-apr12vti-3 charon[2441]: 09[IKE] <peer-10.10.2.2-tunnel-vti|938> CHILD_SA peer-10.10.2.2-tunnel-vti{29} established with SPIs c5d368e0_i c44e8e51_o and TS 0.0.0.0/0 === 0.0.0.0/0

"Old" CHILD_SA {28}: expected: CHILD_REKEYED (?) / actual: still CHILD_REKEYING .. due to adoption earlier to the new IKE_SA 939.

"New" CHILD_SA {29}: expected: CHILD_INSTALLED (?) / ... and added to the old IKE_SA 938. I guess expected would be IKE_SA 939.

Apr 12 22:42:17 vm-apr12vti-3 charon[2441]: 15[NET] <peer-10.10.2.2-tunnel-vti|937> received packet: from 10.10.2.2[500] to 10.10.2.3[500] (92 bytes)
Apr 12 22:42:17 vm-apr12vti-3 charon[2441]: 15[ENC] <peer-10.10.2.2-tunnel-vti|937> parsed INFORMATIONAL_V1 request 448055613 [ HASH D ]
Apr 12 22:42:17 vm-apr12vti-3 charon[2441]: 15[IKE] <peer-10.10.2.2-tunnel-vti|937> received DELETE for IKE_SA peer-10.10.2.2-tunnel-vti[937]
Apr 12 22:42:17 vm-apr12vti-3 charon[2441]: 15[IKE] <peer-10.10.2.2-tunnel-vti|937> deleting IKE_SA peer-10.10.2.2-tunnel-vti[937] between 10.10.2.3[10.10.2.3]...10.10.2.2[10.10.2.2]
Apr 12 22:42:18 vm-apr12vti-3 charon[2441]: 14[IKE] <peer-10.10.2.2-tunnel-vti|939> unable to reauthenticate in CHILD_SA REKEYING state, delaying for 28s

"Old" CHILD_SA {28} I guess should be here in state CHILD_REKEYED. But seems to be still in state: CHILD_REKEYING

History

#1 Updated by Tobias Brunner over 4 years ago

  • Status changed from New to Feedback

Well, first, don't use IKEv1 if you don't absolutely need to (except for a gun to your head there should really be no valid reason to do so in this day and age).

Here only one child seems to get adopted by the IKE re-authentication (adopting from IKE_SA 938 to 939).

Yes, the CHILD_SA that's rekeyed by the other peer does not exist yet. And the Quick Mode task is not migrated (there is no point as the other peer would not suddenly send the third QM message on the new IKE_SA). And once the CHILD_SA is completed it does not get migrated. Depending on the timing the adopt_children job might catch it, but that runs pretty much immediately after the new IKE_SA is established, or the old IKE_SA is already deleted once the third QM message arrives - even though the deletion is delayed for 10s.

As can be seen in the last log excerpt, if the CHILD_SA rekeying is started before the reauthentication the latter gets blocked. But here it happens the other way around. I guess we could catch that by checking the IKE_SA state for IKE_REKEYING when processing the Quick Mode request, however, the IKEv1 protocol does not provide a way to properly handle that (e.g. like IKEv2's TEMPORARY_FAILURE notify). An option might be to try and migrate any remaining CHILD_SAs once the old IKE_SA is deleted. Or initiate a rekeying on the new IKE_SA for adopted CHILD_SAs in state CHILD_REKEYING.

Also available in: Atom PDF