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

    Phase 2 : "invalid HASH_V1 payload length" error

    Scheduled Pinned Locked Moved IPsec
    19 Posts 5 Posters 3.4k 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.
    • P
      Peter2121
      last edited by

      I have a really strange problem, establishing VPN tunnel between pfSense 2.3.2-RELEASE-p1 and Sophos SG (based on Astaro, uses Pluto as IKE daemon).
      I have 2 local networks (pfSense side) and 3 distant networks (Sophos side). If I configure two firewalls with such 6 phases 2 - the tunnel does not work. But if I leave just one configured network in Sophos configuration (for pfSense side) - the tunnel works correctly. It works for both present networks separately, but not in the same time. The networks are completely different (10.192.20.0/24 and 192.168.32.0/24).
      When the tunnel is down I can see in logs that Phase 1 and Phase 2 negotiations are successful for phase 1 and for all phases 2 present, BUT in pfSense logs I se the following errors:

      Jan 11 18:07:24 firewall charon: 11[NET] <con1000|6> received packet: from sss.sss.214.38[500] to sss.sss.188.161[500] (68 bytes)
      Jan 11 18:07:24 firewall charon: 11[ENC] <con1000|6> invalid HASH_V1 payload length, decryption failed?
      Jan 11 18:07:24 firewall charon: 11[ENC] <con1000|6> could not decrypt payloads
      Jan 11 18:07:24 firewall charon: 11[IKE] <con1000|6> message parsing failed
      Jan 11 18:07:24 firewall charon: 11[ENC] <con1000|6> generating INFORMATIONAL_V1 request 83928482 [ HASH N(PLD_MAL) ]
      Jan 11 18:07:24 firewall charon: 11[NET] <con1000|6> sending packet: from sss.sss.188.161[500] to sss.sss.214.38[500] (84 bytes)
      Jan 11 18:07:24 firewall charon: 11[IKE] <con1000|6> QUICK_MODE request with message ID 820365128 processing failed
      

      Evidently, Sophos does not know what to do with such packet and just drops PAYLOAD_MALFORMED. It continues to send packets (the tunnel is 'up'), but pfSense cannot decrypt them.
      Once again, if I use just ONE network (only Sophos configuration is changed!) on pfSense side - the tunnel works correctly, for both networks. So there is no problem with PSK, choosing proposals etc.
      Looks like a bug, but where? Pluto?
      Any ideas?

      1 Reply Last reply Reply Quote 0
      • P
        Peter2121
        last edited by

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

        invalid HASH_V1 payload length

        It seems that we touched the issue explained here:
        https://wiki.strongswan.org/issues/1120
        So, we need to increase a number of simultaneous phase 2 negotiations in StrongSWan config:
        https://wiki.strongswan.org/issues/1128
        Is it possible on pfSense?
        PS
        I think to update the version to 2.4.4 this evening, so it would be interesting to see the instructions for both 2.3.2 and 2.4.4 versions.

        K 2 Replies Last reply Reply Quote 0
        • K
          Konstanti @Peter2121
          last edited by Konstanti

          @peter2121
          Hey
          I correctly understand that it is a question here about this setting ?
          Charon.max_ikev1_exchanges = 3
          Maximum number of IKEv1 phase 2 exchange for IKE_SA store state and
          he track at the same time.

          If so, you should do so
          Diagnostics/Edit File
          Open the file /etc/inc / vpn.inc
          Looking for here's a snippet
          0_1547570076831_c09778d1-59ab-49fc-80e5-c62674f683d4-image.png

          Make it so (Do not delete anything, add only one line)

          0_1547569738819_65815783-0426-4ec5-9d59-259fc9802e60-image.png

          Save file
          Continue
          VPN/IPSEC/IPSEC tunnels / Edit phase 1 entry / (Change nothing) / Save
          Apply changes
          Restart service
          and check

          cukalC 1 Reply Last reply Reply Quote 1
          • K
            Konstanti @Peter2121
            last edited by

            @peter2121 Wanted to know if my decision helped ?

            P 1 Reply Last reply Reply Quote 0
            • P
              Peter2121 @Konstanti
              last edited by

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

              @peter2121 Wanted to know if my decision helped ?

              Thank you, I could change StrongSWan parameters using your advise.
              I still have problems with my tunnels though :(
              Probably, there are several problems, I've just eliminated the first one.

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

                @konstanti Setting the key max_ikey1_exchanges = 6 fixed my problem with

                invalid HASH_V1 payload length, decryption failed?
                

                and consequently this error message:

                no matching CHILD_SA config found
                

                Will this change in /etc/inc/vpn.inc be retained after reboots and such?

                Thanks!

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

                  @cukal

                  These changes will persist until the system is updated
                  After you update the file vpn.inc will be overwritten
                  And all the changes will have to be made again

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

                    @Konstanti Thanks for your reply.
                    Is there a specific reason the number of max_ikey1_exchanges is 6?
                    I'm seeing some issues with a public IP where multiple P1's (with P2's) are enabled but each time with different remote peers.
                    Problem I'm having is a P1 with 5 P2's, that connection still logs invalid HASH_V1 payload length, decryption failed?

                    Thanks!

                    K 1 Reply Last reply Reply Quote 0
                    • 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
                                          Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.