IPSEC Phase 2 disconnects after 1 hour and does not reconnect
-
Hi,
I tried to set up an IPSEC S2S VPN with one of our vendors (we already have 3 other S2S VPNs running with different vendors). They set their side up and gave me the following details:
The 10.207.239.61 should be NATted by us and 10.11.0.0 is their remote subnet.
I put this all in a Phase 1 and Phase 2:
Everything worked on first try but after exactly 1 hour (which is the Phase 2 lifetime) Phase 1 is still running but Phase 2 does disconnect and does not get up again.
Following is the log directly after the Phase 2 is down and tries to come up again:Apr 13 13:20:17 charon 10[CFG] vici client 4175 connected Apr 13 13:20:17 charon 11[CFG] vici client 4175 registered for: list-sa Apr 13 13:20:17 charon 11[CFG] vici client 4175 requests: list-sas Apr 13 13:20:17 charon 14[CFG] vici client 4175 disconnected Apr 13 13:20:12 charon 13[CFG] vici client 4174 connected Apr 13 13:20:12 charon 14[CFG] vici client 4174 registered for: list-sa Apr 13 13:20:12 charon 14[CFG] vici client 4174 requests: list-sas Apr 13 13:20:12 charon 14[CFG] vici client 4174 disconnected Apr 13 13:20:10 charon 09[IKE] <con4000|13> sending DPD request Apr 13 13:20:10 charon 09[IKE] <con4000|13> queueing IKE_DPD task Apr 13 13:20:10 charon 09[IKE] <con4000|13> activating new tasks Apr 13 13:20:10 charon 09[IKE] <con4000|13> activating IKE_DPD task Apr 13 13:20:10 charon 09[ENC] <con4000|13> generating INFORMATIONAL request 423 [ ] Apr 13 13:20:10 charon 09[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (80 bytes) Apr 13 13:20:10 charon 10[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:20:10 charon 10[ENC] <con4000|13> parsed INFORMATIONAL response 423 [ ] Apr 13 13:20:10 charon 10[IKE] <con4000|13> activating new tasks Apr 13 13:20:10 charon 10[IKE] <con4000|13> nothing to initiate Apr 13 13:20:10 charon 10[JOB] CHILD_SA ESP/0xcb917a86/213.34.11.17 not found for rekey Apr 13 13:20:07 charon 10[CFG] vici client 4173 connected Apr 13 13:20:07 charon 12[CFG] vici client 4173 registered for: list-sa Apr 13 13:20:07 charon 09[CFG] vici client 4173 requests: list-sas Apr 13 13:20:07 charon 09[CFG] vici client 4173 disconnected Apr 13 13:20:02 charon 01[CFG] vici client 4172 connected Apr 13 13:20:02 charon 10[CFG] vici client 4172 registered for: list-sa Apr 13 13:20:02 charon 10[CFG] vici client 4172 requests: list-sas Apr 13 13:20:02 charon 09[CFG] vici client 4172 disconnected Apr 13 13:20:01 charon 09[JOB] CHILD_SA ESP/0xcb917a86/213.34.11.17 not found for rekey Apr 13 13:20:00 charon 01[KNL] creating delete job for CHILD_SA ESP/0xcb917a86/213.34.11.17 Apr 13 13:20:00 charon 09[IKE] <con4000|13> queueing CHILD_DELETE task Apr 13 13:20:00 charon 01[KNL] creating delete job for CHILD_SA ESP/0x68790460/185.121.192.8 Apr 13 13:20:00 charon 09[IKE] <con4000|13> activating new tasks Apr 13 13:20:00 charon 09[IKE] <con4000|13> activating CHILD_DELETE task Apr 13 13:20:00 charon 09[IKE] <con4000|13> closing expired CHILD_SA con4000{1072} with SPIs cb917a86_i 68790460_o and TS 10.207.239.61/32|192.168.1.0/24 === 10.11.0.0/11|/0 Apr 13 13:20:00 charon 09[IKE] <con4000|13> sending DELETE for ESP CHILD_SA with SPI cb917a86 Apr 13 13:20:00 charon 09[CHD] <con4000|13> CHILD_SA con4000{1072} state change: INSTALLED => DELETING Apr 13 13:20:00 charon 09[IKE] <con4000|13> scheduling CHILD_SA recreate after hard expire Apr 13 13:20:00 charon 09[IKE] <con4000|13> queueing CHILD_CREATE task Apr 13 13:20:00 charon 09[ENC] <con4000|13> generating INFORMATIONAL request 419 [ D ] Apr 13 13:20:00 charon 09[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (80 bytes) Apr 13 13:20:00 charon 15[IKE] <con4000|13> queueing CHILD_DELETE task Apr 13 13:20:00 charon 15[IKE] <con4000|13> delaying task initiation, INFORMATIONAL exchange in progress Apr 13 13:20:00 charon 15[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:20:00 charon 15[ENC] <con4000|13> parsed INFORMATIONAL response 419 [ D ] Apr 13 13:20:00 charon 15[IKE] <con4000|13> received DELETE for ESP CHILD_SA with SPI 68790460 Apr 13 13:20:00 charon 15[IKE] <con4000|13> CHILD_SA closed Apr 13 13:20:00 charon 15[CHD] <con4000|13> CHILD_SA con4000{1072} state change: DELETING => DELETED Apr 13 13:20:00 charon 15[CHD] <con4000|13> CHILD_SA con4000{1072} state change: DELETED => DESTROYING Apr 13 13:20:00 charon 15[KNL] <con4000|13> unable to delete SAD entry with SPI cb917a86: No such process (3) Apr 13 13:20:00 charon 15[KNL] <con4000|13> unable to delete SAD entry with SPI 68790460: No such process (3) Apr 13 13:20:00 charon 15[IKE] <con4000|13> activating new tasks Apr 13 13:20:00 charon 15[IKE] <con4000|13> activating CHILD_DELETE task Apr 13 13:20:00 charon 15[ENC] <con4000|13> generating INFORMATIONAL request 420 [ ] Apr 13 13:20:00 charon 15[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (80 bytes) Apr 13 13:20:00 charon 09[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:20:00 charon 09[ENC] <con4000|13> parsed INFORMATIONAL request 30 [ D ] Apr 13 13:20:00 charon 09[IKE] <con4000|13> received DELETE for unknown ESP CHILD_SA with SPI 68790460 Apr 13 13:20:00 charon 09[IKE] <con4000|13> CHILD_SA closed Apr 13 13:20:00 charon 09[ENC] <con4000|13> generating INFORMATIONAL response 30 [ ] Apr 13 13:20:00 charon 09[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (80 bytes) Apr 13 13:20:00 charon 09[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:20:00 charon 09[ENC] <con4000|13> parsed INFORMATIONAL response 420 [ ] Apr 13 13:20:00 charon 09[IKE] <con4000|13> activating new tasks Apr 13 13:20:00 charon 09[IKE] <con4000|13> activating CHILD_CREATE task Apr 13 13:20:00 charon 09[CFG] <con4000|13> proposing traffic selectors for us: Apr 13 13:20:00 charon 09[CFG] <con4000|13> 10.207.239.61/32|192.168.1.0/24 Apr 13 13:20:00 charon 09[CFG] <con4000|13> proposing traffic selectors for other: Apr 13 13:20:00 charon 09[CFG] <con4000|13> 10.11.0.0/11|/0 Apr 13 13:20:00 charon 09[CFG] <con4000|13> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_GCM_16_128/ECP_256/NO_EX Apr 13 13:20:00 charon 09[IKE] <con4000|13> establishing CHILD_SA con4000{1197} Apr 13 13:20:00 charon 09[ENC] <con4000|13> generating CREATE_CHILD_SA request 421 [ N(ESP_TFC_PAD_N) SA No KE TSi TSr ] Apr 13 13:20:00 charon 09[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (2592 bytes) Apr 13 13:20:00 charon 09[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:20:00 charon 09[ENC] <con4000|13> parsed CREATE_CHILD_SA response 421 [ N(INVAL_KE) ] Apr 13 13:20:00 charon 09[IKE] <con4000|13> peer didn't accept DH group ECP_256, it requested ECP_256 Apr 13 13:20:00 charon 09[CHD] <con4000|13> CHILD_SA con4000{1197} state change: CREATED => RETRYING Apr 13 13:20:00 charon 09[CHD] <con4000|13> CHILD_SA con4000{1197} state change: RETRYING => DESTROYING Apr 13 13:20:00 charon 09[IKE] <con4000|13> reinitiating already active tasks Apr 13 13:20:00 charon 09[IKE] <con4000|13> CHILD_CREATE task Apr 13 13:20:00 charon 09[CFG] <con4000|13> proposing traffic selectors for us: Apr 13 13:20:00 charon 09[CFG] <con4000|13> 10.207.239.61/32|192.168.1.0/24 Apr 13 13:20:00 charon 09[CFG] <con4000|13> proposing traffic selectors for other: Apr 13 13:20:00 charon 09[CFG] <con4000|13> 10.11.0.0/11|/0 Apr 13 13:20:00 charon 09[CFG] <con4000|13> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_GCM_16_128/ECP_256/NO_EX Apr 13 13:20:00 charon 09[IKE] <con4000|13> establishing CHILD_SA con4000{1198} Apr 13 13:20:00 charon 09[ENC] <con4000|13> generating CREATE_CHILD_SA request 422 [ N(ESP_TFC_PAD_N) SA No KE TSi TSr ] Apr 13 13:20:00 charon 09[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (2592 bytes) Apr 13 13:20:00 charon 09[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:20:00 charon 09[ENC] <con4000|13> parsed CREATE_CHILD_SA response 422 [ N(INVAL_KE) ] Apr 13 13:20:00 charon 09[IKE] <con4000|13> already retried with DH group ECP_256, ignorerequested ECP_256 Apr 13 13:20:00 charon 09[IKE] <con4000|13> failed to establish CHILD_SA, keeping IKE_SA Apr 13 13:20:00 charon 09[CHD] <con4000|13> CHILD_SA con4000{1198} state change: CREATED => DESTROYING Apr 13 13:20:00 charon 09[IKE] <con4000|13> activating new tasks Apr 13 13:20:00 charon 09[IKE] <con4000|13> nothing to initiate Apr 13 13:19:58 charon 01[IKE] <con4000|13> queueing CHILD_REKEY task Apr 13 13:19:58 charon 01[IKE] <con4000|13> activating new tasks Apr 13 13:19:58 charon 01[IKE] <con4000|13> activating CHILD_REKEY task Apr 13 13:19:58 charon 01[CFG] <con4000|13> proposing traffic selectors for us: Apr 13 13:19:58 charon 01[CFG] <con4000|13> 10.207.239.61/32|192.168.1.0/24 Apr 13 13:19:58 charon 01[CFG] <con4000|13> proposing traffic selectors for other: Apr 13 13:19:58 charon 01[CFG] <con4000|13> 10.11.0.0/11|/0 Apr 13 13:19:58 charon 01[CFG] <con4000|13> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_GCM_16_128/ECP_256/NO_EX Apr 13 13:19:58 charon 01[IKE] <con4000|13> establishing CHILD_SA con4000{1195} reqid 43 Apr 13 13:19:58 charon 01[CHD] <con4000|13> CHILD_SA con4000{1072} state change: INSTALLED => REKEYING Apr 13 13:19:58 charon 01[ENC] <con4000|13> generating CREATE_CHILD_SA request 417 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ] Apr 13 13:19:58 charon 01[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (2608 bytes) Apr 13 13:19:58 charon 01[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:19:58 charon 01[ENC] <con4000|13> parsed CREATE_CHILD_SA response 417 [ N(INVAL_KE) ] Apr 13 13:19:58 charon 01[IKE] <con4000|13> peer didn't accept DH group ECP_256, it requested ECP_256 Apr 13 13:19:58 charon 01[CHD] <con4000|13> CHILD_SA con4000{1195} state change: CREATED => RETRYING Apr 13 13:19:58 charon 01[CHD] <con4000|13> CHILD_SA con4000{1195} state change: RETRYING => DESTROYING Apr 13 13:19:58 charon 01[IKE] <con4000|13> reinitiating already active tasks Apr 13 13:19:58 charon 01[IKE] <con4000|13> CHILD_REKEY task Apr 13 13:19:58 charon 01[CFG] <con4000|13> proposing traffic selectors for us: Apr 13 13:19:58 charon 01[CFG] <con4000|13> 10.207.239.61/32|192.168.1.0/24 Apr 13 13:19:58 charon 01[CFG] <con4000|13> proposing traffic selectors for other: Apr 13 13:19:58 charon 01[CFG] <con4000|13> 10.11.0.0/11|/0 Apr 13 13:19:58 charon 01[CFG] <con4000|13> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_GCM_16_128/ECP_256/NO_EX Apr 13 13:19:58 charon 01[IKE] <con4000|13> establishing CHILD_SA con4000{1196} reqid 43 Apr 13 13:19:58 charon 01[ENC] <con4000|13> generating CREATE_CHILD_SA request 418 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ] Apr 13 13:19:58 charon 01[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (2608 bytes) Apr 13 13:19:58 charon 01[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:19:58 charon 01[ENC] <con4000|13> parsed CREATE_CHILD_SA response 418 [ N(INVAL_KE) ] Apr 13 13:19:58 charon 01[IKE] <con4000|13> already retried with DH group ECP_256, ignorerequested ECP_256 Apr 13 13:19:58 charon 01[IKE] <con4000|13> failed to establish CHILD_SA, keeping IKE_SA Apr 13 13:19:58 charon 01[IKE] <con4000|13> CHILD_SA rekeying failed, trying again in 12 seconds Apr 13 13:19:58 charon 01[CHD] <con4000|13> CHILD_SA con4000{1072} state change: REKEYING => INSTALLED Apr 13 13:19:58 charon 01[CHD] <con4000|13> CHILD_SA con4000{1196} state change: CREATED => DESTROYING Apr 13 13:19:58 charon 01[IKE] <con4000|13> activating new tasks Apr 13 13:19:58 charon 01[IKE] <con4000|13> nothing to initiate Apr 13 13:19:57 charon 16[CFG] vici client 4171 connected Apr 13 13:19:57 charon 08[CFG] vici client 4171 registered for: list-sa Apr 13 13:19:57 charon 01[CFG] vici client 4171 requests: list-sas Apr 13 13:19:57 charon 01[CFG] vici client 4171 disconnected Apr 13 13:19:52 charon 01[CFG] vici client 4170 connected Apr 13 13:19:52 charon 16[CFG] vici client 4170 registered for: list-sa Apr 13 13:19:52 charon 16[CFG] vici client 4170 requests: list-sas Apr 13 13:19:52 charon 01[CFG] vici client 4170 disconnected Apr 13 13:19:49 charon 06[IKE] <con4000|13> queueing CHILD_REKEY task Apr 13 13:19:49 charon 06[IKE] <con4000|13> activating new tasks Apr 13 13:19:49 charon 06[IKE] <con4000|13> activating CHILD_REKEY task Apr 13 13:19:49 charon 06[CFG] <con4000|13> proposing traffic selectors for us: Apr 13 13:19:49 charon 06[CFG] <con4000|13> 10.207.239.61/32|192.168.1.0/24 Apr 13 13:19:49 charon 06[CFG] <con4000|13> proposing traffic selectors for other: Apr 13 13:19:49 charon 06[CFG] <con4000|13> 10.11.0.0/11|/0 Apr 13 13:19:49 charon 06[CFG] <con4000|13> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_GCM_16_128/ECP_256/NO_EX Apr 13 13:19:49 charon 06[IKE] <con4000|13> establishing CHILD_SA con4000{1193} reqid 43 Apr 13 13:19:49 charon 06[CHD] <con4000|13> CHILD_SA con4000{1072} state change: INSTALLED => REKEYING Apr 13 13:19:49 charon 06[ENC] <con4000|13> generating CREATE_CHILD_SA request 415 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ] Apr 13 13:19:49 charon 06[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (2608 bytes) Apr 13 13:19:49 charon 06[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:19:49 charon 06[ENC] <con4000|13> parsed CREATE_CHILD_SA response 415 [ N(INVAL_KE) ] Apr 13 13:19:49 charon 06[IKE] <con4000|13> peer didn't accept DH group ECP_256, it requested ECP_256 Apr 13 13:19:49 charon 06[CHD] <con4000|13> CHILD_SA con4000{1193} state change: CREATED => RETRYING Apr 13 13:19:49 charon 06[CHD] <con4000|13> CHILD_SA con4000{1193} state change: RETRYING => DESTROYING Apr 13 13:19:49 charon 06[IKE] <con4000|13> reinitiating already active tasks Apr 13 13:19:49 charon 06[IKE] <con4000|13> CHILD_REKEY task Apr 13 13:19:49 charon 06[CFG] <con4000|13> proposing traffic selectors for us: Apr 13 13:19:49 charon 06[CFG] <con4000|13> 10.207.239.61/32|192.168.1.0/24 Apr 13 13:19:49 charon 06[CFG] <con4000|13> proposing traffic selectors for other: Apr 13 13:19:49 charon 06[CFG] <con4000|13> 10.11.0.0/11|/0 Apr 13 13:19:49 charon 06[CFG] <con4000|13> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_GCM_16_128/ECP_256/NO_EX Apr 13 13:19:49 charon 06[IKE] <con4000|13> establishing CHILD_SA con4000{1194} reqid 43 Apr 13 13:19:49 charon 06[ENC] <con4000|13> generating CREATE_CHILD_SA request 416 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ] Apr 13 13:19:49 charon 06[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (2608 bytes) Apr 13 13:19:49 charon 06[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:19:49 charon 06[ENC] <con4000|13> parsed CREATE_CHILD_SA response 416 [ N(INVAL_KE) ] Apr 13 13:19:49 charon 06[IKE] <con4000|13> already retried with DH group ECP_256, ignorerequested ECP_256 Apr 13 13:19:49 charon 06[IKE] <con4000|13> failed to establish CHILD_SA, keeping IKE_SA Apr 13 13:19:49 charon 06[IKE] <con4000|13> CHILD_SA rekeying failed, trying again in 12 seconds Apr 13 13:19:49 charon 06[CHD] <con4000|13> CHILD_SA con4000{1072} state change: REKEYING => INSTALLED Apr 13 13:19:49 charon 06[CHD] <con4000|13> CHILD_SA con4000{1194} state change: CREATED => DESTROYING Apr 13 13:19:49 charon 06[IKE] <con4000|13> activating new tasks Apr 13 13:19:49 charon 06[IKE] <con4000|13> nothing to initiate Apr 13 13:19:48 charon 06[IKE] <con4000|13> queueing CHILD_REKEY task Apr 13 13:19:48 charon 06[IKE] <con4000|13> activating new tasks Apr 13 13:19:48 charon 06[IKE] <con4000|13> activating CHILD_REKEY task Apr 13 13:19:48 charon 06[CFG] <con4000|13> proposing traffic selectors for us: Apr 13 13:19:48 charon 06[CFG] <con4000|13> 10.207.239.61/32|192.168.1.0/24 Apr 13 13:19:48 charon 06[CFG] <con4000|13> proposing traffic selectors for other: Apr 13 13:19:48 charon 06[CFG] <con4000|13> 10.11.0.0/11|/0 Apr 13 13:19:48 charon 06[CFG] <con4000|13> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_GCM_16_128/ECP_256/NO_EX Apr 13 13:19:48 charon 06[IKE] <con4000|13> establishing CHILD_SA con4000{1191} reqid 43 Apr 13 13:19:48 charon 06[CHD] <con4000|13> CHILD_SA con4000{1072} state change: INSTALLED => REKEYING Apr 13 13:19:48 charon 06[ENC] <con4000|13> generating CREATE_CHILD_SA request 413 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ] Apr 13 13:19:48 charon 06[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (2608 bytes) Apr 13 13:19:48 charon 06[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:19:48 charon 06[ENC] <con4000|13> parsed CREATE_CHILD_SA response 413 [ N(INVAL_KE) ] Apr 13 13:19:48 charon 06[IKE] <con4000|13> peer didn't accept DH group ECP_256, it requested ECP_256 Apr 13 13:19:48 charon 06[CHD] <con4000|13> CHILD_SA con4000{1191} state change: CREATED => RETRYING Apr 13 13:19:48 charon 06[CHD] <con4000|13> CHILD_SA con4000{1191} state change: RETRYING => DESTROYING Apr 13 13:19:48 charon 06[IKE] <con4000|13> reinitiating already active tasks Apr 13 13:19:48 charon 06[IKE] <con4000|13> CHILD_REKEY task Apr 13 13:19:48 charon 06[CFG] <con4000|13> proposing traffic selectors for us: Apr 13 13:19:48 charon 06[CFG] <con4000|13> 10.207.239.61/32|192.168.1.0/24 Apr 13 13:19:48 charon 06[CFG] <con4000|13> proposing traffic selectors for other: Apr 13 13:19:48 charon 06[CFG] <con4000|13> 10.11.0.0/11|/0 Apr 13 13:19:48 charon 06[CFG] <con4000|13> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_GCM_16_128/ECP_256/NO_EX Apr 13 13:19:48 charon 06[IKE] <con4000|13> establishing CHILD_SA con4000{1192} reqid 43 Apr 13 13:19:48 charon 06[ENC] <con4000|13> generating CREATE_CHILD_SA request 414 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ] Apr 13 13:19:48 charon 06[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (2608 bytes) Apr 13 13:19:48 charon 06[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:19:48 charon 06[ENC] <con4000|13> parsed CREATE_CHILD_SA response 414 [ N(INVAL_KE) ] Apr 13 13:19:48 charon 06[IKE] <con4000|13> already retried with DH group ECP_256, ignorerequested ECP_256 Apr 13 13:19:48 charon 06[IKE] <con4000|13> failed to establish CHILD_SA, keeping IKE_SA Apr 13 13:19:48 charon 06[IKE] <con4000|13> CHILD_SA rekeying failed, trying again in 10 seconds Apr 13 13:19:48 charon 06[CHD] <con4000|13> CHILD_SA con4000{1072} state change: REKEYING => INSTALLED Apr 13 13:19:48 charon 06[CHD] <con4000|13> CHILD_SA con4000{1192} state change: CREATED => DESTROYING Apr 13 13:19:48 charon 06[IKE] <con4000|13> activating new tasks Apr 13 13:19:48 charon 06[IKE] <con4000|13> nothing to initiate Apr 13 13:19:47 charon 07[CFG] vici client 4169 connected Apr 13 13:19:47 charon 11[CFG] vici client 4169 registered for: list-sa Apr 13 13:19:47 charon 07[CFG] vici client 4169 requests: list-sas Apr 13 13:19:47 charon 06[CFG] vici client 4169 disconnected Apr 13 13:19:41 charon 06[CFG] vici client 4168 connected Apr 13 13:19:41 charon 14[CFG] vici client 4168 registered for: list-sa Apr 13 13:19:41 charon 14[CFG] vici client 4168 requests: list-sas Apr 13 13:19:41 charon 06[CFG] vici client 4168 disconnected Apr 13 13:19:39 charon 13[IKE] <con4000|13> queueing CHILD_REKEY task Apr 13 13:19:39 charon 13[IKE] <con4000|13> activating new tasks Apr 13 13:19:39 charon 13[IKE] <con4000|13> activating CHILD_REKEY task Apr 13 13:19:39 charon 13[CFG] <con4000|13> proposing traffic selectors for us: Apr 13 13:19:39 charon 13[CFG] <con4000|13> 10.207.239.61/32|192.168.1.0/24 Apr 13 13:19:39 charon 13[CFG] <con4000|13> proposing traffic selectors for other: Apr 13 13:19:39 charon 13[CFG] <con4000|13> 10.11.0.0/11|/0 Apr 13 13:19:39 charon 13[CFG] <con4000|13> configured proposals: ESP:AES_CBC_256/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_192/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_MD5_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA1_96/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_384_192/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/HMAC_SHA2_512_256/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_128/AES_XCBC_96/ECP_256/NO_EXT_SEQ, ESP:AES_GCM_16_128/ECP_256/NO_EX Apr 13 13:19:39 charon 13[IKE] <con4000|13> establishing CHILD_SA con4000{1189} reqid 43 Apr 13 13:19:39 charon 13[CHD] <con4000|13> CHILD_SA con4000{1072} state change: INSTALLED => REKEYING Apr 13 13:19:39 charon 13[ENC] <con4000|13> generating CREATE_CHILD_SA request 411 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ] Apr 13 13:19:39 charon 13[NET] <con4000|13> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (2608 bytes) Apr 13 13:19:39 charon 13[NET] <con4000|13> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (80 bytes) Apr 13 13:19:39 charon 13[ENC] <con4000|13> parsed CREATE_CHILD_SA response 411 [ N(INVAL_KE) ] Apr 13 13:19:39 charon 13[IKE] <con4000|13> peer didn't accept DH group ECP_256, it requested ECP_256 Apr 13 13:19:39 charon 13[CHD] <con4000|13> CHILD_SA con4000{1189} state change: CREATED => RETRYING Apr 13 13:19:39 charon 13[CHD] <con4000|13> CHILD_SA con4000{1189} state change: RETRYING => DESTROYING Apr 13 13:19:39 charon 13[IKE] <con4000|13> reinitiating already active tasks Apr 13 13:19:39 charon 13[IKE] <con4000|13> CHILD_REKEY task
I already tried afew things like adding more proposals, activating rekeying on my side with 180s margin, pinging a host for keep-alive in the remote subnet.
Nothing works, I can't get Phase 2 up again except when I disconnect Phase 1 under "Status -> IPsec" and reconnect manually. Starting then, it works exactly 3600s and disconnects.I would really appreciate if someone could point me in the right direction or tell me if it's even on my side or the remote side. I can't reach someone until monday to check the remote sid, but I would like to exclude errors on my side before getting them involved!
Thanks
-
@schossel
Hey
I will assume that during the rekeying , due to the fact that the message includes KEi payload , the message size exceeds 1500 bytes.generating CREATE_CHILD_SA request 411 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ]
sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (2608 bytes)And since the remote peer may not support message fragmentation , the CREATE_CHILD_SA request will not be fully received, and DH the public key will not be accepted by the remote peer
-
Solution? MSS clamping, setting MTU down?
Why does it work the first time it's connecting?For what it's worth (I can't really say what the effects are) it's running for more than 2 hours at the moment because I read somewhere that someone with a similar problem tried to set PFS group to "off".
This seems to get around this error
[IKE] <con4000|13> peer didn't accept DH group ECP_256, it requested ECP_256
I don't know if it is "allowed" to just set it to "off" but it's running. -
@schossel said in IPSEC Phase 2 disconnects after 1 hour and does not reconnect:
If possible , for example , set PFS group to "NONE" in phase 2
Why it works when establishing a connection I don't know
Need to watch the logs
Or , alternatively , try from the PF to increase the SA lifetime to a remote peer has initiated the rekeying -
Like I said, I set PFS group to "off" and it's running for 2 hours now.
-
As I was testing with PFS "off", I thought to myself "Perphaps they configured more groups except PFS 19" and I just tried with PFS group 14 and I think I was right. They told me 19 but 14 seems to exist, too. As far as I can tell, it works with 14 as expected, after 1 hour the rekey starts and seems to work fine. The MTU is not too big and a new child_sa is created.
Apr 13 19:19:32 charon 06[CHD] <con4000|30> CHILD_SA con4000{1584} state change: INSTALLING => INSTALLED Apr 13 19:19:32 charon 06[IKE] <con4000|30> CHILD_SA con4000{1584} established with SPIs c25045b2_i 495408d7_o and TS 10.207.239.61/32|192.168.1.0/24 === 10.11.0.0/11|/0 Apr 13 19:19:32 charon 06[CHD] <con4000|30> SPI 0x495408d7, src 213.34.11.17 dst 185.121.192.8 Apr 13 19:19:32 charon 06[CHD] <con4000|30> adding outbound ESP SA Apr 13 19:19:32 charon 06[CHD] <con4000|30> SPI 0xc25045b2, src 185.121.192.8 dst 213.34.11.17 Apr 13 19:19:32 charon 06[CHD] <con4000|30> adding inbound ESP SA Apr 13 19:19:32 charon 06[CHD] <con4000|30> using HMAC_SHA2_256_128 for integrity Apr 13 19:19:32 charon 06[CHD] <con4000|30> using AES_CBC for encryption Apr 13 19:19:32 charon 06[CHD] <con4000|30> CHILD_SA con4000{1584} state change: CREATED => INSTALLING Apr 13 19:19:32 charon 06[CFG] <con4000|30> config: 10.11.0.0/11|/0, received: 10.11.0.0/11|/0 => match: 10.11.0.0/11|/0 Apr 13 19:19:32 charon 06[CFG] <con4000|30> selecting traffic selectors for other: Apr 13 19:19:32 charon 06[CFG] <con4000|30> config: 10.207.239.61/32|192.168.1.0/24, received: 10.207.239.61/32|/0 => match: 10.207.239.61/32|192.168.1.0/24 Apr 13 19:19:32 charon 06[CFG] <con4000|30> selecting traffic selectors for us: Apr 13 19:19:32 charon 06[CFG] <con4000|30> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ Apr 13 19:19:32 charon 06[CFG] <con4000|30> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ Apr 13 19:19:32 charon 06[CFG] <con4000|30> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ Apr 13 19:19:32 charon 06[CFG] <con4000|30> proposal matches Apr 13 19:19:32 charon 06[CFG] <con4000|30> selecting proposal: Apr 13 19:19:32 charon 06[IKE] <con4000|30> received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding Apr 13 19:19:32 charon 06[IKE] <con4000|30> received NON_FIRST_FRAGMENTS_ALSO notify Apr 13 19:19:32 charon 06[IKE] <con4000|30> received ESP_TFC_PADDING_NOT_SUPPORTED notify Apr 13 19:19:32 charon 06[ENC] <con4000|30> parsed CREATE_CHILD_SA response 2 [ SA No KE TSi TSr N(ESP_TFC_PAD_N) N(NON_FIRST_FRAG) ] Apr 13 19:19:32 charon 06[NET] <con4000|30> received packet: from 185.121.192.8[500] to 213.34.11.17[500] (480 bytes) Apr 13 19:19:32 charon 06[NET] <con4000|30> sending packet: from 213.34.11.17[500] to 185.121.192.8[500] (480 bytes) Apr 13 19:19:32 charon 06[ENC] <con4000|30> generating CREATE_CHILD_SA request 2 [ N(ESP_TFC_PAD_N) SA No KE TSi TSr ] Apr 13 19:19:32 charon 06[IKE] <con4000|30> establishing CHILD_SA con4000{1584} reqid 70 Apr 13 19:19:32 charon 06[CFG] <con4000|30> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ Apr 13 19:19:32 charon 06[CFG] <con4000|30> 10.11.0.0/11|/0 Apr 13 19:19:32 charon 06[CFG] <con4000|30> proposing traffic selectors for other: Apr 13 19:19:32 charon 06[CFG] <con4000|30> 10.207.239.61/32|192.168.1.0/24 Apr 13 19:19:32 charon 06[CFG] <con4000|30> proposing traffic selectors for us: Apr 13 19:19:32 charon 06[IKE] <con4000|30> activating CHILD_CREATE task Apr 13 19:19:32 charon 06[IKE] <con4000|30> activating new tasks
I'll let it run through the night to see if it works but I'm pretty confident that it will. I don't know why PFS group 19 raises this problems I described above but if it works with 14, this should be a problem for another day.