IPSec troubles
-
I think this is an issue with the pfSense…
Here's a partial debug trace of the pfSense trying to initiate a connection. The tunnel is down, and I try to ping a host in the remote subnet. This brings up phase 1 of the tunnel but not phase 2 (or whatever the IKEv2 terms are.)
IKEv2-PROTO-2: (153): Received Packet [From 1.2.3.4:4500/To 9.8.7.6:500/VRF i0:f0] (153): Initiator SPI : 8CE2615A4BA17050 - Responder SPI : 3A1657181A5F8FB2 Message id: 1 (153): IKEv2 IKE_AUTH Exchange REQUESTIKEv2-PROTO-3: (153): Next payload: ENCR, version: 2.0 (153): Exchange type: IKE_AUTH, flags: INITIATOR (153): Message id: 1, length: 464(153): Payload contents: (153): REAL Decrypted packet:(153): Data: 376 bytes (153): IDi(153): Next payload: NOTIFY, reserved: 0x0, length: 12 (153): Id type: IPv4 address, Reserved: 0x0 0x0 (153): (153): b8 45 a9 a2 (153): NOTIFY(INITIAL_CONTACT)(153): Next payload: IDr, reserved: 0x0, length: 8 (153): Security protocol id: Unknown - 0, spi size: 0, type: INITIAL_CONTACT (153): IDr(153): Next payload: AUTH, reserved: 0x0, length: 12 (153): Id type: IPv4 address, Reserved: 0x0 0x0 (153): (153): a2 d4 ca 7e (153): AUTH(153): Next payload: NOTIFY, reserved: 0x0, length: 72 (153): Auth method PSK, reserved: 0x0, reserved 0x0 (153): Auth data: 64 bytes (153): NOTIFY(ESP_TFC_NO_SUPPORT)(153): Next payload: SA, reserved: 0x0, length: 8 (153): Security protocol id: Unknown - 0, spi size: 0, type: ESP_TFC_NO_SUPPORT (153): SA(153): Next payload: TSi, reserved: 0x0, length: 156 (153): last proposal: 0x2, reserved: 0x0, length: 40 Proposal: 1, Protocol id: ESP, SPI size: 4, #trans: 3(153): last transform: 0x3, reserved: 0x0: length: 12 type: 1, reserved: 0x0, id: AES-CBC (153): last transform: 0x3, reserved: 0x0: length: 8 type: 3, reserved: 0x0, id: SHA96 (153): last transform: 0x0, reserved: 0x0: length: 8 type: 5, reserved: 0x0, id: Don't use ESN (153): last proposal: 0x2, reserved: 0x0, length: 40 Proposal: 2, Protocol id: ESP, SPI size: 4, #trans: 3(153): last transform: 0x3, reserved: 0x0: length: 12 type: 1, reserved: 0x0, id: AES-CBC (153): last transform: 0x3, reserved: 0x0: length: 8 type: 3, reserved: 0x0, id: SHA512 (153): last transform: 0x0, reserved: 0x0: length: 8 type: 5, reserved: 0x0, id: Don't use ESN (153): last proposal: 0x2, reserved: 0x0, length: 36 Proposal: 3, Protocol id: ESP, SPI size: 4, #trans: 3(153): last transform: 0x3, reserved: 0x0: length: 8 type: 1, reserved: 0x0, id: 3DES (153): last transform: 0x3, reserved: 0x0: length: 8 type: 3, reserved: 0x0, id: SHA96 (153): last transform: 0x0, reserved: 0x0: length: 8 type: 5, reserved: 0x0, id: Don't use ESN (153): last proposal: 0x0, reserved: 0x0, length: 36 Proposal: 4, Protocol id: ESP, SPI size: 4, #trans: 3(153): last transform: 0x3, reserved: 0x0: length: 8 type: 1, reserved: 0x0, id: 3DES (153): last transform: 0x3, reserved: 0x0: length: 8 type: 3, reserved: 0x0, id: SHA512 (153): last transform: 0x0, reserved: 0x0: length: 8 type: 5, reserved: 0x0, id: Don't use ESN (153): TSi(153): Next payload: TSr, reserved: 0x0, length: 40 (153): Num of TSs: 2, reserved 0x0, reserved 0x0 (153): TS type: TS_IPV4_ADDR_RANGE, proto id: 0, length: 16 (153): start port: 0, end port: 65535 (153): start addr: 1.2.3.4, end addr: 1.2.3.4 (153): TS type: TS_IPV4_ADDR_RANGE, proto id: 0, length: 16 (153): start port: 0, end port: 65535 (153): start addr: 192.168.244.0, end addr: 192.168.244.255 (153): TSr(153): Next payload: NOTIFY, reserved: 0x0, length: 40 (153): Num of TSs: 2, reserved 0x0, reserved 0x0 (153): TS type: TS_IPV4_ADDR_RANGE, proto id: 0, length: 16 (153): start port: 0, end port: 65535 (153): start addr: 9.8.7.6, end addr: 9.8.7.6 (153): TS type: TS_IPV4_ADDR_RANGE, proto id: 0, length: 16 (153): start port: 0, end port: 65535 (153): start addr: 192.168.242.0, end addr: 192.168.242.255 (153): NOTIFY(Unknown - 16396)(153): Next payload: NOTIFY, reserved: 0x0, length: 8 (153): Security protocol id: Unknown - 0, spi size: 0, type: Unknown - 0 (153): NOTIFY(Unknown - 16397)(153): Next payload: NOTIFY, reserved: 0x0, length: 12 (153): Security protocol id: Unknown - 0, spi size: 0, type: Unknown - 0 (153): (153): c0 a8 f4 01 (153): NOTIFY(Unknown - 16417)(153): Next payload: NONE, reserved: 0x0, length: 8 (153): Security protocol id: Unknown - 0, spi size: 0, type: Unknown - 0 (153): (153): Decrypted packet:(153): Data: 464 bytes
Note the public IP addresses are included in the 'TS_IPV4_ADDR_RANGE' section. The resulting failure looks like this:
IKEv2-PROTO-1: (153): Failed to find a matching policy IKEv2-PROTO-1: (153): Received Policies: IKEv2-PROTO-1: (153): Failed to find a matching policy IKEv2-PROTO-1: (153): Expected Policies: IKEv2-PROTO-5: (153): Failed to verify the proposed policies IKEv2-PROTO-1: (153): Failed to find a matching policy
Here is what happens, moments later, when I manually start the tunnel from the IPSec status page:
IKEv2-PROTO-2: (154): Received Packet [From 1.2.3.4:4500/To 9.8.7.6:500/VRF i0:f0] (154): Initiator SPI : A1D8249CBDC4008D - Responder SPI : 8E4623ACA44823B8 Message id: 1 (154): IKEv2 IKE_AUTH Exchange REQUESTIKEv2-PROTO-3: (154): Next payload: ENCR, version: 2.0 (154): Exchange type: IKE_AUTH, flags: INITIATOR (154): Message id: 1, length: 432(154): Payload contents: (154): REAL Decrypted packet:(154): Data: 344 bytes (154): IDi(154): Next payload: NOTIFY, reserved: 0x0, length: 12 (154): Id type: IPv4 address, Reserved: 0x0 0x0 (154): (154): b8 45 a9 a2 (154): NOTIFY(INITIAL_CONTACT)(154): Next payload: IDr, reserved: 0x0, length: 8 (154): Security protocol id: Unknown - 0, spi size: 0, type: INITIAL_CONTACT (154): IDr(154): Next payload: AUTH, reserved: 0x0, length: 12 (154): Id type: IPv4 address, Reserved: 0x0 0x0 (154): (154): a2 d4 ca 7e (154): AUTH(154): Next payload: NOTIFY, reserved: 0x0, length: 72 (154): Auth method PSK, reserved: 0x0, reserved 0x0 (154): Auth data: 64 bytes (154): NOTIFY(ESP_TFC_NO_SUPPORT)(154): Next payload: SA, reserved: 0x0, length: 8 (154): Security protocol id: Unknown - 0, spi size: 0, type: ESP_TFC_NO_SUPPORT (154): SA(154): Next payload: TSi, reserved: 0x0, length: 156 (154): last proposal: 0x2, reserved: 0x0, length: 40 Proposal: 1, Protocol id: ESP, SPI size: 4, #trans: 3(154): last transform: 0x3, reserved: 0x0: length: 12 type: 1, reserved: 0x0, id: AES-CBC (154): last transform: 0x3, reserved: 0x0: length: 8 type: 3, reserved: 0x0, id: SHA96 (154): last transform: 0x0, reserved: 0x0: length: 8 type: 5, reserved: 0x0, id: Don't use ESN (154): last proposal: 0x2, reserved: 0x0, length: 40 Proposal: 2, Protocol id: ESP, SPI size: 4, #trans: 3(154): last transform: 0x3, reserved: 0x0: length: 12 type: 1, reserved: 0x0, id: AES-CBC (154): last transform: 0x3, reserved: 0x0: length: 8 type: 3, reserved: 0x0, id: SHA512 (154): last transform: 0x0, reserved: 0x0: length: 8 type: 5, reserved: 0x0, id: Don't use ESN (154): last proposal: 0x2, reserved: 0x0, length: 36 Proposal: 3, Protocol id: ESP, SPI size: 4, #trans: 3(154): last transform: 0x3, reserved: 0x0: length: 8 type: 1, reserved: 0x0, id: 3DES (154): last transform: 0x3, reserved: 0x0: length: 8 type: 3, reserved: 0x0, id: SHA96 (154): last transform: 0x0, reserved: 0x0: length: 8 type: 5, reserved: 0x0, id: Don't use ESN (154): last proposal: 0x0, reserved: 0x0, length: 36 Proposal: 4, Protocol id: ESP, SPI size: 4, #trans: 3(154): last transform: 0x3, reserved: 0x0: length: 8 type: 1, reserved: 0x0, id: 3DES (154): last transform: 0x3, reserved: 0x0: length: 8 type: 3, reserved: 0x0, id: SHA512 (154): last transform: 0x0, reserved: 0x0: length: 8 type: 5, reserved: 0x0, id: Don't use ESN (154): TSi(154): Next payload: TSr, reserved: 0x0, length: 24 (154): Num of TSs: 1, reserved 0x0, reserved 0x0 (154): TS type: TS_IPV4_ADDR_RANGE, proto id: 0, length: 16 (154): start port: 0, end port: 65535 (154): start addr: 192.168.244.0, end addr: 192.168.244.255 (154): TSr(154): Next payload: NOTIFY, reserved: 0x0, length: 24 (154): Num of TSs: 1, reserved 0x0, reserved 0x0 (154): TS type: TS_IPV4_ADDR_RANGE, proto id: 0, length: 16 (154): start port: 0, end port: 65535 (154): start addr: 192.168.242.0, end addr: 192.168.242.255 (154): NOTIFY(Unknown - 16396)(154): Next payload: NOTIFY, reserved: 0x0, length: 8 (154): Security protocol id: Unknown - 0, spi size: 0, type: Unknown - 0 (154): NOTIFY(Unknown - 16397)(154): Next payload: NOTIFY, reserved: 0x0, length: 12 (154): Security protocol id: Unknown - 0, spi size: 0, type: Unknown - 0 (154): (154): c0 a8 f4 01 (154): NOTIFY(Unknown - 16417)(154): Next payload: NONE, reserved: 0x0, length: 8 (154): Security protocol id: Unknown - 0, spi size: 0, type: Unknown - 0 (154): (154): Decrypted packet:(154): Data: 432 bytes
No public IP addresses included, and this connection succeeds. Thoughts?
EDIT: Here are pfSense logs for these two connection attempts. Aside from the different size of the packets sent, note the line 'establishing CHILD_SA con1{1}' in the failed attemps, versus 'establishing CHILD_SA con1' in the successful attempt. Does this indicate anything useful?
Dec 18 09:38:59 pf-victoria charon: 16[KNL] creating acquire job for policy 1.2.3.4/32|/0 === 9.8.7.6/32|/0 with reqid {1} Dec 18 09:38:59 pf-victoria charon: 06[IKE] <con1|28>initiating IKE_SA con1[28] to 9.8.7.6 Dec 18 09:38:59 pf-victoria charon: 06[IKE] initiating IKE_SA con1[28] to 9.8.7.6 Dec 18 09:38:59 pf-victoria charon: 06[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) ] Dec 18 09:38:59 pf-victoria charon: 06[NET] sending packet: from 1.2.3.4[500] to 9.8.7.6[500] (440 bytes) Dec 18 09:38:59 pf-victoria charon: 06[NET] received packet: from 9.8.7.6[500] to 1.2.3.4[500] (585 bytes) Dec 18 09:38:59 pf-victoria charon: 06[ENC] parsed IKE_SA_INIT response 0 [ SA KE No V V V N(NATD_S_IP) N(NATD_D_IP) V ] Dec 18 09:38:59 pf-victoria charon: 06[IKE] <con1|28>received Cisco Delete Reason vendor ID Dec 18 09:38:59 pf-victoria charon: 06[IKE] received Cisco Delete Reason vendor ID Dec 18 09:38:59 pf-victoria charon: 06[IKE] <con1|28>received Cisco Copyright (c) 2009 vendor ID Dec 18 09:38:59 pf-victoria charon: 06[IKE] received Cisco Copyright (c) 2009 vendor ID Dec 18 09:38:59 pf-victoria charon: 06[ENC] received unknown vendor ID: 43:49:53:43:4f:2d:47:52:45:2d:4d:4f:44:45:02 Dec 18 09:38:59 pf-victoria charon: 06[IKE] <con1|28>received FRAGMENTATION vendor ID Dec 18 09:38:59 pf-victoria charon: 06[IKE] received FRAGMENTATION vendor ID Dec 18 09:38:59 pf-victoria charon: 06[IKE] <con1|28>authentication of '1.2.3.4' (myself) with pre-shared key Dec 18 09:38:59 pf-victoria charon: 06[IKE] authentication of '1.2.3.4' (myself) with pre-shared key Dec 18 09:38:59 pf-victoria charon: 06[IKE] <con1|28>establishing CHILD_SA con1{1} Dec 18 09:38:59 pf-victoria charon: 06[IKE] establishing CHILD_SA con1{1} Dec 18 09:38:59 pf-victoria charon: 06[ENC] generating IKE_AUTH request 1 [ IDi N(INIT_CONTACT) IDr AUTH N(ESP_TFC_PAD_N) SA TSi TSr N(MOBIKE_SUP) N(ADD_4_ADDR) N(EAP_ONLY) ] Dec 18 09:38:59 pf-victoria charon: 06[NET] sending packet: from 1.2.3.4[4500] to 9.8.7.6[4500] (464 bytes) Dec 18 09:38:59 pf-victoria charon: 06[NET] received packet: from 9.8.7.6[4500] to 1.2.3.4[4500] (208 bytes) Dec 18 09:38:59 pf-victoria charon: 06[ENC] parsed IKE_AUTH response 1 [ V IDr AUTH N(NO_PROP) ] Dec 18 09:38:59 pf-victoria charon: 06[IKE] <con1|28>authentication of '9.8.7.6' with pre-shared key successful Dec 18 09:38:59 pf-victoria charon: 06[IKE] authentication of '9.8.7.6' with pre-shared key successful Dec 18 09:38:59 pf-victoria charon: 06[IKE] <con1|28>IKE_SA con1[28] established between 1.2.3.4[1.2.3.4]...9.8.7.6[9.8.7.6] Dec 18 09:38:59 pf-victoria charon: 06[IKE] IKE_SA con1[28] established between 1.2.3.4[1.2.3.4]...9.8.7.6[9.8.7.6] Dec 18 09:38:59 pf-victoria charon: 06[IKE] <con1|28>scheduling reauthentication in 27865s Dec 18 09:38:59 pf-victoria charon: 06[IKE] scheduling reauthentication in 27865s Dec 18 09:38:59 pf-victoria charon: 06[IKE] <con1|28>maximum IKE_SA lifetime 28405s Dec 18 09:38:59 pf-victoria charon: 06[IKE] maximum IKE_SA lifetime 28405s Dec 18 09:38:59 pf-victoria charon: 06[IKE] <con1|28>received NO_PROPOSAL_CHOSEN notify, no CHILD_SA built Dec 18 09:38:59 pf-victoria charon: 06[IKE] received NO_PROPOSAL_CHOSEN notify, no CHILD_SA built Dec 18 09:38:59 pf-victoria charon: 06[IKE] <con1|28>failed to establish CHILD_SA, keeping IKE_SA Dec 18 09:38:59 pf-victoria charon: 06[IKE] failed to establish CHILD_SA, keeping IKE_SA Dec 18 09:39:34 pf-victoria charon: 16[CFG] received stroke: initiate 'con1' Dec 18 09:39:34 pf-victoria charon: 09[IKE] <con1|29>initiating IKE_SA con1[29] to 9.8.7.6 Dec 18 09:39:34 pf-victoria charon: 09[IKE] initiating IKE_SA con1[29] to 9.8.7.6 Dec 18 09:39:34 pf-victoria charon: 09[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) ] Dec 18 09:39:34 pf-victoria charon: 09[NET] sending packet: from 1.2.3.4[500] to 9.8.7.6[500] (440 bytes) Dec 18 09:39:34 pf-victoria charon: 09[NET] received packet: from 9.8.7.6[500] to 1.2.3.4[500] (585 bytes) Dec 18 09:39:34 pf-victoria charon: 09[ENC] parsed IKE_SA_INIT response 0 [ SA KE No V V V N(NATD_S_IP) N(NATD_D_IP) V ] Dec 18 09:39:34 pf-victoria charon: 09[IKE] <con1|29>received Cisco Delete Reason vendor ID Dec 18 09:39:34 pf-victoria charon: 09[IKE] received Cisco Delete Reason vendor ID Dec 18 09:39:34 pf-victoria charon: 09[IKE] <con1|29>received Cisco Copyright (c) 2009 vendor ID Dec 18 09:39:34 pf-victoria charon: 09[IKE] received Cisco Copyright (c) 2009 vendor ID Dec 18 09:39:34 pf-victoria charon: 09[ENC] received unknown vendor ID: 43:49:53:43:4f:2d:47:52:45:2d:4d:4f:44:45:02 Dec 18 09:39:34 pf-victoria charon: 09[IKE] <con1|29>received FRAGMENTATION vendor ID Dec 18 09:39:34 pf-victoria charon: 09[IKE] received FRAGMENTATION vendor ID Dec 18 09:39:34 pf-victoria charon: 09[IKE] <con1|29>authentication of '1.2.3.4' (myself) with pre-shared key Dec 18 09:39:34 pf-victoria charon: 09[IKE] authentication of '1.2.3.4' (myself) with pre-shared key Dec 18 09:39:34 pf-victoria charon: 09[IKE] <con1|29>establishing CHILD_SA con1 Dec 18 09:39:34 pf-victoria charon: 09[IKE] establishing CHILD_SA con1 Dec 18 09:39:34 pf-victoria charon: 09[ENC] generating IKE_AUTH request 1 [ IDi N(INIT_CONTACT) IDr AUTH N(ESP_TFC_PAD_N) SA TSi TSr N(MOBIKE_SUP) N(ADD_4_ADDR) N(EAP_ONLY) ] Dec 18 09:39:34 pf-victoria charon: 09[NET] sending packet: from 1.2.3.4[4500] to 9.8.7.6[4500] (432 bytes) Dec 18 09:39:34 pf-victoria charon: 09[NET] received packet: from 9.8.7.6[4500] to 1.2.3.4[4500] (304 bytes) Dec 18 09:39:34 pf-victoria charon: 09[ENC] parsed IKE_AUTH response 1 [ V IDr AUTH SA TSi TSr N(ESP_TFC_PAD_N) N(NON_FIRST_FRAG) ] Dec 18 09:39:34 pf-victoria charon: 09[IKE] <con1|29>authentication of '9.8.7.6' with pre-shared key successful Dec 18 09:39:34 pf-victoria charon: 09[IKE] authentication of '9.8.7.6' with pre-shared key successful Dec 18 09:39:34 pf-victoria charon: 09[IKE] <con1|29>IKE_SA con1[29] established between 1.2.3.4[1.2.3.4]...9.8.7.6[9.8.7.6] Dec 18 09:39:34 pf-victoria charon: 09[IKE] IKE_SA con1[29] established between 1.2.3.4[1.2.3.4]...9.8.7.6[9.8.7.6] Dec 18 09:39:34 pf-victoria charon: 09[IKE] <con1|29>scheduling reauthentication in 28245s Dec 18 09:39:34 pf-victoria charon: 09[IKE] scheduling reauthentication in 28245s Dec 18 09:39:34 pf-victoria charon: 09[IKE] <con1|29>maximum IKE_SA lifetime 28785s Dec 18 09:39:34 pf-victoria charon: 09[IKE] maximum IKE_SA lifetime 28785s Dec 18 09:39:34 pf-victoria charon: 09[IKE] <con1|29>received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding Dec 18 09:39:34 pf-victoria charon: 09[IKE] received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding Dec 18 09:39:34 pf-victoria charon: 09[IKE] <con1|29>CHILD_SA con1{1} established with SPIs c02da961_i c6c0ab47_o and TS 192.168.244.0/24|/0 === 192.168.242.0/24|/0 Dec 18 09:39:34 pf-victoria charon: 09[IKE] CHILD_SA con1{1} established with SPIs c02da961_i c6c0ab47_o and TS 192.168.244.0/24|/0 === 192.168.242.0/24|/0</con1|29></con1|29></con1|29></con1|29></con1|29></con1|29></con1|29></con1|29></con1|29></con1|29></con1|29></con1|29></con1|28></con1|28></con1|28></con1|28></con1|28></con1|28></con1|28></con1|28></con1|28></con1|28></con1|28></con1|28>
-
@cmb:
The source of the issue is definitely the "Crypto Map Policy not found for remote traffic selector" log from the ASA. As to why, probably a better question for a Cisco forum. Your crypto map looks like it matches what the ASA claims doesn't match.
Any input on this? It looks like the traffic selector being sent by StrongSwan is different based on how the tunnel is initiated, which seems like a bug. I'd open a bug but am not sure I could describe it in sufficient detail to ensure a resolution, as I've no experience with StrongSwan.
-
edit: no, misread that.
-
@cmb:
That's this. https://redmine.pfsense.org/issues/4129
I only have the single phase 2 entry; does it still apply to me? Thanks.
-
No it doesn't in that case, I mis-read your last post. I'm doing some IPsec testing with an ASA right now, will see if that's replicable.
-
@cmb:
No it doesn't in that case, I mis-read your last post. I'm doing some IPsec testing with an ASA right now, will see if that's replicable.
Any luck with this? Anything more I can do to help narrow it down?
-
Did you test new snapshots?
There have been fixes put in place for various issues especially on IPsec. -
@ermal:
Did you test new snapshots?
There have been fixes put in place for various issues especially on IPsec.No improvements with this morning's build. Tunnels have to be manually started or the wrong traffic selector is sent.
-
What's wrong about it? It looks like it's sending what you have configured and the ASA is rejecting it. The only issue with interoperability with Cisco IPsec that I'm aware of is this. https://redmine.pfsense.org/issues/4178 Which only applies to IKEv1 and isn't what you're seeing here.
-
@cmb:
What's wrong about it? It looks like it's sending what you have configured and the ASA is rejecting it.
Please reread my earlier post at https://forum.pfsense.org/index.php?topic=84934.msg469407#msg469407. When pfSense tries to bring up the tunnel automatically, it sends a different traffic selector than when the tunnel is manually started from the status page.
-
The latest strongswan release (5.2.1->5.2.2) went into today's snapshots, please retry after upgrading to something from the 7th or newer and report back.
-
@cmb:
The latest strongswan release (5.2.1->5.2.2) went into today's snapshots, please retry after upgrading to something from the 7th or newer and report back.
Just updated. Tunnel still does not come up on boot, but a subsequent ping test from the pfSense did eventually bring up P1 and P2 successfully. Will do further testing and advise tomorrow, but looks like it's usable now. Thanks a lot!
-
Glad to hear. Tunnels never come up unless there is traffic triggering them, or you have the "Automatically ping host" set in the P2, so sounds like that's the expected end result.