Register Now

Login

Lost Password

Lost your password? Please enter your email address. You will receive a link and will create a new password via email.

How To Troubleshoot IPSEC VPN Logs In Sophos XG

Here in this article we will learn how to troubleshoot IPSEC VPN related issues in sophos XG firewall by analysing logs.

In case if you are doing initial setup for VPN, follow this article:

Configuration

Strongswan service is responsible for establishing IPSEC VPN, so all the errors related to VPN will be stored in “strongswan.log“. So the first step is to keep this service in debug mode, if we do not keep this service in debug we will get very less information from the logs by which we cannot point out the issue correctly. If we keep this service in debug mode, we will get detailed information in logs.

Strongswan service in debug mode:

Step-1: Login to the cli of the firewall using putty.

Step-2: Select device management as shown in below image

Device management
Device Management

Step-3: Select advanced shell as shown in below image

advanced shell
Advanced shell

Now type this command “service -S | grep strong“. This command will be used to check whether this service is running in debug mode or normal mode. As we can see from the below image, strong swan service is running in normal mode. If its running in debug mode we will be able to observe word debug beside running.

strong swan service
Strongswan service

Now to keep this service in debug mode, we need to execute this command “service strongswan:debug -ds nosync” which will keep this service in debug mode as shown in below image

strongswan service debug
Strongswan debug

Now we have kept this service “strongswan” in debug mode, we need to analyse these logs.

Analysing Logs:

This is the time to analyse logs. Enter this command “cd /log” this will move you to log directory. Then execute this command “tail -f strongswan.log” and try to connect IPSEC tunnel again, then it will list all the logs as shown in below image.

strongswan logs
strongswan logs

Issue-1: Incorrect Traffic Selectors

Sample logs:

020-09-20 00:25:13 05[NET] <Azure_to_XG-1|9> received packet: from 72.138.xx.xx[4500] to 10.0.0.4[4500] (1168 bytes)

2020-09-20 00:25:13 05[ENC] <Azure_to_XG-1|9> parsed CREATE_CHILD_SA request 2 [ SA No KE TSi TSr ]

2020-09-20 00:25:13 05[CFG] <Azure_to_XG-1|9> looking for a child config for 10.0.1.0/24 === 172.16.19.0/24

2020-09-20 00:25:13 05[IKE] <Azure_to_XG-1|9> traffic selectors 10.0.1.0/24 === 172.16.19.0/24 inacceptable

2020-09-20 00:25:13 05[DMN] <Azure_to_XG-1|9> [GARNER-LOGGING] (child_alert) ALERT: the received traffic selectors did not match: 172.16.19.0/24 === 10.0.1.0/24 << Local and remote network did not match.

2020-09-20 00:25:13 05[IKE] <Azure_to_XG-1|9> failed to establish CHILD_SA, keeping IKE_SA

Resolution:

This error is caused due to mismatch of local and remote networks in both the firewalls. Local and remote networks must match in both firewalls.

local remote networks
firewall-1

Issue-2: No IKE Config found

Sample logs:

Logs on remote(respond only) XG firewall

2020-09-24 18:51:19 13[NET] <100> received packet: from 72.138.xx.xx1[500] to 10.0.0.4[500] (872 bytes)

2020-09-24 18:51:19 13[ENC] <100> parsed ID_PROT request 0 [ SA V V V V V V ]

2020-09-24 18:51:19 13[CFG] <100> looking for an ike config for 10.0.0.4…72.138.xx.xx

2020-09-24 18:51:19 13[IKE] <100> no IKE config found for 10.0.0.4…72.138.xx.xx, sending NO_PROPOSAL_CHOSEN

2020-09-24 18:51:19 13[ENC] <100> generating INFORMATIONAL_V1 request 1316998708 [ N(NO_PROP) ]

2020-09-24 18:51:19 13[NET] <100> sending packet: from 10.0.0.4[500] to 72.138.107.211[500] (40 bytes)

2020-09-24 18:51:19 13[IKE] <100> IKE_SA (unnamed)[100] state change: CREATED => DESTROYING

Logs on Local(Initiator) XG firewall

2020-09-24 09:50:54 06[NET] <To_Azure_XG-1|108> received packet: from 40.84.xx.xx [500] to 192.168.1.16[500] (40 bytes)

2020-09-24 09:50:54 06[ENC] <To_Azure_XG-1|108> parsed INFORMATIONAL_V1 request 1316998708 [ N(NO_PROP) ]

2020-09-24 09:50:54 06[IKE] <To_Azure_XG-1|108> informational: received NO_PROPOSAL_CHOSEN error notify

2020-09-24 09:50:54 06[IKE] <To_Azure_XG-1|108> IKE_SA NO_PROPOSAL_CHOSEN set_condition COND_START_OVER

2020-09-24 09:50:54 06[IKE] <To_Azure_XG-1|108> flush_queue(IKE_MOBIKE)

2020-09-24 09:50:54 06[IKE] <To_Azure_XG-1|108> ### destroy: 0x7f9b88001f80

2020-09-24 09:50:54 06[IKE] <To_Azure_XG-1|108> flush_queue(IKE_NATD)

2020-09-24 09:50:54 06[IKE] <To_Azure_XG-1|108> flush_queue(IKE_INIT)

2020-09-24 09:50:54 06[IKE] <To_Azure_XG-1|108> IKE_SA has_condition COND_START_OVER retry initiate in 60 sec

2020-09-24 09:50:54 06[IKE] <To_Azure_XG-1|108> IKE_SA To_Azure_XG-1[108] state change: CONNECTING => DESTROYING

Resolution:

This error could be due to mismatch of IKE version in IPSEC policies, on both ends either it should be IKEV1 or IKEV2.

You should also verify encryption algorithms and hashing algorithms must match in both firewalls.

Issue-3: Peer Authentication Failed

Sample Logs:

2020-09-20 00:29:42 22[NET] <10> received packet: from 72.138.xx.xx[4500] to 10.0.0.4[4500] (464 bytes)

2020-09-20 00:29:42 22[ENC] <10> parsed IKE_AUTH request 1 [ IDi IDr AUTH SA TSi TSr N(MULT_AUTH) N(EAP_ONLY) N(MSG_ID_SYN_SUP) ]

2020-09-20 00:29:42 22[CFG] <10> looking for peer configs matching 10.0.0.4[10.0.0.1]…72.138.xx.xx[72.138.xx.xx]

2020-09-20 00:29:42 22[CFG] <10> no matching peer config found

2020-09-20 00:29:42 22[DMN] <10> [GARNER-LOGGING] (child_alert) ALERT: peer authentication failed

2020-09-20 00:29:42 22[ENC] <10> generating IKE_AUTH response 1 [ N(AUTH_FAILED) ]

2020-09-20 00:29:42 22[NET] <10> sending packet: from 10.0.0.4[4500] to 72.138.xx.xx[4500] (96 bytes)

2020-09-20 00:29:42 22[IKE] <10> IKE_SA (unnamed)[10] state change: CONNECTING => DESTROYING

2020-09-20 00:29:42 04[NET] sending packet: from 10.0.0.4[4500] to xx.xx[4500]

Resolution:

This error is due to mismatch of local and remote connection ID in both the firewalls. In case if there is a mismatch of the connection ID, this error will occur.

Issue-4: Invalid HASH_V1 payload length, decryption failed? & Parsed IKE_AUTH response1[ N(AUTH_FAILED) ]

Sample Logs:

Initiator:

2020-11-13 04:55:06 17[NET] <To_Azure_XG-1|134> received packet: from 20.36.xxx.xxx[500] to 192.168.1.16[500] (124 bytes)

2020-11-13 04:55:06 17[ENC] <To_Azure_XG-1|134> invalid HASH_V1 payload length, decryption failed?

2020-11-13 04:55:06 17[ENC] <To_Azure_XG-1|134> could not decrypt payloads

2020-11-13 04:55:06 17[IKE] <To_Azure_XG-1|134> message parsing failed

2020-11-13 04:55:06 17[IKE] <To_Azure_XG-1|134> ignore malformed INFORMATIONAL request

2020-11-13 04:55:06 17[IKE] <To_Azure_XG-1|134> INFORMATIONAL_V1 request with message ID 2070455846 processing failed

2020-11-13 04:55:06 17[DMN] <To_Azure_XG-1|134> [GARNER-LOGGING] (child_alert) ALERT: parsing IKE message from 20.36.xxx.xxx[500] failed

2020-11-13 04:55:10 19[IKE] <To_Azure_XG-1|134> sending retransmit 1 of request message ID 0, seq 3

Respond only:

2020-11-13 13:56:39 12[NET] <5> received packet: from 72.138.xxx.xxx[4500] to 10.0.0.4[4500] (124 bytes)

2020-11-13 13:56:39 12[ENC] <5> invalid ID_V1 payload length, decryption failed?

2020-11-13 13:56:39 12[ENC] <5> could not decrypt payloads

2020-11-13 13:56:39 12[IKE] <5> message parsing failed

2020-11-13 13:56:39 12[ENC] <5> generating INFORMATIONAL_V1 request 2070455846 [ HASH N(PLD_MAL) ]

2020-11-13 13:56:39 12[NET] <5> sending packet: from 10.0.0.4[500] to 72.138.xxx.xxx[500] (124 bytes)

2020-11-13 13:56:39 12[IKE] <5> ID_PROT request with message ID 0 processing failed

2020-11-13 13:56:39 04[NET] sending packet: from 10.0.0.4[500] to 72.138.xxx.xxx[500]

2020-11-13 13:56:39 12[DMN] <5> [GARNER-LOGGING] (child_alert) ALERT: parsing IKE message from 72.138.xxx.xxx[4500] failed

Logs using IKEv2 for the key exchange.

Initiator:

2020-11-03 04:17:03 03[NET] <To_Azure_XG-1|123> received packet: from 40.75.xxx.xxx[4500] to 192.168.1.16[4500] (96 bytes)

2020-11-03 04:17:03 03[ENC] <To_Azure_XG-1|123> parsed IKE_AUTH response 1 [ N(AUTH_FAILED) ]

2020-11-03 04:17:03 03[IKE] <To_Azure_XG-1|123> received AUTHENTICATION_FAILED notify error

2020-11-03 04:17:03 03[DMN] <To_Azure_XG-1|123> [GARNER-LOGGING] (child_alert) ALERT: creating local authentication data failed

2020-11-03 04:17:03 03[IKE] <To_Azure_XG-1|123> IKE_SA AUTHENTICATION_FAILED set_condition COND_START_OVER 

2020-11-03 04:17:03 03[IKE] <To_Azure_XG-1|123> IKE_SA has_condition COND_START_OVER retry initiate in 60 sec

2020-11-03 04:17:03 03[CHD] <To_Azure_XG-1|123> CHILD_SA To_Azure_XG-1{191} state change: CREATED => DESTROYING

2020-11-03 04:17:03 03[IKE] <To_Azure_XG-1|123> IKE_SA To_Azure_XG-1[123] state change: CONNECTING => DESTROYING

Responder:

2020-11-03 13:18:07 21[NET] <136> received packet: from 72.138.xxx.xxx[4500] to 10.0.0.4[4500] (464 bytes)

2020-11-03 13:18:07 21[ENC] <136> parsed IKE_AUTH request 1 [ IDi IDr AUTH SA TSi TSr N(MULT_AUTH) N(EAP_ONLY) N(MSG_ID_SYN_SUP) ]

2020-11-03 13:18:07 21[CFG] <136> looking for peer configs matching 10.0.0.4[10.0.0.4]…72.138.xxx.xxx[72.138.xxx.xxx]

2020-11-03 13:18:07 21[CFG] <136>   candidate “Azure_to_XG-1”, match: 20/20/1052 (me/other/ike)

2020-11-03 13:18:07 21[CFG] <Azure_to_XG-1|136> selected peer config ‘Azure_to_XG-1’

2020-11-03 13:18:07 21[IKE] <Azure_to_XG-1|136> tried 2 shared keys for ‘10.0.0.4’ – ‘72.138.xxx.xxx’, but MAC mismatched

2020-11-03 13:18:07 21[DMN] <Azure_to_XG-1|136> [GARNER-LOGGING] (child_alert) ALERT: peer authentication failed

2020-11-03 13:18:07 21[ENC] <Azure_to_XG-1|136> generating IKE_AUTH response 1 [ N(AUTH_FAILED) ]

2020-11-03 13:18:07 21[NET] <Azure_to_XG-1|136> sending packet: from 10.0.0.4[4500] to 72.138.xxx.xxx[4500] (96 bytes)

2020-11-03 13:18:07 21[IKE] <Azure_to_XG-1|136> IKE_SA Azure_to_XG-1[136] state change: CONNECTING => DESTROYING

Resolution:

In case if there is a mismatch of preshared key in both the firewalls, this issue will happen. Make sure to enter same preshared key on both firewalls.

This article explained how to resolve issues when IPSEC tunnel is not establishing. In case if the tunnel is established but not traffic is passing through IPSEC tunnel, please follow this article:

Traffic not passing

Hope this article helps you.