IPSec Site-2-Site VPN gone mad: ALERT: Couldn't parse IKE message from remoteIP[4500]. Check the debug logs.

Question

An XG106 with SFOS 19.0.1 has a unchanged VPN Tunnel to a SG Firewall. The tunnel is up and communication through the tunnel is possible.

But since the last Firmwareupgrade of the SG Firewall (9.712-13) , the XG is producing Gigabytes of errors and the reporting partition was already full. Before that, there was no issue.

XG is initiator, SG responds only.

Main error is:

ALERT: Couldn't parse IKE message from 212.xxx.xxx.62[4500]. Check the debug logs.

212.xxx.xxx.62 is the remote IP of the SG FW.

10.1.254.1 ist the WAN NAT IP of XG.

87.xxx.xxx.127 is the WAN IP of XG.

strongswan.log:

2022-11-18 12:42:34Z 17[ENC] <Tunnel_ABC-1|1> generating INFORMATIONAL_V1 request 1317840500 [ HASH N(PLD_MAL) ]
2022-11-18 12:42:34Z 17[NET] <Tunnel_ABC-1|1> sending packet: from 10.1.254.1[4500] to 212.xxx.xxx.62[4500] (92 bytes)
2022-11-18 12:42:34Z 17[IKE] <Tunnel_ABC-1|1> QUICK_MODE request with message ID 2342557437 processing failed
2022-11-18 12:42:34Z 17[DMN] <Tunnel_ABC-1|1> [GARNER-LOGGING] (child_alert) ALERT: Couldn't parse IKE message from 212.xxx.xxx.62[4500]. Check the debug logs.
2022-11-18 12:42:35Z 25[NET] <Tunnel_ABC-1|1> received packet: from 212.xxx.xxx.62[4500] to 10.1.254.1[4500] (460 bytes)
2022-11-18 12:42:35Z 25[ENC] <Tunnel_ABC-1|1> invalid HASH_V1 payload length, decryption failed?
2022-11-18 12:42:35Z 25[ENC] <Tunnel_ABC-1|1> could not decrypt payloads
2022-11-18 12:42:35Z 25[IKE] <Tunnel_ABC-1|1> message parsing failed
2022-11-18 12:42:35Z 25[ENC] <Tunnel_ABC-1|1> generating INFORMATIONAL_V1 request 1499943847 [ HASH N(PLD_MAL) ]
2022-11-18 12:42:35Z 25[NET] <Tunnel_ABC-1|1> sending packet: from 10.1.254.1[4500] to 212.xxx.xxx.62[4500] (92 bytes)
2022-11-18 12:42:35Z 25[IKE] <Tunnel_ABC-1|1> QUICK_MODE request with message ID 4226133011 processing failed
2022-11-18 12:42:35Z 25[DMN] <Tunnel_ABC-1|1> [GARNER-LOGGING] (child_alert) ALERT: Couldn't parse IKE message from 212.xxx.xxx.62[4500]. Check the debug logs.
2022-11-18 12:42:35Z 25[NET] <Tunnel_ABC-1|1> received packet: from 212.xxx.xxx.62[4500] to 10.1.254.1[4500] (476 bytes)
2022-11-18 12:42:35Z 25[ENC] <Tunnel_ABC-1|1> invalid HASH_V1 payload length, decryption failed?
2022-11-18 12:42:35Z 25[ENC] <Tunnel_ABC-1|1> could not decrypt payloads
2022-11-18 12:42:35Z 25[IKE] <Tunnel_ABC-1|1> message parsing failed
2022-11-18 12:42:35Z 25[ENC] <Tunnel_ABC-1|1> generating INFORMATIONAL_V1 request 3677167524 [ HASH N(PLD_MAL) ]
2022-11-18 12:42:35Z 25[NET] <Tunnel_ABC-1|1> sending packet: from 10.1.254.1[4500] to 212.xxx.xxx.62[4500] (92 bytes)
2022-11-18 12:42:35Z 25[IKE] <Tunnel_ABC-1|1> QUICK_MODE request with message ID 1391690793 processing failed
2022-11-18 12:42:35Z 25[DMN] <Tunnel_ABC-1|1> [GARNER-LOGGING] (child_alert) ALERT: Couldn't parse IKE message from 212.xxx.xxx.62[4500]. Check the debug logs.
2022-11-18 12:42:35Z 18[NET] <Tunnel_ABC-1|1> received packet: from 212.xxx.xxx.62[4500] to 10.1.254.1[4500] (476 bytes)
2022-11-18 12:42:35Z 18[ENC] <Tunnel_ABC-1|1> invalid HASH_V1 payload length, decryption failed?
2022-11-18 12:42:35Z 18[ENC] <Tunnel_ABC-1|1> could not decrypt payloads
2022-11-18 12:42:35Z 18[IKE] <Tunnel_ABC-1|1> message parsing failed
2022-11-18 12:42:35Z 18[ENC] <Tunnel_ABC-1|1> generating INFORMATIONAL_V1 request 3581790772 [ HASH N(PLD_MAL) ]
2022-11-18 12:42:35Z 18[NET] <Tunnel_ABC-1|1> sending packet: from 10.1.254.1[4500] to 212.xxx.xxx.62[4500] (92 bytes)
2022-11-18 12:42:35Z 18[IKE] <Tunnel_ABC-1|1> QUICK_MODE request with message ID 3476906697 processing failed
2022-11-18 12:42:35Z 18[DMN] <Tunnel_ABC-1|1> [GARNER-LOGGING] (child_alert) ALERT: Couldn't parse IKE message from 212.xxx.xxx.62[4500]. Check the debug logs.
2022-11-18 12:42:35Z 32[NET] <Tunnel_ABC-1|1> received packet: from 212.xxx.xxx.62[4500] to 10.1.254.1[4500] (460 bytes)
2022-11-18 12:42:35Z 32[ENC] <Tunnel_ABC-1|1> parsed QUICK_MODE request 4034064137 [ HASH SA No KE ID ID ]
2022-11-18 12:42:35Z 32[IKE] <Tunnel_ABC-1|1> ### process_request invoking quick_mode_create
2022-11-18 12:42:35Z 32[IKE] <Tunnel_ABC-1|1> ### quick_mode_create: 0x7fc520015f20 config (nil)
2022-11-18 12:42:35Z 32[IKE] <Tunnel_ABC-1|1> ### process_r: 0x7fc520015f20 QM_INIT
2022-11-18 12:42:35Z 32[IKE] <Tunnel_ABC-1|1> trying other candidates from phase 1
2022-11-18 12:42:35Z 32[IKE] <Tunnel_ABC-1|1> no matching CHILD_SA config found
2022-11-18 12:42:35Z 32[IKE] <Tunnel_ABC-1|1> ### destroy: 0x7fc520015f20
2022-11-18 12:42:35Z 32[ENC] <Tunnel_ABC-1|1> generating INFORMATIONAL_V1 request 1611972440 [ HASH N(INVAL_ID) ]
2022-11-18 12:42:35Z 32[NET] <Tunnel_ABC-1|1> sending packet: from 10.1.254.1[4500] to 212.xxx.xxx.62[4500] (92 bytes)
2022-11-18 12:42:35Z 19[NET] <Tunnel_ABC-1|1> received packet: from 212.xxx.xxx.62[4500] to 10.1.254.1[4500] (460 bytes)
2022-11-18 12:42:35Z 19[ENC] <Tunnel_ABC-1|1> invalid HASH_V1 payload length, decryption failed?
2022-11-18 12:42:35Z 19[ENC] <Tunnel_ABC-1|1> could not decrypt payloads
2022-11-18 12:42:35Z 19[IKE] <Tunnel_ABC-1|1> message parsing failed
2022-11-18 12:42:35Z 19[ENC] <Tunnel_ABC-1|1> generating INFORMATIONAL_V1 request 3861111861 [ HASH N(PLD_MAL) ]
2022-11-18 12:42:35Z 19[NET] <Tunnel_ABC-1|1> sending packet: from 10.1.254.1[4500] to 212.xxx.xxx.62[4500] (92 bytes)
2022-11-18 12:42:35Z 19[IKE] <Tunnel_ABC-1|1> QUICK_MODE request with message ID 2041049298 processing failed
2022-11-18 12:42:35Z 19[DMN] <Tunnel_ABC-1|1> [GARNER-LOGGING] (child_alert) ALERT: Couldn't parse IKE message from 212.xxx.xxx.62[4500]. Check the debug logs.
2022-11-18 12:42:35Z 19[NET] <Tunnel_ABC-1|1> received packet: from 212.xxx.xxx.62[4500] to 10.1.254.1[4500] (476 bytes)
2022-11-18 12:42:35Z 19[ENC] <Tunnel_ABC-1|1> invalid HASH_V1 payload length, decryption failed?
2022-11-18 12:42:35Z 19[ENC] <Tunnel_ABC-1|1> could not decrypt payloads
2022-11-18 12:42:35Z 19[IKE] <Tunnel_ABC-1|1> message parsing failed
2022-11-18 12:42:35Z 19[ENC] <Tunnel_ABC-1|1> generating INFORMATIONAL_V1 request 2327794970 [ HASH N(PLD_MAL) ]
2022-11-18 12:42:35Z 19[NET] <Tunnel_ABC-1|1> sending packet: from 10.1.254.1[4500] to 212.xxx.xxx.62[4500] (92 bytes)
2022-11-18 12:42:35Z 19[IKE] <Tunnel_ABC-1|1> QUICK_MODE request with message ID 3029038951 processing failed
2022-11-18 12:42:35Z 19[DMN] <Tunnel_ABC-1|1> [GARNER-LOGGING] (child_alert) ALERT: Couldn't parse IKE message from 212.xxx.xxx.62[4500]. Check the debug logs.

That is the SG log:

2022:11:18-00:00:04 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1975465: starting keying attempt 104 of an unlimited number
2022:11:18-00:00:04 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1975614: initiating Quick Mode PUBKEY+ENCRYPT+COMPRESS+TUNNEL+PFS to replace #1975465 {using isakmp#1958337}
2022:11:18-00:00:04 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:04 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:04 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:04 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:04 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:04 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:04 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:04 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:04 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:04 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type NO_PROPOSAL_CHOSEN
2022:11:18-00:00:05 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_3"[1] 87.xxx.xxx.127:4500 #1975466: max number of retransmissions (2) reached STATE_QUICK_I1
2022:11:18-00:00:05 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_3"[1] 87.xxx.xxx.127:4500 #1975466: starting keying attempt 52 of an unlimited number
2022:11:18-00:00:05 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_3"[1] 87.xxx.xxx.127:4500 #1975615: initiating Quick Mode PUBKEY+ENCRYPT+COMPRESS+TUNNEL+PFS to replace #1975466 {using isakmp#1958337}
2022:11:18-00:00:05 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:05 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:05 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:05 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type NO_PROPOSAL_CHOSEN
2022:11:18-00:00:06 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:06 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:06 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:06 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:07 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_14"[1] 87.xxx.xxx.127:4500 #1975470: max number of retransmissions (2) reached STATE_QUICK_I1
2022:11:18-00:00:07 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_14"[1] 87.xxx.xxx.127:4500 #1975470: starting keying attempt 6 of an unlimited number
2022:11:18-00:00:07 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_14"[1] 87.xxx.xxx.127:4500 #1975616: initiating Quick Mode PUBKEY+ENCRYPT+COMPRESS+TUNNEL+PFS to replace #1975470 {using isakmp#1958337}
2022:11:18-00:00:07 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_1"[1] 87.xxx.xxx.127:4500 #1975469: max number of retransmissions (2) reached STATE_QUICK_I1
2022:11:18-00:00:07 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_1"[1] 87.xxx.xxx.127:4500 #1975469: starting keying attempt 52 of an unlimited number
2022:11:18-00:00:07 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_1"[1] 87.xxx.xxx.127:4500 #1975617: initiating Quick Mode PUBKEY+ENCRYPT+COMPRESS+TUNNEL+PFS to replace #1975469 {using isakmp#1958337}
2022:11:18-00:00:07 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type PAYLOAD_MALFORMED
2022:11:18-00:00:07 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type NO_PROPOSAL_CHOSEN
2022:11:18-00:00:07 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_9"[1] 87.xxx.xxx.127:4500 #1958337: ignoring informational payload, type NO_PROPOSAL_CHOSEN
2022:11:18-00:00:09 fw-320-1 pluto[8604]: "S_REF_IpsSitTunnelABC2_14"[1] 87.xxx.xxx.127:4500 #1975472: max number of retransmissions (2) reached STATE_QUICK_I1

I already rebooted the XG106 cluster. No luck.

On SG tunnel was also shown as up.

Simply re-enabling the Tunnel on SG side solved the issue for now. Any idea, what was causing this behaviour?

This thread was automatically locked due to age.

LHerzog · Accepted Answer

LHerzog said: Compression was enabled - this setting was OK for years. Disabled it. Restarted the connection and is fine again. We'll see if the issue comes back. 
 Tunnel is fine so far after disabling compression on both sides (SG & XG Firewall). Re-keying works and the errors did not came back.

Vivek Jagad · Answer

Hello LHerzog , Thank you for reaching out to the community, this could be possibly an issue with the PSK based on the following errors: "could not decrypt payloads" & "invalid HASH_V1 payload length, decryption failed?" But based on the SG logs shared: "ignoring informational payload, type PAYLOAD_MALFORMED" would seem the policy mismatch, disable data compression and PFS and try again if enabled ! Create a new policy for this connection. And may I know the length of the PSK used ? Again that may also effect ! I would have recommended you to switch to IKev2 but again SG does not support IKev2 Unlike XG !

IPSec Site-2-Site VPN gone mad: ALERT: Couldn't parse IKE message from remoteIP[4500]. Check the debug logs.

Top Replies