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:
    alt text
    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:
    alt text
    alt text

    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.


Log in to reply