Getting hundreds of duplicating Phase2's on IPSEC VTI tunnels to AWS

ttblum · Sep 23, 2020, 9:40 PM

Hello,

Starting in the past year, all of my VTI tunnels from my pfSense routers to AWS have been getting intermittent periods of packet loss.

When the loss is happening I'm noticing hundreds of Phase2's listed for this connection in Status-->IPSec:

even though I only have 1 Phase2 configured for the tunnel:

The following is logged over and over:

Sep 23 14:25:01 myrouter charon: 09[IKE] <con3000|5478> sending DPD request
Sep 23 14:25:01 myrouter charon: 09[ENC] <con3000|5478> generating INFORMATIONAL request 456 [ ]
Sep 23 14:25:01 myrouter charon: 09[NET] <con3000|5478> sending packet: from my.ip.addr.ess[4500] to their.ip.addr.ess[4500] (80 bytes)
Sep 23 14:25:01 myrouter charon: 09[NET] <con3000|5478> received packet: from their.ip.addr.ess[4500] to my.ip.addr.ess[4500] (80 bytes)
Sep 23 14:25:01 myrouter charon: 09[ENC] <con3000|5478> parsed INFORMATIONAL response 456 [ ]
Sep 23 14:25:02 myrouter charon: 10[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:02 myrouter charon: 10[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:04 myrouter charon: 09[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:04 myrouter charon: 09[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:07 myrouter charon: 11[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:07 myrouter charon: 11[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:10 myrouter charon: 15[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:10 myrouter charon: 15[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:11 myrouter charon: 01[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:11 myrouter charon: 01[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:11 myrouter charon: 01[IKE] <con3000|5478> sending DPD request
Sep 23 14:25:11 myrouter charon: 01[ENC] <con3000|5478> generating INFORMATIONAL request 457 [ ]
Sep 23 14:25:11 myrouter charon: 01[NET] <con3000|5478> sending packet: from my.ip.addr.ess[4500] to their.ip.addr.ess[4500] (80 bytes)
Sep 23 14:25:11 myrouter charon: 01[NET] <con3000|5478> received packet: from their.ip.addr.ess[4500] to my.ip.addr.ess[4500] (80 bytes)
Sep 23 14:25:11 myrouter charon: 01[ENC] <con3000|5478> parsed INFORMATIONAL response 457 [ ]
Sep 23 14:25:13 myrouter charon: 06[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:13 myrouter charon: 06[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:16 myrouter charon: 10[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:16 myrouter charon: 10[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:18 myrouter charon: 09[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:18 myrouter charon: 09[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:21 myrouter charon: 12[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:21 myrouter charon: 12[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:21 myrouter charon: 12[IKE] <con3000|5478> sending DPD request
Sep 23 14:25:21 myrouter charon: 12[ENC] <con3000|5478> generating INFORMATIONAL request 458 [ ]
Sep 23 14:25:21 myrouter charon: 12[NET] <con3000|5478> sending packet: from my.ip.addr.ess[4500] to their.ip.addr.ess[4500] (80 bytes)
Sep 23 14:25:21 myrouter charon: 12[NET] <con3000|5478> received packet: from their.ip.addr.ess[4500] to my.ip.addr.ess[4500] (80 bytes)
Sep 23 14:25:21 myrouter charon: 12[ENC] <con3000|5478> parsed INFORMATIONAL response 458 [ ]
Sep 23 14:25:22 myrouter charon: 11[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:22 myrouter charon: 11[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:28 myrouter charon: 13[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:28 myrouter charon: 13[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:28 myrouter charon: 06[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:28 myrouter charon: 06[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:31 myrouter charon: 09[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:31 myrouter charon: 09[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:31 myrouter charon: 09[IKE] <con3000|5478> sending DPD request
Sep 23 14:25:31 myrouter charon: 09[ENC] <con3000|5478> generating INFORMATIONAL request 459 [ ]
Sep 23 14:25:31 myrouter charon: 09[NET] <con3000|5478> sending packet: from my.ip.addr.ess[4500] to their.ip.addr.ess[4500] (80 bytes)
Sep 23 14:25:31 myrouter charon: 09[NET] <con3000|5478> received packet: from their.ip.addr.ess[4500] to my.ip.addr.ess[4500] (80 bytes)
Sep 23 14:25:31 myrouter charon: 09[ENC] <con3000|5478> parsed INFORMATIONAL response 459 [ ]
Sep 23 14:25:33 myrouter charon: 09[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:33 myrouter charon: 09[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:34 myrouter charon: 08[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:34 myrouter charon: 08[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:38 myrouter charon: 14[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:38 myrouter charon: 14[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:40 myrouter charon: 06[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:40 myrouter charon: 06[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 out failed, not found
Sep 23 14:25:41 myrouter charon: 13[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:41 myrouter charon: 13[KNL] <con3000|5478> querying policy 0.0.0.0/0|/0 === 0.0.0.0/0|/0 in failed, not found
Sep 23 14:25:41 myrouter charon: 13[IKE] <con3000|5478> sending DPD request

I'm running 2.4.5-RELEASE .

Has anyone else seen anything like this?

jimp · Sep 24, 2020, 8:15 PM

https://redmine.pfsense.org/issues/10176

ttblum · Oct 7, 2020, 7:08 PM

OK, thanks.

As far as I can tell, the suggested settings are:

Enable 'Make-before-break' (VPN-->IPSec-->Advanced Settings tab) on both sides

OR -

Disable reauthentication and enable rekey -
Version 2.5.0: Leave reauth blank and put a value in rekey
Version 2.4.5: Check 'Disable Reauth'. Leave 'Disable Rekey' unchecked
On one side, Check 'Responder Only', and set 'Child SA Close Action' to 'Close/Clear'
On the other side, set 'Child SA close action' to 'Restart/Reconnect'

This patch would need to be applied to allow VTI tunnels to be set to Responder Only

Is this correct?

How would I apply these settings to an IPSec tunnel to AWS?