Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    IPsec site to site dropping every 49-55 minutes

    Scheduled Pinned Locked Moved IPsec
    44 Posts 4 Posters 1.1k Views
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • T
      TheStormsOfFury
      last edited by TheStormsOfFury

      We have other issues we're still working on with speeds; however, we have two sites (Site A and Site B) with different service providers (Site A = Cox and Site B = ATT), and for some odd reason around the 49-55 minute mark the tunnel will fail for 25-45 seconds and then resume.

      We are running CARP and both sites are running identical hardware (Dell R620) with pfSense 24.11-RELEASE.

      Here is the IPsec configuration (Anything not mentioned is default, or not enabled, EXCEPT PSK), and they are identical across all devices:

      Phase 1:
      Key exchange Version: IKEv2
      Authentication Method: Mutual PSK
      My Identifier: My IP Address
      Peer Identifier: Peer IP Address
      Encryption Algorithm:

      • Algorithm: AES
      • Key Length: 256 bits
      • Hash: SHA256
      • DH Group: 14 (2048 bit)
        Expiration life Time: 3600
        Expiration Rekey Time: 3240
        Expiration ReAuth Time: 3240
        Expiration Rand Time: 360
        Child SA Start Action: Default
        Child SA Close Action: Restart/Reconnect
        Dead Peer Detection: Enabled

      Phase 2 (There are two phase two entries and both are identical aside from the "Networks" section):

      Protocol: ESP
      Encryption Algorithms: AES256-GCM (128 bits)
      PFS Key Group: 14 (1028 bits)
      Expiration Life Time: 3960
      Expiration Rekey Time: 3600
      Expiration Rand Time: 360

      In system_advanced_firewall:
      Enable Maximum MSS: Enabled
      Maximum MSS: 1400

      In system_advanced_misc:
      IPsec-MB: Enabled

      Both of these system's processors support "Intel AES-NI" and it is enabled in BIOS; however, when I enable it under "Cryptographic Hardware (AES-NI CPU-Based Acceleration) it actually kept the tunnel from connecting. I even tried disabling "IPsec-MB", but the problem still persisted until I disabled the AES-NI CPU-Based Acceleration. Should this have happened? Or does it require a reboot to take effect?

      I did try bumping the Expiration times; however, that caused some massive headaches and the tunnel would go down hard every 3 hours or so for about 5 minutes.

      Edit: I should also mention that the times and timezones are synched across all devices as well.

      Thanks in advance!

      TSoF

      V M 2 Replies Last reply Reply Quote 0
      • T
        TheStormsOfFury
        last edited by

        I thought this morning when I changed it back to the lower Expiration times the issue was fine, but I have run into an issue where it is trying to create multiple Phase one tunnels and then you've got 2 tunnels which effectively kills the vpn.

        I added 10 seconds to everything on phase 1 and both phase 2's for the Site A, and restarted the services, and now i'm waiting for the time to hit again to see if this might resolve the issue.

        OpenVPN is way to slow ... IPSec is not usable if we're going to have these problems. is L2TP better or Wireguard VPN?

        TIA

        TSoF

        1 Reply Last reply Reply Quote 0
        • T
          TheStormsOfFury
          last edited by

          Just now at 49 minutes it did the same thing and started creating additional tunnel instances which killed the site to site link.

          Open to suggestions!

          Thanks again.
          TSoF

          1 Reply Last reply Reply Quote 0
          • V
            viragomann @TheStormsOfFury
            last edited by

            @TheStormsOfFury said in IPsec site to site dropping every 49-55 minutes:

            Both of these system's processors support "Intel AES-NI" and it is enabled in BIOS; however, when I enable it under "Cryptographic Hardware (AES-NI CPU-Based Acceleration) it actually kept the tunnel from connecting.

            Strange. I have it enabled and no problems with IPSec, even I have similar encryption settings.

            Or does it require a reboot to take effect?

            It needs a reboot though, but I don't expect that IPSec doesn't work till then.

            However, why are you using different encryption settings in p1 and p2?

            I would try a much higher live time in the phase 1 than in the p2. It should be a multiple.
            I have 28800 in p1 and 3600 in p2.
            Also I have Rekey Time, ReAuth Time and Rand Time blank. So the values are set automatically. But if you want a short Rekey Time due to security concerns you have to specify a shorter value.

            T 4 Replies Last reply Reply Quote 0
            • T
              TheStormsOfFury @viragomann
              last edited by

              @viragomann I'm going to make those changes now and i'll let you know how it goes.

              Thanks for the suggestions

              TSoF

              1 Reply Last reply Reply Quote 0
              • T
                TheStormsOfFury @viragomann
                last edited by

                @viragomann said in IPsec site to site dropping every 49-55 minutes:

                However, why are you using different encryption settings in p1 and p2?

                I meant to address this a moment ago. So I honestly followed the instructions on the official documentation here and it shows AES standard on P1 and AES256-GCm on phase 2.

                I actually did try matching it once and I think there were issues.

                The biggest issues now is that it's loosing it's mind at that 49-55 minute mark and i'm having to reset the VPn which shouldn't be happening.

                Thanks again!

                TSoF

                1 Reply Last reply Reply Quote 0
                • T
                  TheStormsOfFury @viragomann
                  last edited by

                  @viragomann said in IPsec site to site dropping every 49-55 minutes:

                  I have 28800 in p1 and 3600 in p2.

                  I now have this set AND i went ahead and changed my phase 2 encryption to AES ... 256 bit ... SHA256 to match the Phase 1 encryption.

                  Let's see what happens in 49-55 minutes!

                  Thanks again!

                  TSoF

                  1 Reply Last reply Reply Quote 0
                  • T
                    TheStormsOfFury @viragomann
                    last edited by

                    @viragomann So I just caught it right as it happened, and here are the log files. it looks like I lost site to site ping at 18:31:19 (earliest reported at Site B) and it came back at 18:32:03 (also Site B). Not down for long, but that does cause the drop in phones and issues across the sites.

                    Any ideas?

                    Here are the logs:

                    Site A (18:31:20 hours to 18:32:02) and here are the ipsec logs (Newest to Oldest)

                    Apr 8 18:32:53	charon	25819	12[CFG] vici client 3498 disconnected
                    Apr 8 18:32:53	charon	25819	12[CFG] vici client 3498 requests: list-sas
                    Apr 8 18:32:53	charon	25819	12[CFG] vici client 3498 registered for: list-sa
                    Apr 8 18:32:53	charon	25819	10[CFG] vici client 3498 connected
                    Apr 8 18:32:47	charon	25819	10[CFG] vici client 3497 disconnected
                    Apr 8 18:32:47	charon	25819	14[CFG] vici client 3497 requests: list-sas
                    Apr 8 18:32:47	charon	25819	11[CFG] vici client 3497 registered for: list-sa
                    Apr 8 18:32:47	charon	25819	11[CFG] vici client 3497 connected
                    Apr 8 18:32:42	charon	25819	10[CFG] vici client 3496 disconnected
                    Apr 8 18:32:42	charon	25819	11[CFG] vici client 3496 requests: list-sas
                    Apr 8 18:32:42	charon	25819	11[CFG] vici client 3496 registered for: list-sa
                    Apr 8 18:32:42	charon	25819	11[CFG] vici client 3496 connected
                    Apr 8 18:32:39	charon	25819	07[IKE] <con1|1> nothing to initiate
                    Apr 8 18:32:39	charon	25819	07[IKE] <con1|1> activating new tasks
                    Apr 8 18:32:39	charon	25819	07[ENC] <con1|1> parsed INFORMATIONAL response 18 [ ]
                    Apr 8 18:32:39	charon	25819	07[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                    Apr 8 18:32:39	charon	25819	07[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                    Apr 8 18:32:39	charon	25819	07[ENC] <con1|1> generating INFORMATIONAL request 18 [ ]
                    Apr 8 18:32:39	charon	25819	07[IKE] <con1|1> activating IKE_DPD task
                    Apr 8 18:32:39	charon	25819	07[IKE] <con1|1> activating new tasks
                    Apr 8 18:32:39	charon	25819	07[IKE] <con1|1> queueing IKE_DPD task
                    Apr 8 18:32:39	charon	25819	07[IKE] <con1|1> sending DPD request
                    Apr 8 18:32:37	charon	25819	07[CFG] vici client 3495 disconnected
                    Apr 8 18:32:37	charon	25819	11[CFG] vici client 3495 requests: list-sas
                    Apr 8 18:32:37	charon	25819	11[CFG] vici client 3495 registered for: list-sa
                    Apr 8 18:32:37	charon	25819	07[CFG] vici client 3495 connected
                    Apr 8 18:32:32	charon	25819	05[CFG] vici client 3494 disconnected
                    Apr 8 18:32:32	charon	25819	11[CFG] vici client 3494 requests: list-sas
                    Apr 8 18:32:32	charon	25819	11[CFG] vici client 3494 registered for: list-sa
                    Apr 8 18:32:32	charon	25819	07[CFG] vici client 3494 connected
                    Apr 8 18:32:29	charon	25819	11[IKE] <con1|1> nothing to initiate
                    Apr 8 18:32:29	charon	25819	11[IKE] <con1|1> activating new tasks
                    Apr 8 18:32:29	charon	25819	11[ENC] <con1|1> parsed INFORMATIONAL response 17 [ ]
                    Apr 8 18:32:29	charon	25819	11[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                    Apr 8 18:32:29	charon	25819	11[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                    Apr 8 18:32:29	charon	25819	11[ENC] <con1|1> generating INFORMATIONAL request 17 [ ]
                    Apr 8 18:32:29	charon	25819	11[IKE] <con1|1> activating IKE_DPD task
                    Apr 8 18:32:29	charon	25819	11[IKE] <con1|1> activating new tasks
                    Apr 8 18:32:29	charon	25819	11[IKE] <con1|1> queueing IKE_DPD task
                    Apr 8 18:32:29	charon	25819	11[IKE] <con1|1> sending DPD request
                    Apr 8 18:32:27	charon	25819	11[CFG] vici client 3493 disconnected
                    Apr 8 18:32:27	charon	25819	09[CFG] vici client 3493 requests: list-sas
                    Apr 8 18:32:27	charon	25819	09[CFG] vici client 3493 registered for: list-sa
                    Apr 8 18:32:27	charon	25819	07[CFG] vici client 3493 connected
                    Apr 8 18:32:22	charon	25819	09[CFG] vici client 3492 disconnected
                    Apr 8 18:32:22	charon	25819	07[CFG] vici client 3492 requests: list-sas
                    Apr 8 18:32:22	charon	25819	16[CFG] vici client 3492 registered for: list-sa
                    Apr 8 18:32:22	charon	25819	09[CFG] vici client 3492 connected
                    Apr 8 18:32:19	charon	25819	16[IKE] <con1|1> nothing to initiate
                    Apr 8 18:32:19	charon	25819	16[IKE] <con1|1> activating new tasks
                    Apr 8 18:32:19	charon	25819	16[ENC] <con1|1> parsed INFORMATIONAL response 16 [ ]
                    Apr 8 18:32:19	charon	25819	16[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                    Apr 8 18:32:19	charon	25819	16[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                    Apr 8 18:32:19	charon	25819	16[ENC] <con1|1> generating INFORMATIONAL request 16 [ ]
                    Apr 8 18:32:19	charon	25819	16[IKE] <con1|1> activating IKE_DPD task
                    Apr 8 18:32:19	charon	25819	16[IKE] <con1|1> activating new tasks
                    Apr 8 18:32:19	charon	25819	16[IKE] <con1|1> queueing IKE_DPD task
                    Apr 8 18:32:19	charon	25819	16[IKE] <con1|1> sending DPD request
                    Apr 8 18:32:16	charon	25819	16[CFG] vici client 3491 disconnected
                    Apr 8 18:32:16	charon	25819	16[CFG] vici client 3491 requests: list-sas
                    Apr 8 18:32:16	charon	25819	16[CFG] vici client 3491 registered for: list-sa
                    Apr 8 18:32:16	charon	25819	16[CFG] vici client 3491 connected
                    Apr 8 18:32:14	charon	25819	16[CFG] vici client 3490 disconnected
                    Apr 8 18:32:14	charon	25819	13[CFG] vici client 3490 requests: list-sas
                    Apr 8 18:32:14	charon	25819	13[CFG] vici client 3490 registered for: list-sa
                    Apr 8 18:32:14	charon	25819	13[CFG] vici client 3490 connected
                    Apr 8 18:32:11	charon	25819	15[CFG] vici client 3489 disconnected
                    Apr 8 18:32:11	charon	25819	15[CFG] vici client 3489 requests: list-sas
                    Apr 8 18:32:11	charon	25819	15[CFG] vici client 3489 registered for: list-sa
                    Apr 8 18:32:11	charon	25819	13[CFG] vici client 3489 connected
                    Apr 8 18:32:09	charon	25819	15[IKE] <con1|1> nothing to initiate
                    Apr 8 18:32:09	charon	25819	15[IKE] <con1|1> activating new tasks
                    Apr 8 18:32:09	charon	25819	15[ENC] <con1|1> parsed INFORMATIONAL response 15 [ ]
                    Apr 8 18:32:09	charon	25819	15[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                    Apr 8 18:32:09	charon	25819	15[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                    Apr 8 18:32:09	charon	25819	15[ENC] <con1|1> generating INFORMATIONAL request 15 [ ]
                    Apr 8 18:32:09	charon	25819	15[IKE] <con1|1> activating IKE_DPD task
                    Apr 8 18:32:09	charon	25819	15[IKE] <con1|1> activating new tasks
                    Apr 8 18:32:09	charon	25819	15[IKE] <con1|1> queueing IKE_DPD task
                    Apr 8 18:32:09	charon	25819	15[IKE] <con1|1> sending DPD request
                    Apr 8 18:32:06	charon	25819	08[CFG] vici client 3488 disconnected
                    Apr 8 18:32:06	charon	25819	15[CFG] vici client 3488 requests: list-sas
                    Apr 8 18:32:06	charon	25819	15[CFG] vici client 3488 registered for: list-sa
                    Apr 8 18:32:06	charon	25819	08[CFG] vici client 3488 connected
                    Apr 8 18:32:04	charon	25819	15[IKE] <con1|1> nothing to initiate
                    Apr 8 18:32:04	charon	25819	15[IKE] <con1|1> activating new tasks
                    Apr 8 18:32:04	charon	25819	15[CHD] <con1|1> CHILD_SA con1{4} state change: DELETED => DESTROYING
                    Apr 8 18:32:04	charon	25819	15[IKE] <con1|1> activating CHILD_DELETE task
                    Apr 8 18:32:04	charon	25819	15[IKE] <con1|1> activating new tasks
                    Apr 8 18:32:04	charon	25819	15[IKE] <con1|1> queueing CHILD_DELETE task
                    Apr 8 18:32:01	charon	25819	06[CFG] vici client 3487 disconnected
                    Apr 8 18:32:01	charon	25819	15[CFG] vici client 3487 requests: list-sas
                    Apr 8 18:32:01	charon	25819	15[CFG] vici client 3487 registered for: list-sa
                    Apr 8 18:32:01	charon	25819	08[CFG] vici client 3487 connected
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> nothing to initiate
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> activating new tasks
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> CHILD_SA con1{4} state change: DELETING => DELETED
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> CHILD_SA closed
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> received DELETE for ESP CHILD_SA with SPI cd203610
                    Apr 8 18:31:59	charon	25819	15[ENC] <con1|1> parsed INFORMATIONAL response 14 [ D ]
                    Apr 8 18:31:59	charon	25819	15[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                    Apr 8 18:31:59	charon	25819	15[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                    Apr 8 18:31:59	charon	25819	15[ENC] <con1|1> generating INFORMATIONAL request 14 [ D ]
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> CHILD_SA con1{4} state change: REKEYED => DELETING
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> sending DELETE for ESP CHILD_SA with SPI c2676e62
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> closing CHILD_SA con1{4} with SPIs c2676e62_i (49700865 bytes) cd203610_o (76839736 bytes) and TS 10.1.0.0/16|/0 === 10.0.1.0/24|/0 10.2.0.0/16|/0
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> CHILD_REKEY task
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> reinitiating already active tasks
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> CHILD_SA con1{4} state change: REKEYING => REKEYED
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> outbound CHILD_SA con1{5} established with SPIs c0473839_i c5258feb_o and TS 10.1.0.0/16|/0 === 10.0.1.0/24|/0 10.2.0.0/16|/0
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> SPI 0xc5258feb, src 207.162.137.151 dst 75.61.85.193
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> adding outbound ESP SA
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> CHILD_SA con1{5} state change: INSTALLING => INSTALLED
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> inbound CHILD_SA con1{5} established with SPIs c0473839_i c5258feb_o and TS 10.1.0.0/16|/0 === 10.0.1.0/24|/0 10.2.0.0/16|/0
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> SPI 0xc5258feb, src 207.162.137.151 dst 75.61.85.193
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> registering outbound ESP SA
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> SPI 0xc0473839, src 75.61.85.193 dst 207.162.137.151
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> adding inbound ESP SA
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> using HMAC_SHA2_256_128 for integrity
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> using AES_CBC for encryption
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> CHILD_SA con1{5} state change: CREATED => INSTALLING
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> config: 10.0.1.0/24|/0, received: 10.0.1.0/24|/0 => match: 10.0.1.0/24|/0
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> config: 10.0.1.0/24|/0, received: 10.2.0.0/16|/0 => no match
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> config: 10.2.0.0/16|/0, received: 10.0.1.0/24|/0 => no match
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> config: 10.2.0.0/16|/0, received: 10.2.0.0/16|/0 => match: 10.2.0.0/16|/0
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> selecting traffic selectors for other:
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> config: 10.1.0.0/16|/0, received: 10.1.0.0/16|/0 => match: 10.1.0.0/16|/0
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> config: 10.1.0.0/16|/0, received: 10.1.0.0/16|/0 => match: 10.1.0.0/16|/0
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> selecting traffic selectors for us:
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> proposal matches
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> selecting proposal:
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> received ESP_TFC_PADDING_NOT_SUPPORTED notify
                    Apr 8 18:31:59	charon	25819	15[ENC] <con1|1> parsed CREATE_CHILD_SA response 13 [ N(ESP_TFC_PAD_N) SA No KE TSi TSr ]
                    Apr 8 18:31:59	charon	25819	15[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (496 bytes)
                    Apr 8 18:31:59	charon	25819	15[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (512 bytes)
                    Apr 8 18:31:59	charon	25819	15[ENC] <con1|1> generating CREATE_CHILD_SA request 13 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ]
                    Apr 8 18:31:59	charon	25819	15[CHD] <con1|1> CHILD_SA con1{4} state change: INSTALLED => REKEYING
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> establishing CHILD_SA con1{5} reqid 1
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> 10.0.1.0/24|/0
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> 10.2.0.0/16|/0
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> proposing traffic selectors for other:
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> 10.1.0.0/16|/0
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> 10.1.0.0/16|/0
                    Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> proposing traffic selectors for us:
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> activating CHILD_REKEY task
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> activating new tasks
                    Apr 8 18:31:59	charon	25819	15[IKE] <con1|1> queueing CHILD_REKEY task
                    Apr 8 18:31:59	charon	25819	12[KNL] creating rekey job for CHILD_SA ESP/0xcd203610/75.61.85.193
                    Apr 8 18:31:56	charon	25819	12[CFG] vici client 3486 disconnected
                    Apr 8 18:31:56	charon	25819	12[CFG] vici client 3486 requests: list-sas
                    Apr 8 18:31:56	charon	25819	12[CFG] vici client 3486 registered for: list-sa
                    Apr 8 18:31:56	charon	25819	12[CFG] vici client 3486 connected
                    Apr 8 18:31:51	charon	25819	14[CFG] vici client 3485 disconnected
                    Apr 8 18:31:51	charon	25819	12[CFG] vici client 3485 requests: list-sas
                    Apr 8 18:31:51	charon	25819	12[CFG] vici client 3485 registered for: list-sa
                    Apr 8 18:31:51	charon	25819	15[CFG] vici client 3485 connected
                    Apr 8 18:31:46	charon	25819	12[CFG] vici client 3484 disconnected
                    Apr 8 18:31:46	charon	25819	15[CFG] vici client 3484 requests: list-sas
                    Apr 8 18:31:46	charon	25819	15[CFG] vici client 3484 registered for: list-sa
                    Apr 8 18:31:46	charon	25819	10[CFG] vici client 3484 connected
                    Apr 8 18:31:41	charon	25819	15[CFG] vici client 3483 disconnected
                    Apr 8 18:31:41	charon	25819	15[CFG] vici client 3483 requests: list-sas
                    Apr 8 18:31:41	charon	25819	15[CFG] vici client 3483 registered for: list-sa
                    Apr 8 18:31:41	charon	25819	05[CFG] vici client 3483 connected
                    Apr 8 18:31:36	charon	25819	15[CFG] vici client 3482 disconnected
                    Apr 8 18:31:36	charon	25819	05[CFG] vici client 3482 requests: list-sas
                    Apr 8 18:31:36	charon	25819	11[CFG] vici client 3482 registered for: list-sa
                    Apr 8 18:31:36	charon	25819	05[CFG] vici client 3482 connected
                    Apr 8 18:31:31	charon	25819	11[CFG] vici client 3481 disconnected
                    Apr 8 18:31:31	charon	25819	05[CFG] vici client 3481 requests: list-sas
                    Apr 8 18:31:31	charon	25819	05[CFG] vici client 3481 registered for: list-sa
                    Apr 8 18:31:31	charon	25819	15[CFG] vici client 3481 connected
                    Apr 8 18:31:25	charon	25819	07[CFG] vici client 3480 disconnected
                    Apr 8 18:31:25	charon	25819	05[CFG] vici client 3480 requests: list-sas
                    Apr 8 18:31:25	charon	25819	05[CFG] vici client 3480 registered for: list-sa
                    Apr 8 18:31:25	charon	25819	05[CFG] vici client 3480 connected
                    Apr 8 18:31:20	charon	25819	07[CFG] vici client 3479 disconnected
                    Apr 8 18:31:20	charon	25819	16[CFG] vici client 3479 requests: list-sas
                    Apr 8 18:31:20	charon	25819	05[CFG] vici client 3479 registered for: list-sa
                    Apr 8 18:31:20	charon	25819	07[CFG] vici client 3479 connected
                    Apr 8 18:31:15	charon	25819	05[CFG] vici client 3478 disconnected
                    Apr 8 18:31:15	charon	25819	07[CFG] vici client 3478 requests: list-sas
                    Apr 8 18:31:15	charon	25819	05[CFG] vici client 3478 registered for: list-sa
                    Apr 8 18:31:15	charon	25819	05[CFG] vici client 3478 connected
                    Apr 8 18:31:10	charon	25819	09[CFG] vici client 3477 disconnected
                    Apr 8 18:31:10	charon	25819	05[CFG] vici client 3477 requests: list-sas
                    Apr 8 18:31:10	charon	25819	05[CFG] vici client 3477 registered for: list-sa
                    Apr 8 18:31:10	charon	25819	13[CFG] vici client 3477 connected
                    Apr 8 18:31:05	charon	25819	05[CFG] vici client 3476 disconnected
                    Apr 8 18:31:05	charon	25819	13[CFG] vici client 3476 requests: list-sas
                    Apr 8 18:31:05	charon	25819	13[CFG] vici client 3476 registered for: list-sa
                    Apr 8 18:31:05	charon	25819	13[CFG] vici client 3476 connected
                    Apr 8 18:31:00	charon	25819	05[CFG] vici client 3475 disconnected
                    Apr 8 18:31:00	charon	25819	05[CFG] vici client 3475 requests: list-sas
                    Apr 8 18:31:00	charon	25819	05[CFG] vici client 3475 registered for: list-sa
                    Apr 8 18:31:00	charon	25819	05[CFG] vici client 3475 connected
                    

                    Site B (18:31:19 hours to 18:32:03 Hours) and here are the ipsec logs (Newest to Oldest)

                    Apr 8 18:32:53	charon	93875	07[CFG] vici client 3219 disconnected
                    Apr 8 18:32:53	charon	93875	07[CFG] vici client 3219 requests: list-sas
                    Apr 8 18:32:53	charon	93875	07[CFG] vici client 3219 registered for: list-sa
                    Apr 8 18:32:53	charon	93875	06[CFG] vici client 3219 connected
                    Apr 8 18:32:47	charon	93875	06[CFG] vici client 3218 disconnected
                    Apr 8 18:32:47	charon	93875	06[CFG] vici client 3218 requests: list-sas
                    Apr 8 18:32:47	charon	93875	06[CFG] vici client 3218 registered for: list-sa
                    Apr 8 18:32:47	charon	93875	06[CFG] vici client 3218 connected
                    Apr 8 18:32:41	charon	93875	06[CFG] vici client 3217 disconnected
                    Apr 8 18:32:41	charon	93875	05[CFG] vici client 3217 requests: list-sas
                    Apr 8 18:32:41	charon	93875	05[CFG] vici client 3217 registered for: list-sa
                    Apr 8 18:32:41	charon	93875	06[CFG] vici client 3217 connected
                    Apr 8 18:32:39	charon	93875	05[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                    Apr 8 18:32:39	charon	93875	05[ENC] <con1|1> generating INFORMATIONAL response 18 [ ]
                    Apr 8 18:32:39	charon	93875	05[ENC] <con1|1> parsed INFORMATIONAL request 18 [ ]
                    Apr 8 18:32:39	charon	93875	05[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                    Apr 8 18:32:36	charon	93875	05[CFG] vici client 3216 disconnected
                    Apr 8 18:32:36	charon	93875	15[CFG] vici client 3216 requests: list-sas
                    Apr 8 18:32:36	charon	93875	15[CFG] vici client 3216 registered for: list-sa
                    Apr 8 18:32:36	charon	93875	06[CFG] vici client 3216 connected
                    Apr 8 18:32:31	charon	93875	15[CFG] vici client 3215 disconnected
                    Apr 8 18:32:31	charon	93875	06[CFG] vici client 3215 requests: list-sas
                    Apr 8 18:32:31	charon	93875	15[CFG] vici client 3215 registered for: list-sa
                    Apr 8 18:32:31	charon	93875	13[CFG] vici client 3215 connected
                    Apr 8 18:32:29	charon	93875	15[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                    Apr 8 18:32:29	charon	93875	15[ENC] <con1|1> generating INFORMATIONAL response 17 [ ]
                    Apr 8 18:32:29	charon	93875	15[ENC] <con1|1> parsed INFORMATIONAL request 17 [ ]
                    Apr 8 18:32:29	charon	93875	15[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                    Apr 8 18:32:25	charon	93875	15[CFG] vici client 3214 disconnected
                    Apr 8 18:32:25	charon	93875	13[CFG] vici client 3214 requests: list-sas
                    Apr 8 18:32:25	charon	93875	13[CFG] vici client 3214 registered for: list-sa
                    Apr 8 18:32:25	charon	93875	16[CFG] vici client 3214 connected
                    Apr 8 18:32:20	charon	93875	13[CFG] vici client 3213 disconnected
                    Apr 8 18:32:20	charon	93875	16[CFG] vici client 3213 requests: list-sas
                    Apr 8 18:32:20	charon	93875	16[CFG] vici client 3213 registered for: list-sa
                    Apr 8 18:32:20	charon	93875	15[CFG] vici client 3213 connected
                    Apr 8 18:32:19	charon	93875	16[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                    Apr 8 18:32:19	charon	93875	16[ENC] <con1|1> generating INFORMATIONAL response 16 [ ]
                    Apr 8 18:32:19	charon	93875	16[ENC] <con1|1> parsed INFORMATIONAL request 16 [ ]
                    Apr 8 18:32:19	charon	93875	16[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                    Apr 8 18:32:15	charon	93875	11[CFG] vici client 3212 disconnected
                    Apr 8 18:32:15	charon	93875	11[CFG] vici client 3212 requests: list-sas
                    Apr 8 18:32:15	charon	93875	11[CFG] vici client 3212 registered for: list-sa
                    Apr 8 18:32:15	charon	93875	11[CFG] vici client 3212 connected
                    Apr 8 18:32:10	charon	93875	11[CFG] vici client 3211 disconnected
                    Apr 8 18:32:10	charon	93875	14[CFG] vici client 3211 requests: list-sas
                    Apr 8 18:32:10	charon	93875	14[CFG] vici client 3211 registered for: list-sa
                    Apr 8 18:32:10	charon	93875	14[CFG] vici client 3211 connected
                    Apr 8 18:32:09	charon	93875	11[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                    Apr 8 18:32:09	charon	93875	11[ENC] <con1|1> generating INFORMATIONAL response 15 [ ]
                    Apr 8 18:32:09	charon	93875	11[ENC] <con1|1> parsed INFORMATIONAL request 15 [ ]
                    Apr 8 18:32:09	charon	93875	11[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                    Apr 8 18:32:05	charon	93875	11[CFG] vici client 3210 disconnected
                    Apr 8 18:32:05	charon	93875	11[CFG] vici client 3210 requests: list-sas
                    Apr 8 18:32:05	charon	93875	11[CFG] vici client 3210 registered for: list-sa
                    Apr 8 18:32:05	charon	93875	09[CFG] vici client 3210 connected
                    Apr 8 18:32:04	charon	93875	09[IKE] <con1|1> nothing to initiate
                    Apr 8 18:32:04	charon	93875	09[IKE] <con1|1> activating new tasks
                    Apr 8 18:32:04	charon	93875	09[CHD] <con1|1> CHILD_SA con1{4} state change: DELETED => DESTROYING
                    Apr 8 18:32:04	charon	93875	09[IKE] <con1|1> activating CHILD_DELETE task
                    Apr 8 18:32:04	charon	93875	09[IKE] <con1|1> activating new tasks
                    Apr 8 18:32:04	charon	93875	09[IKE] <con1|1> queueing CHILD_DELETE task
                    Apr 8 18:32:00	charon	93875	09[CFG] vici client 3209 disconnected
                    Apr 8 18:32:00	charon	93875	09[CFG] vici client 3209 requests: list-sas
                    Apr 8 18:32:00	charon	93875	09[CFG] vici client 3209 registered for: list-sa
                    Apr 8 18:32:00	charon	93875	08[CFG] vici client 3209 connected
                    Apr 8 18:31:59	charon	93875	09[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                    Apr 8 18:31:59	charon	93875	09[ENC] <con1|1> generating INFORMATIONAL response 14 [ D ]
                    Apr 8 18:31:59	charon	93875	09[IKE] <con1|1> outbound CHILD_SA con1{5} established with SPIs c5258feb_i c0473839_o and TS 10.0.1.0/24|/0 10.2.0.0/16|/0 === 10.1.0.0/16|/0
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> SPI 0xc0473839, src 75.61.85.193 dst 207.162.137.151
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> adding outbound ESP SA
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> CHILD_SA con1{4} state change: DELETING => DELETED
                    Apr 8 18:31:59	charon	93875	09[IKE] <con1|1> CHILD_SA closed
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> CHILD_SA con1{4} state change: REKEYED => DELETING
                    Apr 8 18:31:59	charon	93875	09[IKE] <con1|1> sending DELETE for ESP CHILD_SA with SPI cd203610
                    Apr 8 18:31:59	charon	93875	09[IKE] <con1|1> closing CHILD_SA con1{4} with SPIs cd203610_i (54453700 bytes) c2676e62_o (70115700 bytes) and TS 10.0.1.0/24|/0 10.2.0.0/16|/0 === 10.1.0.0/16|/0
                    Apr 8 18:31:59	charon	93875	09[IKE] <con1|1> received DELETE for ESP CHILD_SA with SPI c2676e62
                    Apr 8 18:31:59	charon	93875	09[ENC] <con1|1> parsed INFORMATIONAL request 14 [ D ]
                    Apr 8 18:31:59	charon	93875	09[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                    Apr 8 18:31:59	charon	93875	09[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (496 bytes)
                    Apr 8 18:31:59	charon	93875	09[ENC] <con1|1> generating CREATE_CHILD_SA response 13 [ N(ESP_TFC_PAD_N) SA No KE TSi TSr ]
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> CHILD_SA con1{4} state change: REKEYING => REKEYED
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> CHILD_SA con1{4} state change: INSTALLED => REKEYING
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> CHILD_SA con1{5} state change: INSTALLING => INSTALLED
                    Apr 8 18:31:59	charon	93875	09[IKE] <con1|1> inbound CHILD_SA con1{5} established with SPIs c5258feb_i c0473839_o and TS 10.0.1.0/24|/0 10.2.0.0/16|/0 === 10.1.0.0/16|/0
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> SPI 0xc0473839, src 75.61.85.193 dst 207.162.137.151
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> registering outbound ESP SA
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> SPI 0xc5258feb, src 207.162.137.151 dst 75.61.85.193
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> adding inbound ESP SA
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> using HMAC_SHA2_256_128 for integrity
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> using AES_CBC for encryption
                    Apr 8 18:31:59	charon	93875	09[CHD] <con1|1> CHILD_SA con1{5} state change: CREATED => INSTALLING
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> config: 10.1.0.0/16|/0, received: 10.1.0.0/16|/0 => match: 10.1.0.0/16|/0
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> config: 10.1.0.0/16|/0, received: 10.1.0.0/16|/0 => match: 10.1.0.0/16|/0
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> selecting traffic selectors for other:
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> config: 10.0.1.0/24|/0, received: 10.0.1.0/24|/0 => match: 10.0.1.0/24|/0
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> config: 10.0.1.0/24|/0, received: 10.2.0.0/16|/0 => no match
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> config: 10.2.0.0/16|/0, received: 10.0.1.0/24|/0 => no match
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> config: 10.2.0.0/16|/0, received: 10.2.0.0/16|/0 => match: 10.2.0.0/16|/0
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> selecting traffic selectors for us:
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> proposal matches
                    Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> selecting proposal:
                    Apr 8 18:31:59	charon	93875	09[IKE] <con1|1> received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
                    Apr 8 18:31:59	charon	93875	09[ENC] <con1|1> parsed CREATE_CHILD_SA request 13 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ]
                    Apr 8 18:31:59	charon	93875	09[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (512 bytes)
                    Apr 8 18:31:55	charon	93875	09[CFG] vici client 3208 disconnected
                    Apr 8 18:31:55	charon	93875	12[CFG] vici client 3208 requests: list-sas
                    Apr 8 18:31:55	charon	93875	08[CFG] vici client 3208 registered for: list-sa
                    Apr 8 18:31:55	charon	93875	08[CFG] vici client 3208 connected
                    Apr 8 18:31:49	charon	93875	08[CFG] vici client 3207 disconnected
                    Apr 8 18:31:49	charon	93875	12[CFG] vici client 3207 requests: list-sas
                    Apr 8 18:31:49	charon	93875	08[CFG] vici client 3207 registered for: list-sa
                    Apr 8 18:31:49	charon	93875	07[CFG] vici client 3207 connected
                    Apr 8 18:31:44	charon	93875	08[CFG] vici client 3206 disconnected
                    Apr 8 18:31:44	charon	93875	08[CFG] vici client 3206 requests: list-sas
                    Apr 8 18:31:44	charon	93875	08[CFG] vici client 3206 registered for: list-sa
                    Apr 8 18:31:44	charon	93875	08[CFG] vici client 3206 connected
                    Apr 8 18:31:39	charon	93875	08[CFG] vici client 3205 disconnected
                    Apr 8 18:31:39	charon	93875	10[CFG] vici client 3205 requests: list-sas
                    Apr 8 18:31:39	charon	93875	10[CFG] vici client 3205 registered for: list-sa
                    Apr 8 18:31:39	charon	93875	10[CFG] vici client 3205 connected
                    Apr 8 18:31:34	charon	93875	07[CFG] vici client 3204 disconnected
                    Apr 8 18:31:34	charon	93875	07[CFG] vici client 3204 requests: list-sas
                    Apr 8 18:31:34	charon	93875	07[CFG] vici client 3204 registered for: list-sa
                    Apr 8 18:31:34	charon	93875	05[CFG] vici client 3204 connected
                    Apr 8 18:31:29	charon	93875	07[CFG] vici client 3203 disconnected
                    Apr 8 18:31:29	charon	93875	07[CFG] vici client 3203 requests: list-sas
                    Apr 8 18:31:29	charon	93875	05[CFG] vici client 3203 registered for: list-sa
                    Apr 8 18:31:29	charon	93875	06[CFG] vici client 3203 connected
                    Apr 8 18:31:24	charon	93875	06[CFG] vici client 3202 disconnected
                    Apr 8 18:31:24	charon	93875	06[CFG] vici client 3202 requests: list-sas
                    Apr 8 18:31:24	charon	93875	06[CFG] vici client 3202 registered for: list-sa
                    Apr 8 18:31:24	charon	93875	13[CFG] vici client 3202 connected
                    Apr 8 18:31:19	charon	93875	06[CFG] vici client 3201 disconnected
                    Apr 8 18:31:19	charon	93875	06[CFG] vici client 3201 requests: list-sas
                    Apr 8 18:31:19	charon	93875	06[CFG] vici client 3201 registered for: list-sa
                    Apr 8 18:31:19	charon	93875	13[CFG] vici client 3201 connected
                    Apr 8 18:31:14	charon	93875	15[CFG] vici client 3200 disconnected
                    Apr 8 18:31:14	charon	93875	06[CFG] vici client 3200 requests: list-sas
                    Apr 8 18:31:14	charon	93875	06[CFG] vici client 3200 registered for: list-sa
                    Apr 8 18:31:14	charon	93875	06[CFG] vici client 3200 connected
                    Apr 8 18:31:08	charon	93875	06[CFG] vici client 3199 disconnected
                    Apr 8 18:31:08	charon	93875	15[CFG] vici client 3199 requests: list-sas
                    Apr 8 18:31:08	charon	93875	15[CFG] vici client 3199 registered for: list-sa
                    Apr 8 18:31:08	charon	93875	06[CFG] vici client 3199 connected
                    Apr 8 18:31:03	charon	93875	15[CFG] vici client 3198 disconnected
                    Apr 8 18:31:03	charon	93875	15[CFG] vici client 3198 requests: list-sas
                    Apr 8 18:31:03	charon	93875	06[CFG] vici client 3198 registered for: list-sa
                    Apr 8 18:31:03	charon	93875	14[CFG] vici client 3198 connected
                    
                    T 1 Reply Last reply Reply Quote 0
                    • T
                      TheStormsOfFury @TheStormsOfFury
                      last edited by

                      @Viragonmann

                      So I found this setting that says "Make before Break," and I am wondering if that is the issue I am running into as it is breaking, then renegotiating then reconnecting, which would cause that issue. So it is now enabled; however, my latency went way up for some reason.

                      My Phase One is:
                      Life Time: 28800
                      Rekey Time: 25920
                      Reauth Time: 0
                      Rand Time: 2880

                      Phy Phase Two(s) are:
                      Life Time: 4000
                      ReKey Time: 3600
                      Rand Time: 400

                      Now, in their instructions; it shows that these should match site-to-site. Is this the case in your experience?

                      A 1 Reply Last reply Reply Quote 0
                      • A
                        andrew_cb @TheStormsOfFury
                        last edited by

                        @TheStormsOfFury

                        On Site A:

                        Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> config: 10.0.1.0/24|/0, received: 10.0.1.0/24|/0 => match: 10.0.1.0/24|/0
                        Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> config: 10.0.1.0/24|/0, received: 10.2.0.0/16|/0 => no match
                        Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> config: 10.2.0.0/16|/0, received: 10.0.1.0/24|/0 => no match
                        Apr 8 18:31:59	charon	25819	15[CFG] <con1|1> config: 10.2.0.0/16|/0, received: 10.2.0.0/16|/0 => match: 10.2.0.0/16|/0
                        

                        On Site B:

                        
                        Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> config: 10.1.0.0/16|/0, received: 10.1.0.0/16|/0 => match: 10.1.0.0/16|/0
                        Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> config: 10.1.0.0/16|/0, received: 10.1.0.0/16|/0 => match: 10.1.0.0/16|/0
                        Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> selecting traffic selectors for other:
                        Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> config: 10.0.1.0/24|/0, received: 10.0.1.0/24|/0 => match: 10.0.1.0/24|/0
                        Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> config: 10.0.1.0/24|/0, received: 10.2.0.0/16|/0 => no match
                        Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> config: 10.2.0.0/16|/0, received: 10.0.1.0/24|/0 => no match
                        Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> config: 10.2.0.0/16|/0, received: 10.2.0.0/16|/0 => match: 10.2.0.0/16|/0
                        Apr 8 18:31:59	charon	93875	09[CFG] <con1|1> selecting traffic selectors for us:
                        

                        It looks like this triggers a bunch of deleting of CHILD_SA's which seems to break the tunnel.

                        What are the actual P2 subnets on each side?

                        You might also be experiencing "leakage" during the rekeying, where during the brief interruption, the IPsec routes disappear from the routing table and so pfSense sends the traffic out the WAN interfaces. This causes states to become established which causes it to continue to try sending traffic out the WAN until the state expires.

                        You can prevent this by creating a floating rule, with source interface WAN, destination <VPN subnet>, direction Out, action Block.
                        This causes any attempts to send the VPN subnet traffic out the WAN to be blocked (dropped) and prevents an outbound state from being established on the WAN interface.

                        T 2 Replies Last reply Reply Quote 0
                        • T
                          TheStormsOfFury @andrew_cb
                          last edited by

                          @andrew_cb Thank you very much for the reply.

                          Site A Phase 2 remote subnets
                          P2-1:

                          • Local Subnet: LAN Subnet (10.1.0.0/16
                          • Remote Subnet: 10.2.0.0/16 (Site B LAN Subnet)
                            P2-2:
                          • Local Subnet: LAN Subnet (10.1.0.0/16)
                          • Remote Subnet: 10.0.1.0/24 (for a road warrior open VPN connection at site B)

                          Site B Phase 2 remote subnets
                          P2-1

                          • Local Subnet: LAN Subnet (10.2.0.0/16)
                          • Remote Subnet 10.1.0.0/16 (Site A LAN Subnet)
                            P2-2
                          • Local Subnet: 10.0.1.0/24 (for a road warrior open VPN connection at site B)
                          • Remote Subnet: 10.1.0.0/16 (Site A LAN Subnet)

                          I thought I turned on "Make before break" last night, but I apparently was so tired I forgot to apply the changes and restart the VPN. I just did this now, show hopefully this might fix the issue; however, I am going to also implement your suggestion of the floating rule.

                          In fact I'm looking at this now, but I do have a quick question about the config:

                          Action => Block
                          Interface ... Should this be WAN or IPsec?
                          Direction => out
                          Address Family => IPv4
                          Protocol => Any
                          Source ... should be WAN Address? I'm running HA so I have VIP, should it be the VIP Address? or should I do one for WAN and a separate for VIP?
                          Destination ... I'm going to need 1 for both remote subnets on Site A and just the Site B subnet

                          How close am I on this configuration?

                          T 1 Reply Last reply Reply Quote 0
                          • T
                            TheStormsOfFury @TheStormsOfFury
                            last edited by

                            Well, I was hoping the "Make before break" setting would have resulted this issue, yet at 58 minutes it trimmed out for about 45 seconds again.

                            1 Reply Last reply Reply Quote 0
                            • T
                              TheStormsOfFury @andrew_cb
                              last edited by

                              @andrew_cb Just looking at this again as I know there is a time difference, but shouldn't this be the configuration if we do not want the IPsec traffic to go out the WAN?

                              Action => Block
                              Interface => IPsec
                              Direction => out
                              Address Family => IPv4
                              Protocol => Any
                              Source => LAN
                              Destination => WAN RTR1 / WAN RTR2 / VIP WAN

                              Maybe i'm thinking about this wrong, but this would keep IPsec traffic from the lan going out over the wan, or am I wrong?

                              PS, the system is still dropping for about 40-50 seconds every 55-ish minutes. I'm going to get the logs again shortly.

                              T A 2 Replies Last reply Reply Quote 0
                              • T
                                TheStormsOfFury @TheStormsOfFury
                                last edited by

                                Here are the updated logs for the timeout session that just happened:

                                I am wondering if i should change the ReKey on the Phase2 as it is happening at 55 minutes on a 60 expiration and a 3-4 minute random.

                                I started getting ping timeouts at 14:59:02 and service return at 3:00:03

                                Logs on Site A:

                                Apr 9 15:00:33	charon	81451	09[IKE] <con1|1> nothing to initiate
                                Apr 9 15:00:33	charon	81451	09[IKE] <con1|1> activating new tasks
                                Apr 9 15:00:33	charon	81451	09[ENC] <con1|1> parsed INFORMATIONAL response 27 [ ]
                                Apr 9 15:00:33	charon	81451	09[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                                Apr 9 15:00:33	charon	81451	09[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                                Apr 9 15:00:33	charon	81451	09[ENC] <con1|1> generating INFORMATIONAL request 27 [ ]
                                Apr 9 15:00:33	charon	81451	09[IKE] <con1|1> activating IKE_DPD task
                                Apr 9 15:00:33	charon	81451	09[IKE] <con1|1> activating new tasks
                                Apr 9 15:00:33	charon	81451	09[IKE] <con1|1> queueing IKE_DPD task
                                Apr 9 15:00:33	charon	81451	09[IKE] <con1|1> sending DPD request
                                Apr 9 15:00:23	charon	81451	09[IKE] <con1|1> nothing to initiate
                                Apr 9 15:00:23	charon	81451	09[IKE] <con1|1> activating new tasks
                                Apr 9 15:00:23	charon	81451	09[ENC] <con1|1> parsed INFORMATIONAL response 26 [ ]
                                Apr 9 15:00:23	charon	81451	09[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                                Apr 9 15:00:23	charon	81451	09[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                                Apr 9 15:00:23	charon	81451	09[ENC] <con1|1> generating INFORMATIONAL request 26 [ ]
                                Apr 9 15:00:23	charon	81451	09[IKE] <con1|1> activating IKE_DPD task
                                Apr 9 15:00:23	charon	81451	09[IKE] <con1|1> activating new tasks
                                Apr 9 15:00:23	charon	81451	09[IKE] <con1|1> queueing IKE_DPD task
                                Apr 9 15:00:23	charon	81451	09[IKE] <con1|1> sending DPD request
                                Apr 9 15:00:13	charon	81451	09[IKE] <con1|1> nothing to initiate
                                Apr 9 15:00:13	charon	81451	09[IKE] <con1|1> activating new tasks
                                Apr 9 15:00:13	charon	81451	09[ENC] <con1|1> parsed INFORMATIONAL response 25 [ ]
                                Apr 9 15:00:13	charon	81451	09[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                                Apr 9 15:00:13	charon	81451	10[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                                Apr 9 15:00:13	charon	81451	10[ENC] <con1|1> generating INFORMATIONAL request 25 [ ]
                                Apr 9 15:00:13	charon	81451	10[IKE] <con1|1> activating IKE_DPD task
                                Apr 9 15:00:13	charon	81451	10[IKE] <con1|1> activating new tasks
                                Apr 9 15:00:13	charon	81451	10[IKE] <con1|1> queueing IKE_DPD task
                                Apr 9 15:00:13	charon	81451	10[IKE] <con1|1> sending DPD request
                                Apr 9 15:00:03	charon	81451	10[IKE] <con1|1> nothing to initiate
                                Apr 9 15:00:03	charon	81451	10[IKE] <con1|1> activating new tasks
                                Apr 9 15:00:03	charon	81451	10[ENC] <con1|1> parsed INFORMATIONAL response 24 [ ]
                                Apr 9 15:00:03	charon	81451	10[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                                Apr 9 15:00:03	charon	81451	10[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                                Apr 9 15:00:03	charon	81451	10[ENC] <con1|1> generating INFORMATIONAL request 24 [ ]
                                Apr 9 15:00:03	charon	81451	10[IKE] <con1|1> activating IKE_DPD task
                                Apr 9 15:00:03	charon	81451	10[IKE] <con1|1> activating new tasks
                                Apr 9 15:00:03	charon	81451	10[IKE] <con1|1> queueing IKE_DPD task
                                Apr 9 15:00:03	charon	81451	10[IKE] <con1|1> sending DPD request
                                Apr 9 14:59:53	charon	81451	10[IKE] <con1|1> nothing to initiate
                                Apr 9 14:59:53	charon	81451	10[IKE] <con1|1> activating new tasks
                                Apr 9 14:59:53	charon	81451	10[ENC] <con1|1> parsed INFORMATIONAL response 23 [ ]
                                Apr 9 14:59:53	charon	81451	10[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                                Apr 9 14:59:53	charon	81451	10[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                                Apr 9 14:59:53	charon	81451	10[ENC] <con1|1> generating INFORMATIONAL request 23 [ ]
                                Apr 9 14:59:53	charon	81451	10[IKE] <con1|1> activating IKE_DPD task
                                Apr 9 14:59:53	charon	81451	10[IKE] <con1|1> activating new tasks
                                Apr 9 14:59:53	charon	81451	10[IKE] <con1|1> queueing IKE_DPD task
                                Apr 9 14:59:53	charon	81451	10[IKE] <con1|1> sending DPD request
                                Apr 9 14:59:47	charon	81451	09[IKE] <con1|1> nothing to initiate
                                Apr 9 14:59:47	charon	81451	09[IKE] <con1|1> activating new tasks
                                Apr 9 14:59:47	charon	81451	09[CHD] <con1|1> CHILD_SA con1{6} state change: DELETED => DESTROYING
                                Apr 9 14:59:47	charon	81451	09[IKE] <con1|1> activating CHILD_DELETE task
                                Apr 9 14:59:47	charon	81451	09[IKE] <con1|1> activating new tasks
                                Apr 9 14:59:47	charon	81451	09[IKE] <con1|1> queueing CHILD_DELETE task
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> nothing to initiate
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> activating new tasks
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> CHILD_SA con1{6} state change: DELETING => DELETED
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> CHILD_SA closed
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> received DELETE for ESP CHILD_SA with SPI cfe718f6
                                Apr 9 14:59:42	charon	81451	09[ENC] <con1|1> parsed INFORMATIONAL response 22 [ D ]
                                Apr 9 14:59:42	charon	81451	09[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                                Apr 9 14:59:42	charon	81451	09[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                                Apr 9 14:59:42	charon	81451	09[ENC] <con1|1> generating INFORMATIONAL request 22 [ D ]
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> CHILD_SA con1{6} state change: REKEYED => DELETING
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> sending DELETE for ESP CHILD_SA with SPI cb24b68e
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> closing CHILD_SA con1{6} with SPIs cb24b68e_i (99971985 bytes) cfe718f6_o (135223892 bytes) and TS 10.1.0.0/16|/0 === 10.0.1.0/24|/0 10.2.0.0/16|/0
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> CHILD_REKEY task
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> reinitiating already active tasks
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> CHILD_SA con1{6} state change: REKEYING => REKEYED
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> outbound CHILD_SA con1{7} established with SPIs c0ed26f2_i c421f173_o and TS 10.1.0.0/16|/0 === 10.0.1.0/24|/0 10.2.0.0/16|/0
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> SPI 0xc421f173, src 207.162.137.151 dst 75.61.85.193
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> adding outbound ESP SA
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> CHILD_SA con1{7} state change: INSTALLING => INSTALLED
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> inbound CHILD_SA con1{7} established with SPIs c0ed26f2_i c421f173_o and TS 10.1.0.0/16|/0 === 10.0.1.0/24|/0 10.2.0.0/16|/0
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> SPI 0xc421f173, src 207.162.137.151 dst 75.61.85.193
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> registering outbound ESP SA
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> SPI 0xc0ed26f2, src 75.61.85.193 dst 207.162.137.151
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> adding inbound ESP SA
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> using HMAC_SHA2_256_128 for integrity
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> using AES_CBC for encryption
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> CHILD_SA con1{7} state change: CREATED => INSTALLING
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> config: 10.0.1.0/24|/0, received: 10.0.1.0/24|/0 => match: 10.0.1.0/24|/0
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> config: 10.0.1.0/24|/0, received: 10.2.0.0/16|/0 => no match
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> config: 10.2.0.0/16|/0, received: 10.0.1.0/24|/0 => no match
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> config: 10.2.0.0/16|/0, received: 10.2.0.0/16|/0 => match: 10.2.0.0/16|/0
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> selecting traffic selectors for other:
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> config: 10.1.0.0/16|/0, received: 10.1.0.0/16|/0 => match: 10.1.0.0/16|/0
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> config: 10.1.0.0/16|/0, received: 10.1.0.0/16|/0 => match: 10.1.0.0/16|/0
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> selecting traffic selectors for us:
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> proposal matches
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> selecting proposal:
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> received ESP_TFC_PADDING_NOT_SUPPORTED notify
                                Apr 9 14:59:42	charon	81451	09[ENC] <con1|1> parsed CREATE_CHILD_SA response 21 [ N(ESP_TFC_PAD_N) SA No KE TSi TSr ]
                                Apr 9 14:59:42	charon	81451	09[NET] <con1|1> received packet: from 75.61.85.193[500] to 207.162.137.151[500] (496 bytes)
                                Apr 9 14:59:42	charon	81451	09[NET] <con1|1> sending packet: from 207.162.137.151[500] to 75.61.85.193[500] (512 bytes)
                                Apr 9 14:59:42	charon	81451	09[ENC] <con1|1> generating CREATE_CHILD_SA request 21 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ]
                                Apr 9 14:59:42	charon	81451	09[CHD] <con1|1> CHILD_SA con1{6} state change: INSTALLED => REKEYING
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> establishing CHILD_SA con1{7} reqid 1
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> 10.0.1.0/24|/0
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> 10.2.0.0/16|/0
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> proposing traffic selectors for other:
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> 10.1.0.0/16|/0
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> 10.1.0.0/16|/0
                                Apr 9 14:59:42	charon	81451	09[CFG] <con1|1> proposing traffic selectors for us:
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> activating CHILD_REKEY task
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> activating new tasks
                                Apr 9 14:59:42	charon	81451	09[IKE] <con1|1> queueing CHILD_REKEY task
                                Apr 9 14:59:42	charon	81451	08[KNL] creating rekey job for CHILD_SA ESP/0xcfe718f6/75.61.85.193
                                Apr 9 14:58:06	charon	81451	08[CFG] vici client 3008 disconnected
                                Apr 9 14:58:06	charon	81451	09[CFG] vici client 3008 requests: list-sas
                                Apr 9 14:58:06	charon	81451	09[CFG] vici client 3008 registered for: list-sa
                                Apr 9 14:58:06	charon	81451	08[CFG] vici client 3008 connected
                                Apr 9 14:58:01	charon	81451	09[CFG] vici client 3007 disconnected
                                Apr 9 14:58:01	charon	81451	08[CFG] vici client 3007 requests: list-sas
                                Apr 9 14:58:01	charon	81451	08[CFG] vici client 3007 registered for: list-sa
                                Apr 9 14:58:01	charon	81451	08[CFG] vici client 3007 connected
                                

                                On Site B:

                                Apr 9 15:00:33	charon	80312	13[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                                Apr 9 15:00:33	charon	80312	13[ENC] <con1|1> generating INFORMATIONAL response 27 [ ]
                                Apr 9 15:00:33	charon	80312	13[ENC] <con1|1> parsed INFORMATIONAL request 27 [ ]
                                Apr 9 15:00:33	charon	80312	13[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                                Apr 9 15:00:23	charon	80312	14[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                                Apr 9 15:00:23	charon	80312	14[ENC] <con1|1> generating INFORMATIONAL response 26 [ ]
                                Apr 9 15:00:23	charon	80312	14[ENC] <con1|1> parsed INFORMATIONAL request 26 [ ]
                                Apr 9 15:00:23	charon	80312	14[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                                Apr 9 15:00:13	charon	80312	14[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                                Apr 9 15:00:13	charon	80312	14[ENC] <con1|1> generating INFORMATIONAL response 25 [ ]
                                Apr 9 15:00:13	charon	80312	14[ENC] <con1|1> parsed INFORMATIONAL request 25 [ ]
                                Apr 9 15:00:13	charon	80312	14[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                                Apr 9 15:00:03	charon	80312	14[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                                Apr 9 15:00:03	charon	80312	14[ENC] <con1|1> generating INFORMATIONAL response 24 [ ]
                                Apr 9 15:00:03	charon	80312	14[ENC] <con1|1> parsed INFORMATIONAL request 24 [ ]
                                Apr 9 15:00:03	charon	80312	14[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                                Apr 9 14:59:53	charon	80312	14[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                                Apr 9 14:59:53	charon	80312	14[ENC] <con1|1> generating INFORMATIONAL response 23 [ ]
                                Apr 9 14:59:53	charon	80312	14[ENC] <con1|1> parsed INFORMATIONAL request 23 [ ]
                                Apr 9 14:59:53	charon	80312	14[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                                Apr 9 14:59:47	charon	80312	14[IKE] <con1|1> nothing to initiate
                                Apr 9 14:59:47	charon	80312	14[IKE] <con1|1> activating new tasks
                                Apr 9 14:59:47	charon	80312	14[CHD] <con1|1> CHILD_SA con1{6} state change: DELETED => DESTROYING
                                Apr 9 14:59:47	charon	80312	14[IKE] <con1|1> activating CHILD_DELETE task
                                Apr 9 14:59:47	charon	80312	14[IKE] <con1|1> activating new tasks
                                Apr 9 14:59:47	charon	80312	14[IKE] <con1|1> queueing CHILD_DELETE task
                                Apr 9 14:59:42	charon	80312	14[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (80 bytes)
                                Apr 9 14:59:42	charon	80312	14[ENC] <con1|1> generating INFORMATIONAL response 22 [ D ]
                                Apr 9 14:59:42	charon	80312	14[IKE] <con1|1> outbound CHILD_SA con1{7} established with SPIs c421f173_i c0ed26f2_o and TS 10.0.1.0/24|/0 10.2.0.0/16|/0 === 10.1.0.0/16|/0
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> SPI 0xc0ed26f2, src 75.61.85.193 dst 207.162.137.151
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> adding outbound ESP SA
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> CHILD_SA con1{6} state change: DELETING => DELETED
                                Apr 9 14:59:42	charon	80312	14[IKE] <con1|1> CHILD_SA closed
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> CHILD_SA con1{6} state change: REKEYED => DELETING
                                Apr 9 14:59:42	charon	80312	14[IKE] <con1|1> sending DELETE for ESP CHILD_SA with SPI cfe718f6
                                Apr 9 14:59:42	charon	80312	14[IKE] <con1|1> closing CHILD_SA con1{6} with SPIs cfe718f6_i (106476374 bytes) cb24b68e_o (129569664 bytes) and TS 10.0.1.0/24|/0 10.2.0.0/16|/0 === 10.1.0.0/16|/0
                                Apr 9 14:59:42	charon	80312	14[IKE] <con1|1> received DELETE for ESP CHILD_SA with SPI cb24b68e
                                Apr 9 14:59:42	charon	80312	14[ENC] <con1|1> parsed INFORMATIONAL request 22 [ D ]
                                Apr 9 14:59:42	charon	80312	14[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (80 bytes)
                                Apr 9 14:59:42	charon	80312	14[NET] <con1|1> sending packet: from 75.61.85.193[500] to 207.162.137.151[500] (496 bytes)
                                Apr 9 14:59:42	charon	80312	14[ENC] <con1|1> generating CREATE_CHILD_SA response 21 [ N(ESP_TFC_PAD_N) SA No KE TSi TSr ]
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> CHILD_SA con1{6} state change: REKEYING => REKEYED
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> CHILD_SA con1{6} state change: INSTALLED => REKEYING
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> CHILD_SA con1{7} state change: INSTALLING => INSTALLED
                                Apr 9 14:59:42	charon	80312	14[IKE] <con1|1> inbound CHILD_SA con1{7} established with SPIs c421f173_i c0ed26f2_o and TS 10.0.1.0/24|/0 10.2.0.0/16|/0 === 10.1.0.0/16|/0
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> SPI 0xc0ed26f2, src 75.61.85.193 dst 207.162.137.151
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> registering outbound ESP SA
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> SPI 0xc421f173, src 207.162.137.151 dst 75.61.85.193
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> adding inbound ESP SA
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> using HMAC_SHA2_256_128 for integrity
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> using AES_CBC for encryption
                                Apr 9 14:59:42	charon	80312	14[CHD] <con1|1> CHILD_SA con1{7} state change: CREATED => INSTALLING
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> config: 10.1.0.0/16|/0, received: 10.1.0.0/16|/0 => match: 10.1.0.0/16|/0
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> config: 10.1.0.0/16|/0, received: 10.1.0.0/16|/0 => match: 10.1.0.0/16|/0
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> selecting traffic selectors for other:
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> config: 10.0.1.0/24|/0, received: 10.0.1.0/24|/0 => match: 10.0.1.0/24|/0
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> config: 10.0.1.0/24|/0, received: 10.2.0.0/16|/0 => no match
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> config: 10.2.0.0/16|/0, received: 10.0.1.0/24|/0 => no match
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> config: 10.2.0.0/16|/0, received: 10.2.0.0/16|/0 => match: 10.2.0.0/16|/0
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> selecting traffic selectors for us:
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_2048/NO_EXT_SEQ
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> proposal matches
                                Apr 9 14:59:42	charon	80312	14[CFG] <con1|1> selecting proposal:
                                Apr 9 14:59:42	charon	80312	14[IKE] <con1|1> received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
                                Apr 9 14:59:42	charon	80312	14[ENC] <con1|1> parsed CREATE_CHILD_SA request 21 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ]
                                Apr 9 14:59:42	charon	80312	14[NET] <con1|1> received packet: from 207.162.137.151[500] to 75.61.85.193[500] (512 bytes)
                                Apr 9 14:57:56	charon	80312	16[CFG] vici client 3068 disconnected
                                Apr 9 14:57:56	charon	80312	16[CFG] vici client 3068 requests: list-sas
                                Apr 9 14:57:56	charon	80312	16[CFG] vici client 3068 registered for: list-sa
                                Apr 9 14:57:56	charon	80312	16[CFG] vici client 3068 connected
                                Apr 9 14:57:51	charon	80312	16[CFG] vici client 3067 disconnected
                                Apr 9 14:57:51	charon	80312	05[CFG] vici client 3067 requests: list-sas
                                
                                T 1 Reply Last reply Reply Quote 0
                                • T
                                  TheStormsOfFury @TheStormsOfFury
                                  last edited by

                                  Same thing just happened again. 54 minutes after the last one it went down for roughly 45 seconds.

                                  🤦

                                  Thanks again all!

                                  TSoF

                                  1 Reply Last reply Reply Quote 0
                                  • A
                                    andrew_cb @TheStormsOfFury
                                    last edited by

                                    @TheStormsOfFury said in IPsec site to site dropping every 49-55 minutes:

                                    @andrew_cb Just looking at this again as I know there is a time difference, but shouldn't this be the configuration if we do not want the IPsec traffic to go out the WAN?

                                    Action => Block
                                    Interface => IPsec
                                    Direction => out
                                    Address Family => IPv4
                                    Protocol => Any
                                    Source => LAN
                                    Destination => WAN RTR1 / WAN RTR2 / VIP WAN

                                    Maybe i'm thinking about this wrong, but this would keep IPsec traffic from the lan going out over the wan, or am I wrong?

                                    PS, the system is still dropping for about 40-50 seconds every 55-ish minutes. I'm going to get the logs again shortly.

                                    If the remote subnets are being removed from the firewall's routing table then they are sent out the default route (i.e. 0.0.0.0 / WAN).
                                    When traffic is sent out the WAN, it gets NAT'ed so that the source address is now the WAN IP, and then it is sent out the WAN interface.
                                    A state is created on the WAN interface with the source address being the WAN IP (due to NAT) and the destination will be the remote VPN subnet.
                                    This state will persist and cause the firewall to keep sending traffic destined for the remote VPN subnet out the WAN instead.

                                    Eventually a program will timeout and stop transmitting. When the program tries again, it usually uses a different source port, which causes a new session to be created on the firewall. If the VPN's P2 are established, then the new traffic is correctly sent over the VPN tunnel.

                                    The floating block rule is set on the WAN interface with source of WAN Address because NAT is performed before the firewall rules are processed.

                                    T 1 Reply Last reply Reply Quote 0
                                    • T
                                      TheStormsOfFury @andrew_cb
                                      last edited by

                                      @andrew_cb Okay, I think i understand now.

                                      This means that the rule should look as follows:

                                      Action => Block
                                      Interface => WAN/WAN VIP
                                      Direction => out
                                      Address Family => IPv4
                                      Protocol => Any
                                      Source => WAN/WAN VIP
                                      Destination => For Site A = Site B Subnets && for Site B = Site A Subnets

                                      Let me know if I've got it right this time!

                                      Thanks again,

                                      TSoF

                                      T A 2 Replies Last reply Reply Quote 0
                                      • T
                                        TheStormsOfFury @TheStormsOfFury
                                        last edited by TheStormsOfFury

                                        @andrew_cb well, I have the rules as this one setup above, and it still timed out. Maybe I just need to set P2 to timeout at like 24 hours and then apply it and reboot at like 6:00 AM that way it will take it months to timeout during the working period.

                                        It just seems odd that I have "Make before break" enabled, yet it isn't doing that.

                                        Thinking about it, I have it set to WAN SUBNETS as the source as this uses CARP and VIP Ip address. Should I change it to just the "IP address" that is the VIP IP?

                                        T 1 Reply Last reply Reply Quote 0
                                        • T
                                          TheStormsOfFury @TheStormsOfFury
                                          last edited by TheStormsOfFury

                                          @viragomann @andrew_cb

                                          So i have my firewall rule to block on the WAN VIP address to see if it will stop that 45-50 second down time.

                                          I also performed a test and setup my tunnel times as follows:

                                          Phase 1:

                                          • Lifetime 604,800 (7 days/168 hours)
                                          • ReKey 604,200 (10 minutes less than lifetime)
                                          • ReAuth 160 (2 minutes) (This might need to be 604,640)
                                          • Rand Time 60 (1 minute)

                                          Phase 2:

                                          • 86,400 (1 day/24 hours)
                                          • 85,800 (10 minutes less than lifetime)
                                          • 60 (1 minute)

                                          The results were disastrously. The tunnels were resting every 45-50 seconds and it was creating multiple connection visible in the ipsec status.

                                          I reset everything back to the original mentioned above, but we're still timing out at the 55-ish minute mark, which is not good during business hours as phone calls and app connections are failing.

                                          I do have a question. If i am using make before break, do i still need "Phase One Child SA Close Action" to be restart? Shouldn't it be close?

                                          Any thoughts? I'm about ready to move on and try wireguard.

                                          1 Reply Last reply Reply Quote 0
                                          • T
                                            TheStormsOfFury
                                            last edited by

                                            I did a little checking and the tunnel is going down every 53 minutes 30 seconds (give or take a second).

                                            Then it is down for approximately 38 - 40 seconds.

                                            This is super strange that I have make before break enabled, but it is still doing this.

                                            Thanks in advance!

                                            TSoF

                                            1 Reply Last reply Reply Quote 0
                                            • First post
                                              Last post
                                            Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.