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

    Phase 2 : "invalid HASH_V1 payload length" error

    Scheduled Pinned Locked Moved
    IPsec
    5
    19
    3.1k
    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.
    • K
      Konstanti @cukal
      last edited by

      @cukal
      The first post of this topic says that there are 6 phases 2. Therefore, I wrote that it is necessary to specify this number

      1 Reply Last reply Reply Quote 0
      • cukalC
        cukal
        last edited by

        @Konstanti Thanks for pointing that out to me ;)

        2.4.4-p2 is messing up IPSec tunnels for me.

        Using the max_ikey1_exchanges fixes it for a while but after a P1 renegotiation (set to 3600) the invalid HASH_V1 payload length, decryption failed? returns. When manually disconnecting the P1 it reconnects and a single P2 is created. Disconnecting a second time and all 3 P2's are again present.
        This config has been working for months on 2.4.3-p1.

        Where should I start looking?

        1 Reply Last reply Reply Quote 0
        • G
          gchialli
          last edited by gchialli

          I apologize for replying to this old topic, but I'm having the same issue I think. I'm on 2.4.4-p1. I have already bumped the max_ikev1_exchanges
          value to 50, but the errors keep happening, and the tunnel restarts every 2 minutes.
          @cukal Have you been able to find a solution for this?
          Thank you

          A G 2 Replies Last reply Reply Quote 0
          • A
            armandelli @gchialli
            last edited by

            Hey guys!
            I am also having this issue for about 3 weeks now. I just tried the max_ikey1_exchanges configuration and will monitor to see if it solves this problem.

            Another problem is that my IPSEC simply stops working (as per logs below) and I have to manually disconnect and connect for it to get back to normal.

            "Nov 18 10:53:32 srvfw02 charon: 11[ENC] <con5000|36> generating INFORMATIONAL_V1 request 662765406 [ HASH N(DPD_ACK) ]
            Nov 18 10:53:32 srvfw02 charon: 11[NET] <con5000|36> sending packet: from 187.32.1.97[4500] to 3.93.27.107[4500] (92 bytes)
            Nov 18 10:53:35 srvfw02 charon: 13[CFG] received stroke: terminate 'con5000[36]'
            Nov 18 10:53:35 srvfw02 charon: 05[IKE] <con5000|36> closing CHILD_SA con5001{1951} with SPIs c390bb8a_i (89106592 bytes) 5164593c_o (47764912 bytes) and TS 10.16.0.0/16|/0 === 172.31.0.0/16|/0
            Nov 18 10:53:35 srvfw02 charon: 05[IKE] <con5000|36> sending DELETE for ESP CHILD_SA with SPI c390bb8a
            Nov 18 10:53:35 srvfw02 charon: 05[ENC] <con5000|36> generating INFORMATIONAL_V1 request 2488498287 [ HASH D ]
            Nov 18 10:53:35 srvfw02 charon: 05[NET] <con5000|36> sending packet: from 187.32.1.97[4500] to 3.93.27.107[4500] (76 bytes)
            Nov 18 10:53:35 srvfw02 charon: 05[IKE] <con5000|36> closing CHILD_SA con5000{1952} with SPIs ce3c4bc6_i (21092379 bytes) fc4266f4_o (33628104 bytes) and TS 172.23.1.0/24|/0 === 172.31.0.0/16|/0
            Nov 18 10:53:35 srvfw02 charon: 05[IKE] <con5000|36> sending DELETE for ESP CHILD_SA with SPI ce3c4bc6
            Nov 18 10:53:35 srvfw02 charon: 05[ENC] <con5000|36> generating INFORMATIONAL_V1 request 2855744199 [ HASH D ]
            Nov 18 10:53:35 srvfw02 charon: 05[NET] <con5000|36> sending packet: from 187.32.1.97[4500] to 3.93.27.107[4500] (76 bytes)
            Nov 18 10:53:35 srvfw02 charon: 05[IKE] <con5000|36> closing CHILD_SA con5005{1953} with SPIs cf46097b_i (56835850 bytes) 0a395ec7_o (2706984 bytes) and TS 172.23.1.0/24|/0 === 172.32.0.0/16|/0
            Nov 18 10:53:35 srvfw02 charon: 05[IKE] <con5000|36> sending DELETE for ESP CHILD_SA with SPI cf46097b
            Nov 18 10:53:35 srvfw02 charon: 05[ENC] <con5000|36> generating INFORMATIONAL_V1 request 305020778 [ HASH D ]
            Nov 18 10:53:35 srvfw02 charon: 05[NET] <con5000|36> sending packet: from 187.32.1.97[4500] to 3.93.27.107[4500] (76 bytes)
            Nov 18 10:53:35 srvfw02 charon: 05[IKE] <con5000|36> closing CHILD_SA con5003{1954} with SPIs c8ddb24b_i (51622786 bytes) 66b80f1d_o (1483641528 bytes) and TS 10.0.0.0/16|/0 === 172.32.0.0/16|/0
            Nov 18 10:53:35 srvfw02 charon: 05[IKE] <con5000|36> sending DELETE for ESP CHILD_SA with SPI c8ddb24b"

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

              @armandelli
              Hello
              Looks like you're showing the result of the command
              ipsec down con5000[36]

              A 1 Reply Last reply Reply Quote 0
              • A
                armandelli @Konstanti
                last edited by

                @Konstanti thanks for the reply!

                So it might be that those log lines refer to the moment I manually disconnected the ipsec.
                Next time the problem happens I will check the log messages before applying the manual disconnect/connect.

                Since the environment is in production and affecting many users, I have to restablish the service as soon as possible, not giving me much time to troubleshoot in real time.

                Thanks again!

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

                  @armandelli
                  Ideally, you should show the phase 1 and phase 2 settings
                  And the output of the command
                  ipsec statusall

                  and need logs of the second side of the connection

                  A 1 Reply Last reply Reply Quote 0
                  • A
                    armandelli @Konstanti
                    last edited by armandelli

                    @Konstanti thanks for the reply!

                    The logs from the other side I´ll see what I can do, as they are AWS VPC managed by a third party company.

                    Regarding my pfsense box, here goes the output of ipsec statusall (with public IP information ommited):

                    Status of IKE charon daemon (strongSwan 5.7.1, FreeBSD 11.2-RELEASE-p10, amd64):
                    uptime: 9 days, since Nov 10 11:04:39 2019
                    worker threads: 11 of 16 idle, 5/0/0/0 working, job queue: 0/0/0/0, scheduled: 7
                    loaded plugins: charon unbound aes des blowfish rc2 sha2 sha1 md4 md5 random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey ipseckey pem openssl fips-prf curve25519 xcbc cmac hmac curl attr kernel-pfkey kernel-pfroute resolve socket-default stroke vici updown eap-identity eap-sim eap-md5 eap-mschapv2 eap-dynamic eap-radius eap-tls eap-ttls eap-peap xauth-generic xauth-eap whitelist addrblock counters
                    Listening IP addresses:
                    179.x.x.x
                    179.x.x.x
                    179.x.x.x
                    179.x.x.x
                    172.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    187.x.x.x
                    172.23.1.254
                    10.0.10.51
                    10.0.10.1
                    10.13.8.254
                    192.168.10.1
                    10.16.1.254
                    10.16.3.254
                    10.16.5.254
                    10.16.7.254
                    10.16.9.254
                    192.168.3.1
                    10.250.250.1
                    172.16.10.253
                    Connections:
                    bypasslan: %any...%any IKEv1/2
                    bypasslan: local: uses public key authentication
                    bypasslan: remote: uses public key authentication
                    bypasslan: child: 172.23.1.0/24|/0 === 172.23.1.0/24|/0 PASS
                    con3000: 187.x.x.x...pa01.engesoftware.com.br IKEv1, dpddelay=10s
                    con3000: local: [187.x.x.x] uses pre-shared key authentication
                    con3000: remote: [201.x.x.x] uses pre-shared key authentication
                    con3000: child: 10.0.0.0/16|/0 === 10.221.1.0/24|/0 TUNNEL, dpdaction=restart
                    con3001: child: 10.16.4.0/23|/0 === 10.221.1.0/24|/0 TUNNEL, dpdaction=restart
                    con3002: child: 10.15.1.0/24|/0 === 10.221.1.0/24|/0 TUNNEL, dpdaction=restart
                    con4000: 187.x.x.x...pa02.engesoftware.com.br IKEv1, dpddelay=10s
                    con4000: local: [187.x.x.x] uses pre-shared key authentication
                    con4000: remote: [23.x.x.x] uses pre-shared key authentication
                    con4000: child: 10.0.0.0/16|/0 === 10.222.1.0/24|/0 TUNNEL, dpdaction=restart
                    con5000: 187.x.x.x...3.x.x.x IKEv1, dpddelay=10s
                    con5000: local: [187.x.x.x] uses pre-shared key authentication
                    con5000: remote: [3.x.x.x] uses pre-shared key authentication
                    con5000: child: 172.23.1.0/24|/0 === 172.31.0.0/16|/0 TUNNEL, dpdaction=restart
                    con5001: child: 10.16.0.0/16|/0 === 172.31.0.0/16|/0 TUNNEL, dpdaction=restart
                    con5002: child: 10.0.0.0/16|/0 === 172.31.0.0/16|/0 TUNNEL, dpdaction=restart
                    con5003: child: 10.0.0.0/16|/0 === 172.32.0.0/16|/0 TUNNEL, dpdaction=restart
                    con5004: child: 10.16.0.0/16|/0 === 172.32.0.0/16|/0 TUNNEL, dpdaction=restart
                    con5005: child: 172.23.1.0/24|/0 === 172.32.0.0/16|/0 TUNNEL, dpdaction=restart
                    Shunted Connections:
                    bypasslan: 172.23.1.0/24|/0 === 172.23.1.0/24|/0 PASS
                    Routed Connections:
                    con5005{2024}: ROUTED, TUNNEL, reqid 17
                    con5005{2024}: 172.23.1.0/24|/0 === 172.32.0.0/16|/0
                    con5004{2023}: ROUTED, TUNNEL, reqid 186
                    con5004{2023}: 10.16.0.0/16|/0 === 172.32.0.0/16|/0
                    con5003{2022}: ROUTED, TUNNEL, reqid 15
                    con5003{2022}: 10.0.0.0/16|/0 === 172.32.0.0/16|/0
                    con5002{2021}: ROUTED, TUNNEL, reqid 7
                    con5002{2021}: 10.0.0.0/16|/0 === 172.31.0.0/16|/0
                    con5001{2020}: ROUTED, TUNNEL, reqid 6
                    con5001{2020}: 10.16.0.0/16|/0 === 172.31.0.0/16|/0
                    con5000{2019}: ROUTED, TUNNEL, reqid 5
                    con5000{2019}: 172.23.1.0/24|/0 === 172.31.0.0/16|/0
                    con4000{2018}: ROUTED, TUNNEL, reqid 185
                    con4000{2018}: 10.0.0.0/16|/0 === 10.222.1.0/24|/0
                    con3002{2017}: ROUTED, TUNNEL, reqid 184
                    con3002{2017}: 10.15.1.0/24|/0 === 10.221.1.0/24|/0
                    con3001{2016}: ROUTED, TUNNEL, reqid 183
                    con3001{2016}: 10.16.4.0/23|/0 === 10.221.1.0/24|/0
                    con3000{2015}: ROUTED, TUNNEL, reqid 182
                    con3000{2015}: 10.0.0.0/16|/0 === 10.221.1.0/24|/0
                    Security Associations (1 up, 0 connecting):
                    con5000[49]: ESTABLISHED 93 minutes ago, 187.x.x.x[187.x.x.x]...3.x.x.x[3.x.x.x]
                    con5000[49]: IKEv1 SPIs: KEY-HERE, pre-shared key reauthentication in 6 hours
                    con5000[49]: IKE proposal: AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
                    con5000{2222}: REKEYED, TUNNEL, reqid 5, expires in 9 minutes
                    con5000{2222}: 172.23.1.0/24|/0 === 172.31.0.0/16|/0
                    con5001{2223}: REKEYED, TUNNEL, reqid 6, expires in 9 minutes
                    con5001{2223}: 10.16.0.0/16|/0 === 172.31.0.0/16|/0
                    con5003{2224}: REKEYED, TUNNEL, reqid 15, expires in 10 minutes
                    con5003{2224}: 10.0.0.0/16|/0 === 172.32.0.0/16|/0
                    con5002{2225}: REKEYED, TUNNEL, reqid 7, expires in 10 minutes
                    con5002{2225}: 10.0.0.0/16|/0 === 172.31.0.0/16|/0
                    con5005{2226}: REKEYED, TUNNEL, reqid 17, expires in 12 minutes
                    con5005{2226}: 172.23.1.0/24|/0 === 172.32.0.0/16|/0
                    con5004{2227}: INSTALLED, TUNNEL, reqid 186, ESP in UDP SPIs: c7b077d2_i c0a07721_o
                    con5004{2227}: AES_CBC_128/HMAC_SHA1_96/MODP_1024, 440631522 bytes_i (1377274 pkts, 2012s ago), 4248 bytes_o (35 pkts, 140s ago), rekeying in 12 minutes
                    con5004{2227}: 10.16.0.0/16|/0 === 172.32.0.0/16|/0
                    con5001{2228}: INSTALLED, TUNNEL, reqid 6, ESP in UDP SPIs: c8454966_i d7de6570_o
                    con5001{2228}: AES_CBC_128/HMAC_SHA1_96/MODP_1024, 24261301 bytes_i (54194 pkts, 5s ago), 0 bytes_o, rekeying in 35 minutes
                    con5001{2228}: 10.16.0.0/16|/0 === 172.31.0.0/16|/0
                    con5005{2229}: INSTALLED, TUNNEL, reqid 17, ESP in UDP SPIs: cf2e87d9_i c1b4b270_o
                    con5005{2229}: AES_CBC_128/HMAC_SHA1_96/MODP_1024, 51835711 bytes_i (75994 pkts, 14s ago), 0 bytes_o, rekeying in 39 minutes
                    con5005{2229}: 172.23.1.0/24|/0 === 172.32.0.0/16|/0
                    con5000{2230}: INSTALLED, TUNNEL, reqid 5, ESP in UDP SPIs: c726e7a7_i a92840e7_o
                    con5000{2230}: AES_CBC_128/HMAC_SHA1_96/MODP_1024, 32458073 bytes_i (102776 pkts, 6s ago), 0 bytes_o, rekeying in 39 minutes
                    con5000{2230}: 172.23.1.0/24|/0 === 172.31.0.0/16|/0
                    con5003{2231}: INSTALLED, TUNNEL, reqid 15, ESP in UDP SPIs: c195cada_i fbb87765_o
                    con5003{2231}: AES_CBC_128/HMAC_SHA1_96/MODP_1024, 25662881 bytes_i (109438 pkts, 5s ago), 0 bytes_o, rekeying in 46 minutes
                    con5003{2231}: 10.0.0.0/16|/0 === 172.32.0.0/16|/0
                    con5002{2232}: INSTALLED, TUNNEL, reqid 7, ESP in UDP SPIs: cdca2ae8_i 0a0ec023_o
                    con5002{2232}: AES_CBC_128/HMAC_SHA1_96/MODP_1024, 508394 bytes_i (6233 pkts, 0s ago), 0 bytes_o, rekeying in 45 minutes
                    con5002{2232}: 10.0.0.0/16|/0 === 172.31.0.0/16|/0

                    Regarding Phase 1 and 2 configuration, it´s a lot of stuff and maybe it will pollute the post. Could you specify which part or configuration item would be interesting to look at regarding the issue at hand?

                    Thanks again my friend!

                    Andre.

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

                      @armandelli said in Phase 2 : "invalid HASH_V1 payload length" error:

                      Regarding Phase 1 and 2 configuration, it´s a lot of stuff and maybe it will pollute the post. Could you specify which part or configuration item would be interesting to look at regarding the issue at hand?
                      Thanks again my friend!

                      Hello
                      This is quite enough to understand how everything is set up
                      Now it is necessary to see logs at that moment when there is a failure .

                      A 1 Reply Last reply Reply Quote 0
                      • A
                        armandelli @Konstanti
                        last edited by

                        @Konstanti follows attached part of the ipsec log.

                        The loss of connection was reported at around 10:53 and almost immediately I applied the disconnect/connect workaround to restablish the service. Hope this helps. error-vpn-18Nov.txt

                        I am currently monitoring the connection in order to retrieve more precise logs in real time.

                        Tks a lot!

                        1 Reply Last reply Reply Quote 0
                        • G
                          gchialli @gchialli
                          last edited by gchialli

                          @gchialli said in Phase 2 : "invalid HASH_V1 payload length" error:

                          I apologize for replying to this old topic, but I'm having the same issue I think. I'm on 2.4.4-p1. I have already bumped the max_ikev1_exchanges
                          value to 50, but the errors keep happening, and the tunnel restarts every 2 minutes.
                          @cukal Have you been able to find a solution for this?
                          Thank you

                          Hello,
                          Just wanted to update the forum that my issue got resolved. It was caused by one proxy-id configured with the wrong prefix-length on the other side.
                          Thanks

                          1 Reply Last reply Reply Quote 0
                          • First post
                            Last post