[strongSwan] reconect "loop" with: invalid HASH_V1 payload length, decryption failed

Lorenzo Milesi lorenzo.milesi at yetopen.com
Wed Aug 4 08:15:25 CEST 2021 

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

-- 
Lorenzo Milesi - lorenzo.milesi at yetopen.com 
CTO @ YetOpen Srl

YetOpen - https://www.yetopen.com/

Via Salerno 18 - 23900 Lecco - ITALY -      | 4801 Glenwood Avenue - Suite 200 - Raleigh, NC 27612 - USA -
Tel +39 0341 220 205 - info.it at yetopen.com  | Phone +1 919-817-8106 - info.us at yetopen.com

Think green - Non stampare questa e-mail se non necessario / Don't print this email unless necessary

-------- D.Lgs. 196/2003 e GDPR 679/2016 --------
Tutte le informazioni contenute in questo messaggio sono riservate ed a uso esclusivo del destinatario.
Tutte le informazioni ivi contenute, compresi eventuali allegati, sono da ritenere confidenziali e riservate secondo i termini
del vigente D.Lgs. 196/2003 in materia di privacy e del Regolamento europeo 679/2016 - GDPR - e quindi ne e' proibita l'utilizzazione ulteriore non autorizzata.
Nel caso in cui questo messaggio Le fosse pervenuto per errore, La invitiamo ad eliminarlo senza copiarlo, stamparlo, a non inoltrarlo a terzi e ad avvertirci non appena possibile.
Grazie.

Confidentiality notice: this email message including any attachment is for the sole use of the intended recipient and may contain confidential and privileged information;
pursuant to Legislative Decree 196/2003 and the European General Data Protection Regulation 679/2016 - GDPR - any unauthorized review, use, disclosure or distribution
is prohibited. If you are not the intended recepient please delete this message without copying, printing or forwarding it to others, and alert us as soon as possible.
Thank you.

More information about the Users mailing list