[strongSwan] reconect "loop" with: invalid HASH_V1 payload length, decryption failed
Noel Kuntze
noel.kuntze+strongswan-users-ml at thermi.consulting
Wed Aug 4 20:05:47 CEST 2021
Hello Lorenzo,
Looks like the log is truncated between 08:04:33 and 08:10:03.
Please provide complete logs, and get logs from the other peer.
See the HelpRequests article on the wiki for useful debug levels[1].
Kind regards
Noel
[1] https://wiki.strongswan.org/projects/strongswan/wiki/HelpRequests
Am 04.08.21 um 08:15 schrieb Lorenzo Milesi:
> I've a tunnel between a Fortigate 50E and a StrongSwan 5.8.2 server. The tunnel is normally up and running but every x minutes the connection is dropped for one minute, and then comes up again.
> I checked the FAQs about that error, so I tried explicitly setting PSK for the IP address (I had %any before), it seems to last longer but the drop is still happening regularly.
> Why rekeying doesn't work if connection does?
> thanks
>
>
> Aug 4 08:04:32 vpn01 charon: 06[ENC] generating QUICK_MODE request 1670801381 [ HASH SA No KE ID ID ]
> Aug 4 08:04:32 vpn01 charon: 06[NET] sending packet: from strongswan_ip[4500] to forti_ip[4500] (588 bytes)
> Aug 4 08:04:32 vpn01 charon: 07[NET] received packet: from forti_ip[4500] to strongswan_ip[4500] (92 bytes)
> Aug 4 08:04:32 vpn01 charon: 07[ENC] parsed INFORMATIONAL_V1 request 2622873796 [ HASH D ]
> Aug 4 08:04:32 vpn01 charon: 07[IKE] received DELETE for ESP CHILD_SA with SPI 168c51e3
> Aug 4 08:04:32 vpn01 charon: 07[IKE] CHILD_SA not found, ignored
> Aug 4 08:04:32 vpn01 charon: 08[NET] received packet: from forti_ip[4500] to strongswan_ip[4500] (92 bytes)
> Aug 4 08:04:32 vpn01 charon: 08[ENC] parsed INFORMATIONAL_V1 request 474486553 [ HASH D ]
> Aug 4 08:04:32 vpn01 charon: 08[IKE] received DELETE for ESP CHILD_SA with SPI 168c51e1
> Aug 4 08:04:32 vpn01 charon: 08[IKE] CHILD_SA not found, ignored
> Aug 4 08:04:32 vpn01 charon: 16[NET] received packet: from forti_ip[4500] to strongswan_ip[4500] (92 bytes)
> Aug 4 08:04:32 vpn01 charon: 16[ENC] parsed INFORMATIONAL_V1 request 3851758626 [ HASH D ]
> Aug 4 08:04:32 vpn01 charon: 16[IKE] received DELETE for ESP CHILD_SA with SPI 168c51e2
> Aug 4 08:04:32 vpn01 charon: 16[IKE] CHILD_SA not found, ignored
> Aug 4 08:04:32 vpn01 charon: 12[NET] received packet: from forti_ip[4500] to strongswan_ip[4500] (92 bytes)
> Aug 4 08:04:32 vpn01 charon: 12[ENC] parsed INFORMATIONAL_V1 request 3352306708 [ HASH D ]
> Aug 4 08:04:32 vpn01 charon: 12[IKE] received DELETE for ESP CHILD_SA with SPI 168c51e4
> Aug 4 08:04:32 vpn01 charon: 12[IKE] CHILD_SA not found, ignored
> Aug 4 08:04:32 vpn01 charon: 11[NET] received packet: from forti_ip[4500] to strongswan_ip[4500] (572 bytes)
> Aug 4 08:04:32 vpn01 charon: 11[ENC] parsed QUICK_MODE request 2074613372 [ HASH SA No KE ID ID ]
> Aug 4 08:04:32 vpn01 charon: 11[CFG] selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/MODP_3072/NO_EXT_SEQ
> Aug 4 08:04:32 vpn01 charon: 11[IKE] received 3600s lifetime, configured 86400s
> Aug 4 08:04:32 vpn01 charon: 15[IKE] remote host is behind NAT
> Aug 4 08:04:32 vpn01 charon: 14[IKE] remote host is behind NAT
> Aug 4 08:04:32 vpn01 charon: 11[ENC] generating QUICK_MODE response 2074613372 [ HASH SA No KE ID ID ]
> Aug 4 08:04:33 vpn01 charon: 11[NET] sending packet: from strongswan_ip[4500] to forti_ip[4500] (588 bytes)
> Aug 4 08:04:33 vpn01 charon: 12[NET] received packet: from forti_ip[4500] to strongswan_ip[4500] (604 bytes)
> Aug 4 08:04:33 vpn01 charon: 12[ENC] invalid HASH_V1 payload length, decryption failed?
> Aug 4 08:04:33 vpn01 charon: 12[ENC] could not decrypt payloads
> Aug 4 08:04:33 vpn01 charon: 12[IKE] message parsing failed
> Aug 4 08:04:33 vpn01 charon: 12[ENC] generating INFORMATIONAL_V1 request 2030801044 [ HASH N(PLD_MAL) ]
> Aug 4 08:10:03 vpn01 charon: 10[IKE] giving up after 5 retransmits
> Aug 4 08:10:03 vpn01 charon: 10[IKE] restarting CHILD_SA remote01-lan
> Aug 4 08:10:03 vpn01 charon: 10[IKE] initiating Main Mode IKE_SA remote01-base[151609] to forti_ip
> Aug 4 08:10:03 vpn01 charon: 10[ENC] generating ID_PROT request 0 [ SA V V V V V ]
> Aug 4 08:10:03 vpn01 charon: 10[NET] sending packet: from strongswan_ip[500] to forti_ip[500] (240 bytes)
> Aug 4 08:10:03 vpn01 charon: 10[IKE] restarting CHILD_SA remote01-wifi
> Aug 4 08:10:03 vpn01 charon: 11[NET] received packet: from forti_ip[500] to strongswan_ip[500] (188 bytes)
> Aug 4 08:10:03 vpn01 charon: 11[ENC] parsed ID_PROT response 0 [ SA V V V V V ]
> Aug 4 08:10:03 vpn01 charon: 11[IKE] received NAT-T (RFC 3947) vendor ID
> Aug 4 08:10:03 vpn01 charon: 11[IKE] received DPD vendor ID
> Aug 4 08:10:03 vpn01 charon: 11[ENC] received unknown vendor ID: 82:99:03:17:57:a3:60:82:c6:a6:21:de:00:00:00:00
> Aug 4 08:10:03 vpn01 charon: 11[IKE] received FRAGMENTATION vendor ID
> Aug 4 08:10:03 vpn01 charon: 11[IKE] received FRAGMENTATION vendor ID
> Aug 4 08:10:03 vpn01 charon: 11[CFG] selected proposal: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_3072
> Aug 4 08:10:03 vpn01 charon: 08[KNL] creating delete job for CHILD_SA ESP/0xc4e0d6cf/strongswan_ip
> Aug 4 08:10:03 vpn01 charon: 08[JOB] CHILD_SA ESP/0xc4e0d6cf/strongswan_ip not found for delete
> Aug 4 08:10:03 vpn01 charon: 06[KNL] creating delete job for CHILD_SA ESP/0xc0b04a54/strongswan_ip
> Aug 4 08:10:03 vpn01 charon: 06[JOB] CHILD_SA ESP/0xc0b04a54/strongswan_ip not found for delete
> Aug 4 08:10:03 vpn01 charon: 11[ENC] generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
> Aug 4 08:10:03 vpn01 charon: 11[NET] sending packet: from strongswan_ip[500] to forti_ip[500] (524 bytes)
> Aug 4 08:10:03 vpn01 charon: 15[NET] received packet: from forti_ip[500] to strongswan_ip[500] (508 bytes)
> Aug 4 08:10:03 vpn01 charon: 15[ENC] parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
> Aug 4 08:10:04 vpn01 charon: 15[IKE] remote host is behind NAT
> Aug 4 08:10:04 vpn01 charon: 15[ENC] generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
> Aug 4 08:10:04 vpn01 charon: 15[NET] sending packet: from strongswan_ip[4500] to forti_ip[4500] (108 bytes)
> Aug 4 08:10:04 vpn01 charon: 05[NET] received packet: from forti_ip[4500] to strongswan_ip[4500] (92 bytes)
> Aug 4 08:10:04 vpn01 charon: 05[ENC] parsed ID_PROT response 0 [ ID HASH ]
>
> ipsec.conf:
> conn remote01-base
> keyexchange=ikev1
> fragmentation=yes
> dpdaction=restart
> ike=aes256-sha256-modp3072
> esp=aes256-sha256-modp3072
> keyingtries=%forever
> leftsubnet=172.32.1.0/24
> lifetime=86400
> leftauth=psk
> rightauth=psk
> rightid=Exme
> auto=start
> right=forti_ip
>
> conn remote01-lan
> also=remote01-base
> leftsubnet=172.32.1.0/24
> rightsubnet=192.168.2.0/24
>
> conn remote01-wifi
> also=remote01-base
> leftsubnet=172.32.1.0/24
> rightsubnet=192.168.33.0/24
>
>
> ipsec.secrets:
> forti_ip : PSK abcde
>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: OpenPGP_signature
Type: application/pgp-signature
Size: 840 bytes
Desc: OpenPGP digital signature
URL: <http://lists.strongswan.org/pipermail/users/attachments/20210804/c6568ec4/attachment.sig>
More information about the Users
mailing list