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

    Phase 2 rekey takes 180 seconds

    Scheduled Pinned Locked Moved IPsec
    11 Posts 3 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.
    • S
      scourtney2000
      last edited by

      I have pfSense 2.4.4 p2 on two sides of an IPSEC ikev2 tunnel that is using PSK. During phase 2 rekey it takes around 3 mintues for the tunnel to come back up. During that time, the new phase 2 sits there and shows bytes out but no bytes in. I have tried both Tunnel and VTI and both have the same trouble. I am running CARP on one side of the tunnel.

      I tinkered with the settings over and over trying new things. I settled for increasing my Phase 1 and Phase 2 lifetimes to minimize outages. I want to learn more about how to troubleshoot this issue. What other things should I be looking at?

      I have gone as far as to destroy the tunnel setting on both side and restarting several times.

      Thanks

      K 1 Reply Last reply Reply Quote 0
      • K
        Konstanti @scourtney2000
        last edited by

        @scourtney2000

        Hey
        show the logs where you can see what happens during the process of Rekeying

        1 Reply Last reply Reply Quote 0
        • S
          scourtney2000
          last edited by

          @konstanti said in Phase 2 rekey takes 180 seconds:

          you can see what happens during the process of Rekeying

          [0_1549927906507_ipsec.log](Uploading 100%) 0_1549927946792_ipsec_log.txt

          1 Reply Last reply Reply Quote 0
          • DerelictD
            Derelict LAYER 8 Netgate
            last edited by

            Feb 11 18:15:15	charon		09[KNL] creating rekey job for CHILD_SA ESP/0xc67af502/x.x.x.x
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> queueing CHILD_REKEY task
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> activating new tasks
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> activating CHILD_REKEY task
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> proposing traffic selectors for us:
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> 10.255.255.8/30|/0
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> 0.0.0.0/0|/0
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> proposing traffic selectors for other:
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> 10.255.255.9/32|/0
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> 0.0.0.0/0|/0
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> configured proposals: ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> establishing CHILD_SA con1000{4} reqid 1000
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> CHILD_SA con1000{1} state change: INSTALLED => REKEYING
            Feb 11 18:15:15	charon		09[ENC] <con1000|1> generating CREATE_CHILD_SA request 2162 [ N(REKEY_SA) N(ESP_TFC_PAD_N) SA No KE TSi TSr ]
            Feb 11 18:15:15	charon		09[NET] <con1000|1> sending packet: from y.y.y.y[500] to x.x.x.x[500] (364 bytes)
            Feb 11 18:15:15	charon		09[NET] <con1000|1> received packet: from x.x.x.x[500] to y.y.y.y[500] (348 bytes)
            Feb 11 18:15:15	charon		09[ENC] <con1000|1> parsed CREATE_CHILD_SA response 2162 [ N(ESP_TFC_PAD_N) SA No KE TSi TSr ]
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> received ESP_TFC_PADDING_NOT_SUPPORTED notify
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> received ESP_TFC_PADDING_NOT_SUPPORTED, not using ESPv3 TFC padding
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> selecting proposal:
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> proposal matches
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> received proposals: ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> configured proposals: ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> selected proposal: ESP:AES_CBC_128/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> selecting traffic selectors for us:
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> config: 10.255.255.8/30|/0, received: 0.0.0.0/0|/0 => match: 10.255.255.8/30|/0
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> config: 0.0.0.0/0|/0, received: 0.0.0.0/0|/0 => match: 0.0.0.0/0|/0
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> selecting traffic selectors for other:
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> config: 10.255.255.9/32|/0, received: 0.0.0.0/0|/0 => match: 10.255.255.9/32|/0
            Feb 11 18:15:15	charon		09[CFG] <con1000|1> config: 0.0.0.0/0|/0, received: 0.0.0.0/0|/0 => match: 0.0.0.0/0|/0
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> CHILD_SA con1000{4} state change: CREATED => INSTALLING
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> using AES_CBC for encryption
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> using HMAC_SHA1_96 for integrity
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> adding inbound ESP SA
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> SPI 0xccd147c5, src x.x.x.x dst y.y.y.y
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> registering outbound ESP SA
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> SPI 0xc4672f68, src y.y.y.y dst x.x.x.x
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> inbound CHILD_SA con1000{4} established with SPIs ccd147c5_i c4672f68_o and TS 0.0.0.0/0|/0 === 0.0.0.0/0|/0
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> CHILD_SA con1000{4} state change: INSTALLING => INSTALLED
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> adding outbound ESP SA
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> SPI 0xc4672f68, src y.y.y.y dst x.x.x.x
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> outbound CHILD_SA con1000{4} established with SPIs ccd147c5_i c4672f68_o and TS 0.0.0.0/0|/0 === 0.0.0.0/0|/0
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> CHILD_SA con1000{1} state change: REKEYING => REKEYED
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> reinitiating already active tasks
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> CHILD_REKEY task
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> closing CHILD_SA con1000{1} with SPIs cac7ac71_i (0 bytes) c67af502_o (1920 bytes) and TS 0.0.0.0/0|/0 === 0.0.0.0/0|/0
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> sending DELETE for ESP CHILD_SA with SPI cac7ac71
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> CHILD_SA con1000{1} state change: REKEYED => DELETING
            Feb 11 18:15:15	charon		09[ENC] <con1000|1> generating INFORMATIONAL request 2163 [ D ]
            Feb 11 18:15:15	charon		09[NET] <con1000|1> sending packet: from y.y.y.y[500] to x.x.x.x[500] (76 bytes)
            Feb 11 18:15:15	charon		09[NET] <con1000|1> received packet: from x.x.x.x[500] to y.y.y.y[500] (76 bytes)
            Feb 11 18:15:15	charon		09[ENC] <con1000|1> parsed INFORMATIONAL response 2163 [ D ]
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> received DELETE for ESP CHILD_SA with SPI c67af502
            Feb 11 18:15:15	charon		09[IKE] <con1000|1> CHILD_SA closed
            Feb 11 18:15:15	charon		09[CHD] <con1000|1> CHILD_SA con1000{1} state change: DELETING => DELETED
            

            Looks like this side is doing everything it is supposed to all at second :15.

            What are you seeing that gives you the impression that it is taking 3 minutes?

            Perhaps it has something to do with the way you configured the HA cluster.

            That log right there looks absolutely fine.

            Chattanooga, Tennessee, USA
            A comprehensive network diagram is worth 10,000 words and 15 conference calls.
            DO NOT set a source address/port in a port forward or firewall rule unless you KNOW you need it!
            Do Not Chat For Help! NO_WAN_EGRESS(TM)

            S 1 Reply Last reply Reply Quote 0
            • S
              scourtney2000 @Derelict
              last edited by

              @derelict

              It does pass traffic for 3 minutes. I have a continuous ping running at the time of the rekey. It takes approximately 3 minutes before the traffic passes. On both sides of the tunnel the VPN Status indicates Bytes in as 0.

              1 Reply Last reply Reply Quote 0
              • S
                scourtney2000
                last edited by

                0_1549933343714_ipsec_status.jpg

                1 Reply Last reply Reply Quote 0
                • DerelictD
                  Derelict LAYER 8 Netgate
                  last edited by Derelict

                  If bytes in is 0 we need to see the other side.

                  Packet capture ICMP on the IPsec interface. Do you see the echo requests going out and no reply?

                  Chattanooga, Tennessee, USA
                  A comprehensive network diagram is worth 10,000 words and 15 conference calls.
                  DO NOT set a source address/port in a port forward or firewall rule unless you KNOW you need it!
                  Do Not Chat For Help! NO_WAN_EGRESS(TM)

                  1 Reply Last reply Reply Quote 0
                  • S
                    scourtney2000
                    last edited by

                    The other side say no bytes in also.

                    1 Reply Last reply Reply Quote 0
                    • S
                      scourtney2000
                      last edited by

                      The pattern I see everytime is Phase 1 connects. A single Phase 2 comes up. I can ping for a minute through the tunnel. Another Phase 2 comes up. I can not ping. Bytes-in on both sides displays 0. Then 3 minutes later I can ping through the tunnel. Only the second Phase 2 is actually active. The first Phase 1 is never destroyed.

                      1 Reply Last reply Reply Quote 0
                      • S
                        scourtney2000
                        last edited by

                        If I am using VTI for phase 2 along with CARP would I need to create a VIP for for the tunnel?

                        1 Reply Last reply Reply Quote 0
                        • DerelictD
                          Derelict LAYER 8 Netgate
                          last edited by

                          No. The tunnel interface addresses are specified in the Phase 2 configuration.

                          Chattanooga, Tennessee, USA
                          A comprehensive network diagram is worth 10,000 words and 15 conference calls.
                          DO NOT set a source address/port in a port forward or firewall rule unless you KNOW you need it!
                          Do Not Chat For Help! NO_WAN_EGRESS(TM)

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