AWS VPC Wizard connection - received DELETE for ESP CHILD_SA

harryw · Feb 3, 2016, 5:07 AM

Hi,

we just deployed a new pfSense 2.2.6 system and used the AWS VPC Wizard to establish two tunnels (including dynamic routing via bgp). Packets are flowing but further testing revealed intermittent drops (ping can lose several packets) that seem to be caused by a phase 2 SA being dropped and reestablished.

Others seem to have experienced similar issues and resolved it in one of two ways: switching to IKEv2 or disabling DPD. Unfortunately, neither is an option with AWS.

Based on the log below that covers such an intermittent drop, it appears that the AWS endpoint is requesting to delete the SA? But why!?

Has anyone seen such behavior - or should I better address this to the strongSwan mailing list?

Thanks & cheerio, Harry.


Feb 2 15:47:50	charon: 04[KNL] creating acquire job for policy *.*.*.*/32|/0 === *.*.*.*/32|/0 with reqid {2}
Feb 2 15:47:50	charon: 06[MGR] checkout IKE_SA by config
Feb 2 15:47:50	charon: 06[MGR] found existing IKE_SA 1 with a 'con2000' config
Feb 2 15:47:50	charon: 06[IKE] <con2000|1>queueing QUICK_MODE task
Feb 2 15:47:50	charon: 06[IKE] <con2000|1>activating new tasks
Feb 2 15:47:50	charon: 06[IKE] <con2000|1>activating QUICK_MODE task
Feb 2 15:47:50	charon: 06[ENC] <con2000|1>generating QUICK_MODE request 3659890304 [ HASH SA No KE ID ID ]
Feb 2 15:47:50	charon: 06[NET] <con2000|1>sending packet: from *.*.*.*[500] to *.*.*.*[500] (316 bytes)
Feb 2 15:47:50	charon: 06[MGR] <con2000|1>checkin IKE_SA con2000[1]
Feb 2 15:47:50	charon: 06[MGR] <con2000|1>check-in of IKE_SA successful.
Feb 2 15:47:50	charon: 06[MGR] checkout IKE_SA
Feb 2 15:47:50	charon: 06[MGR] IKE_SA con2000[1] successfully checked out
Feb 2 15:47:50	charon: 06[MGR] <con2000|1>checkin IKE_SA con2000[1]
Feb 2 15:47:50	charon: 06[MGR] <con2000|1>check-in of IKE_SA successful.
Feb 2 15:47:50	charon: 06[MGR] checkout IKE_SA by message
Feb 2 15:47:50	charon: 06[MGR] IKE_SA con2000[1] successfully checked out
Feb 2 15:47:50	charon: 06[NET] <con2000|1>received packet: from *.*.*.*[500] to *.*.*.*[500] (300 bytes)
Feb 2 15:47:50	charon: 06[ENC] <con2000|1>parsed QUICK_MODE response 3659890304 [ HASH SA No KE ID ID ]
Feb 2 15:47:50	charon: 06[CHD] <con2000|1>using AES_CBC for encryption
Feb 2 15:47:50	charon: 06[CHD] <con2000|1>using HMAC_SHA1_96 for integrity
Feb 2 15:47:50	charon: 06[CHD] <con2000|1>adding inbound ESP SA
Feb 2 15:47:50	charon: 06[CHD] <con2000|1>SPI 0xc18f91b9, src *.*.*.* dst *.*.*.*
Feb 2 15:47:50	charon: 06[CHD] <con2000|1>adding outbound ESP SA
Feb 2 15:47:50	charon: 06[CHD] <con2000|1>SPI 0x03ff1679, src *.*.*.* dst *.*.*.*
Feb 2 15:47:50	charon: 06[IKE] <con2000|1>CHILD_SA con2001{47} established with SPIs c18f91b9_i 03ff1679_o and TS *.*.*.*/24|/0 === *.*.*.*/16|/0
Feb 2 15:47:50	charon: 06[IKE] <con2000|1>reinitiating already active tasks
Feb 2 15:47:50	charon: 06[IKE] <con2000|1>QUICK_MODE task
Feb 2 15:47:50	charon: 06[ENC] <con2000|1>generating QUICK_MODE request 3659890304 [ HASH ]
Feb 2 15:47:50	charon: 06[NET] <con2000|1>sending packet: from *.*.*.*[500] to *.*.*.*[500] (60 bytes)
Feb 2 15:47:50	charon: 06[IKE] <con2000|1>activating new tasks
Feb 2 15:47:50	charon: 06[IKE] <con2000|1>nothing to initiate
Feb 2 15:47:50	charon: 06[MGR] <con2000|1>checkin IKE_SA con2000[1]
Feb 2 15:47:50	charon: 06[MGR] <con2000|1>check-in of IKE_SA successful.
Feb 2 15:47:50	charon: 04[MGR] checkout IKE_SA by message
Feb 2 15:47:50	charon: 04[MGR] IKE_SA con2000[1] successfully checked out
Feb 2 15:47:50	charon: 04[NET] <con2000|1>received packet: from *.*.*.*[500] to *.*.*.*[500] (76 bytes)
Feb 2 15:47:50	charon: 04[ENC] <con2000|1>parsed INFORMATIONAL_V1 request 836728501 [ HASH D ]
Feb 2 15:47:50	charon: 04[IKE] <con2000|1>received DELETE for ESP CHILD_SA with SPI 9fac1f02
Feb 2 15:47:50	charon: 04[IKE] <con2000|1>closing CHILD_SA con2000{45} with SPIs cc96a875_i (326 bytes) 9fac1f02_o (512 bytes) and TS 169.254.253.0/30|/0 === 169.254.253.0/30|/0
Feb 2 15:47:50	charon: 04[MGR] <con2000|1>checkin IKE_SA con2000[1]
Feb 2 15:47:50	charon: 04[MGR] <con2000|1>check-in of IKE_SA successful.
Feb 2 15:47:51	charon: 04[MGR] checkout IKE_SA
Feb 2 15:47:51	charon: 04[MGR] IKE_SA con2000[1] successfully checked out
Feb 2 15:47:51	charon: 04[MGR] <con2000|1>checkin IKE_SA con2000[1]
Feb 2 15:47:51	charon: 04[MGR] <con2000|1>check-in of IKE_SA successful.</con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1></con2000|1>

jimp · Feb 11, 2016, 7:46 PM

How many Phase 2 entries do you have?

IIRC AWS will only allow so many P2 entries (3, I think) and if you establish another one after that, they will disconnect one of the previous entries in exactly that fashion.

harryw · Feb 16, 2016, 10:31 PM

@jimp:

How many Phase 2 entries do you have?

IIRC AWS will only allow so many P2 entries (3, I think) and if you establish another one after that, they will disconnect one of the previous entries in exactly that fashion.

Hi,

I had since found the issue and that was in fact the problem. These symptoms are buried in this Amazon tech note https://aws.amazon.com/premiumsupport/knowledge-center/vpn-connection-instability/. Really difficult to track down because you don't have access to any logs on the AWS side…

Cheerio, Harry.