The Problem was first described here : Remote Access via IPSec, Client connected but not receiving packets
Currently running Version 9.713-19 of the Sophos UTM 9 SG550 Firewall.
Client IPSec version is the latest available : 2.2.75
NAT-Traversal Keep Alive has since been changed to 10 seconds.
Once the Client is connected via the VPN it can ping the Firewall successfully.
Network Protection rules must be fine since other users have no Problems whatsoever.
We also use L2TP over IPSec as VPN and that stopped working as of late aswell.
The VPN on Sophos is simply not reliable, some users can't connect on either of the VPN solutions and I have wasted so much time already looking for solutions.
Can you post any logs?
I noticed in the post you mentioned, things seem to go downhill after this entry:
2022-02-22 03:56:23PM 16[KNL] <REF_IpsRoaIpsecverwa3|10> installing route 0.0.0.0/0 src 192.168.6.10 gateway 169.254.128.128 dev {5BB8B74D-9DDB-425A-A371-61A0A63B7494}
2022-02-22 03:56:23PM 16[IKE] <REF_IpsRoaIpsecverwa3|10> CHILD_SA REF_IpsRoaIpsecverwa3-tunnel-1{10} established with SPIs 503a74a4_i 9a7447c4_o and TS 192.168.6.10/32 === 0.0.0.0/0
2022-02-22 03:56:23PM 16[CHD] <REF_IpsRoaIpsecverwa3|10> CHILD_SA REF_IpsRoaIpsecverwa3-tunnel-1{10} state change: INSTALLING => INSTALLED
2022-02-22 03:56:23PM 16[ENC] <REF_IpsRoaIpsecverwa3|10> generating QUICK_MODE request 3420046745 [ HASH ]
2022-02-22 03:56:23PM 16[NET] <REF_IpsRoaIpsecverwa3|10> sending packet: from 172.16.7.36[64539] to SOPHOSFIREWALL[4500] (60 bytes)
2022-02-22 03:56:30PM 08[ESP] unsupported IP version
2022-02-22 03:56:30PM 09[CFG] vici terminate IKE_SA 'REF_IpsRoaIpsecverwa3'
Are you seeing it here as well?
OPNSense 64-bit | Intel Xeon 4-core v3 1225 3.20Ghz
16GB Memory | 500GB SSD HDD | ATT Fiber 1GB
(Former Sophos UTM Veteran, Former XG Rookie)
2022:12:09-08:28:19 sgmrgt02-1 pluto[19105]: | handling event EVENT_RETRANSMIT for 37.201.6.102 "L_for admin" #6104
2022:12:09-08:28:42 sgmrgt02-1 pluto[19105]: | *received 28 bytes from 37.201.6.102:30444 on eth18
2022:12:09-08:28:42 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30444: length of ISAKMP Message is smaller than minimum
2022:12:09-08:28:42 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30444: sending notification PAYLOAD_MALFORMED to 37.201.6.102:30444
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: | *received 180 bytes from 37.201.6.102:30430 on eth18
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30430: received Vendor ID payload [XAUTH]
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30430: received Vendor ID payload [Dead Peer Detection]
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30430: ignoring Vendor ID payload [FRAGMENTATION 80000000]
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30430: received Vendor ID payload [RFC 3947]
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30430: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: | instantiated "D_for Alle_Studierende to Any-0" for 37.201.6.102
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: "D_for Alle_Studierende to Any-0"[71] 37.201.6.102:30430 #6105: responding to Main Mode from unknown peer 37.201.6.102:30430
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: | *received 300 bytes from 37.201.6.102:30430 on eth18
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: "D_for Alle_Studierende to Any-0"[71] 37.201.6.102:30430 #6105: NAT-Traversal: Result using RFC 3947: peer is NATed
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: | *received 524 bytes from 37.201.6.102:30535 on eth18
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: | NAT-T: new mapping 37.201.6.102:30430/30535)
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: "D_for Alle_Studierende to Any-0"[71] 37.201.6.102:30535 #6105: Peer ID is ID_USER_FQDN: 'EMAIL_OF_THE_USER'
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: | instantiated "D_IPSec_Verwaltung-0" for 37.201.6.102
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: deleting connection "D_for Alle_Studierende to Any-0"[71] instance with peer 37.201.6.102 {isakmp=#0/ipsec=#0}
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: we have a cert and are sending it
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: Dead Peer Detection (RFC 3706) enabled
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: sent MR3, ISAKMP SA established
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: sending XAUTH request
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: | *received 92 bytes from 37.201.6.102:30535 on eth18
2022:12:09-08:28:44 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: parsing XAUTH reply
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: extended authentication was successful
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: sending XAUTH status
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: | *received 76 bytes from 37.201.6.102:30535 on eth18
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: parsing XAUTH ack
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: received XAUTH ack, established
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: | *received 76 bytes from 37.201.6.102:30535 on eth18
2022:12:09-08:28:46 sgmrgt02-2 pluto[18480]: | instantiated "D_IPSec_Verwaltung-0" for 37.201.6.102
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: parsing ModeCfg request
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: peer requested virtual IP %any
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: assigning virtual IP 192.168.6.3 to peer
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: sending ModeCfg reply
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6105: sent ModeCfg reply, established
2022:12:09-08:28:46 sgmrgt02-2 pluto[18480]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535: deleting connection "D_IPSec_Verwaltung-0"[12] instance with peer 37.201.6.102 {isakmp=#0/ipsec=#0}
2022:12:09-08:28:46 sgmrgt02-2 pluto[18480]: | instantiated "D_IPSec_Verwaltung-0" for 37.201.6.102
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: | *received 380 bytes from 37.201.6.102:30535 on eth18
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6106: responding to Quick Mode
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: | *received 60 bytes from 37.201.6.102:30535 on eth18
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: | route owner of "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 unrouted: NULL; eroute owner: NULL
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: | route owner of "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 unrouted: NULL; eroute owner: NULL
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: | eroute_connection add eroute 0.0.0.0/0:0 -> 192.168.6.3/32:0 => tun.0@37.201.6.102:0
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: | executing up-client: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='up-client' PLUTO_CONNECTION='D_IPSec_Verwaltung-0' PLUTO_NEXT_HOP='37.201.6.102' PLUTO_INTERFACE='eth18' PLUTO_REQID='38385' PLUTO_ME='IP_OF_FIREWALL' PLUTO_MY_ID='DNS_OF_FIREWALL' PLUTO_MY_CLIENT='0.0.0.0/0' PLUTO_MY_CLIENT_NET='0.0.0.0' PLUTO_MY_CLIENT_MASK='0.0.0.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='37.201.6.102' PLUTO_PEER_ID='EMAIL_OF_THE_USER' PLUTO_PEER_CLIENT='192.168.6.3/32' PLUTO_PEER_CLIENT_NET='192.168.6.3' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='C=de, L=CITY_NAME, O=ORGANISATION_NAME, CN=ORGANISATION_NAME VPN CA, E=ORGANISATION_EMAIL' PLUTO_XAUTH_ID='USER_ID' /usr/libexec/ipsec/updown classic
2022:12:09-08:28:46 sgmrgt02-1 pluto[19105]: id="2201" severity="info" sys="SecureNet" sub="vpn" event="Connection started" username="USER_ID" variant="ipsec" srcip="37.201.6.102" virtual_ip="192.168.6.3"
2022:12:09-08:28:47 sgmrgt02-1 pluto[19105]: | executing prepare-client: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='prepare-client' PLUTO_CONNECTION='D_IPSec_Verwaltung-0' PLUTO_NEXT_HOP='37.201.6.102' PLUTO_INTERFACE='eth18' PLUTO_REQID='38385' PLUTO_ME='IP_OF_FIREWALL' PLUTO_MY_ID='DNS_OF_FIREWALL' PLUTO_MY_CLIENT='0.0.0.0/0' PLUTO_MY_CLIENT_NET='0.0.0.0' PLUTO_MY_CLIENT_MASK='0.0.0.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='37.201.6.102' PLUTO_PEER_ID='EMAIL_OF_THE_USER' PLUTO_PEER_CLIENT='192.168.6.3/32' PLUTO_PEER_CLIENT_NET='192.168.6.3' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='C=de, L=CITY_NAME, O=ORGANISATION_NAME, CN=ORGANISATION_NAME VPN CA, E=ORGANISATION_EMAIL' PLUTO_XAUTH_ID='USER_ID' /usr/libexec/ipsec/updown classic
2022:12:09-08:28:47 sgmrgt02-1 pluto[19105]: | executing route-client: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='route-client' PLUTO_CONNECTION='D_IPSec_Verwaltung-0' PLUTO_NEXT_HOP='37.201.6.102' PLUTO_INTERFACE='eth18' PLUTO_REQID='38385' PLUTO_ME='IP_OF_FIREWALL' PLUTO_MY_ID='DNS_OF_FIREWALL' PLUTO_MY_CLIENT='0.0.0.0/0' PLUTO_MY_CLIENT_NET='0.0.0.0' PLUTO_MY_CLIENT_MASK='0.0.0.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='37.201.6.102' PLUTO_PEER_ID='EMAIL_OF_THE_USER' PLUTO_PEER_CLIENT='192.168.6.3/32' PLUTO_PEER_CLIENT_NET='192.168.6.3' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='C=de, L=CITY_NAME, O=ORGANISATION_NAME, CN=ORGANISATION_NAME VPN CA, E=ORGANISATION_EMAIL' PLUTO_XAUTH_ID='USER_ID' /usr/libexec/ipsec/updown classic
2022:12:09-08:28:47 sgmrgt02-1 pluto[19105]: | route_and_eroute: instance "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535, setting eroute_owner {spd=0x9455578,sr=0x9455578} to #6106 (was #0) (newest_ipsec_sa=#0)
2022:12:09-08:28:47 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 #6106: IPsec SA established {ESP=>0xc614385b <0xf5b524a6 NATOA=0.0.0.0 DPD}
2022:12:09-08:28:47 sgmrgt02-2 pluto[18480]: | route owner of "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 unrouted: NULL; eroute owner: NULL
2022:12:09-08:28:47 sgmrgt02-2 pluto[18480]: | HA System: setting sequence number of added SA esp.c614385b@37.201.6.102 to 4096
2022:12:09-08:28:47 sgmrgt02-2 pluto[18480]: | route owner of "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535 unrouted: NULL; eroute owner: NULL
2022:12:09-08:28:47 sgmrgt02-2 pluto[18480]: | eroute_connection add eroute 0.0.0.0/0:0 -> 192.168.6.3/32:0 => tun.0@37.201.6.102:0
2022:12:09-08:28:47 sgmrgt02-2 pluto[18480]: | executing up-client: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='up-client' PLUTO_CONNECTION='D_IPSec_Verwaltung-0' PLUTO_NEXT_HOP='37.201.6.102' PLUTO_INTERFACE='eth18' PLUTO_REQID='45189' PLUTO_ME='IP_OF_FIREWALL' PLUTO_MY_ID='DNS_OF_FIREWALL' PLUTO_MY_CLIENT='0.0.0.0/0' PLUTO_MY_CLIENT_NET='0.0.0.0' PLUTO_MY_CLIENT_MASK='0.0.0.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='37.201.6.102' PLUTO_PEER_ID='EMAIL_OF_THE_USER' PLUTO_PEER_CLIENT='192.168.6.3/32' PLUTO_PEER_CLIENT_NET='192.168.6.3' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='C=de, L=CITY_NAME, O=ORGANISATION_NAME, CN=ORGANISATION_NAME VPN CA, E=ORGANISATION_EMAIL' PLUTO_XAUTH_ID='USER_ID' /usr/libexec/ipsec/updown classic
2022:12:09-08:28:47 sgmrgt02-2 pluto[18480]: id="2201" severity="info" sys="SecureNet" sub="vpn" event="Connection started" username="USER_ID" variant="ipsec" srcip="37.201.6.102" virtual_ip="192.168.6.3"
2022:12:09-08:28:48 sgmrgt02-2 pluto[18480]: | executing prepare-client: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='prepare-client' PLUTO_CONNECTION='D_IPSec_Verwaltung-0' PLUTO_NEXT_HOP='37.201.6.102' PLUTO_INTERFACE='eth18' PLUTO_REQID='45189' PLUTO_ME='IP_OF_FIREWALL' PLUTO_MY_ID='DNS_OF_FIREWALL' PLUTO_MY_CLIENT='0.0.0.0/0' PLUTO_MY_CLIENT_NET='0.0.0.0' PLUTO_MY_CLIENT_MASK='0.0.0.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='37.201.6.102' PLUTO_PEER_ID='EMAIL_OF_THE_USER' PLUTO_PEER_CLIENT='192.168.6.3/32' PLUTO_PEER_CLIENT_NET='192.168.6.3' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='C=de, L=CITY_NAME, O=ORGANISATION_NAME, CN=ORGANISATION_NAME VPN CA, E=ORGANISATION_EMAIL' PLUTO_XAUTH_ID='USER_ID' /usr/libexec/ipsec/updown classic
2022:12:09-08:28:48 sgmrgt02-2 pluto[18480]: | executing route-client: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='route-client' PLUTO_CONNECTION='D_IPSec_Verwaltung-0' PLUTO_NEXT_HOP='37.201.6.102' PLUTO_INTERFACE='eth18' PLUTO_REQID='45189' PLUTO_ME='IP_OF_FIREWALL' PLUTO_MY_ID='DNS_OF_FIREWALL' PLUTO_MY_CLIENT='0.0.0.0/0' PLUTO_MY_CLIENT_NET='0.0.0.0' PLUTO_MY_CLIENT_MASK='0.0.0.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='37.201.6.102' PLUTO_PEER_ID='EMAIL_OF_THE_USER' PLUTO_PEER_CLIENT='192.168.6.3/32' PLUTO_PEER_CLIENT_NET='192.168.6.3' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='C=de, L=CITY_NAME, O=ORGANISATION_NAME, CN=ORGANISATION_NAME VPN CA, E=ORGANISATION_EMAIL' PLUTO_XAUTH_ID='USER_ID' /usr/libexec/ipsec/updown classic
2022:12:09-08:28:48 sgmrgt02-2 pluto[18480]: | route_and_eroute: instance "D_IPSec_Verwaltung-0"[12] 37.201.6.102:30535, setting eroute_owner {spd=0x8917dc0,sr=0x8917dc0} to #6106 (was #0) (newest_ipsec_sa=#6106)
2022:12:09-08:28:59 sgmrgt02-1 pluto[19105]: | handling event EVENT_RETRANSMIT for 37.201.6.102 "L_for admin" #6104
2022:12:09-08:28:59 sgmrgt02-1 pluto[19105]: "L_for admin"[227] 37.201.6.102:30546 #6104: max number of retransmissions (2) reached STATE_MAIN_R2
2022:12:09-08:28:59 sgmrgt02-1 pluto[19105]: "L_for admin"[227] 37.201.6.102:30546: deleting connection "L_for admin"[227] instance with peer 37.201.6.102 {isakmp=#0/ipsec=#0}
2022:12:09-09:59:00 sgmrgt02-1 pluto[19105]: | next event EVENT_DPD_UPDATE in 0 seconds for #6188
2022:12:09-09:59:00 sgmrgt02-1 pluto[19105]: |
2022:12:09-09:59:00 sgmrgt02-1 pluto[19105]: | *time to handle event
2022:12:09-09:59:00 sgmrgt02-1 pluto[19105]: | event after this is EVENT_DPD_UPDATE in 2 seconds
2022:12:09-09:59:00 sgmrgt02-1 pluto[19105]: | get esp.1ca17a25@IP_OF_FIREWALL
2022:12:09-09:59:00 sgmrgt02-1 pluto[19105]: | current: 40709 bytes
2022:12:09-09:59:00 sgmrgt02-1 pluto[19105]: | get inbound policy with reqid 38641
2022:12:09-09:59:00 sgmrgt02-1 pluto[19105]: | use_time: Dec 09 09:58:55 2022
2022:12:09-09:59:00 sgmrgt02-1 pluto[19105]: | inserting event EVENT_DPD_UPDATE, timeout in 30 seconds for #6188
2022:12:09-09:59:00 sgmrgt02-1 pluto[19105]: | next event EVENT_DPD_UPDATE in 2 seconds for #6168
2022:12:09-09:59:00 sgmrgt02-2 pluto[18480]: | HA System: received SYNC_UPD_SEQ message (44 bytes) from 198.19.250.1
2022:12:09-09:59:00 sgmrgt02-2 pluto[18480]: | next event EVENT_SA_EXPIRE in 90 seconds for #6134
2022:12:09-09:59:00 sgmrgt02-2 pluto[18480]: |
2022:12:09-09:59:00 sgmrgt02-2 pluto[18480]: | *received kernel message
2022:12:09-09:59:00 sgmrgt02-2 pluto[18480]: | netlink_get: XFRM_MSG_NEWAE message
2022:12:09-09:59:00 sgmrgt02-2 pluto[18480]: | next event EVENT_SA_EXPIRE in 90 seconds for #6134
2022:12:09-09:59:08 sgmrgt02-1 pluto[19105]: | *received 28 bytes from 37.201.6.102:30590 on eth18
2022:12:09-09:59:08 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30590: length of ISAKMP Message is smaller than minimum
2022:12:09-09:59:08 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30590: sending notification PAYLOAD_MALFORMED to 37.201.6.102:30590
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: | *received 180 bytes from 37.201.6.102:30515 on eth18
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30515: received Vendor ID payload [XAUTH]
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30515: received Vendor ID payload [Dead Peer Detection]
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30515: ignoring Vendor ID payload [FRAGMENTATION 80000000]
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30515: received Vendor ID payload [RFC 3947]
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30515: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: | instantiated "D_IPSec_Verwaltung-0" for 37.201.6.102
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[16] 37.201.6.102:30515 #6193: responding to Main Mode from unknown peer 37.201.6.102:30515
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: | *received 300 bytes from 37.201.6.102:30515 on eth18
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[16] 37.201.6.102:30515 #6193: NAT-Traversal: Result using RFC 3947: peer is NATed
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: | *received 524 bytes from 37.201.6.102:30512 on eth18
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: | NAT-T: new mapping 37.201.6.102:30515/30512)
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[16] 37.201.6.102:30512 #6193: Peer ID is ID_USER_FQDN: 'EMAIL_OF_THE_USER'
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: | instantiated "D_IPSec_Verwaltung-0" for 37.201.6.102
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: deleting connection "D_IPSec_Verwaltung-0"[16] instance with peer 37.201.6.102 {isakmp=#0/ipsec=#0}
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: we have a cert and are sending it
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: Dead Peer Detection (RFC 3706) enabled
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: sent MR3, ISAKMP SA established
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: sending XAUTH request
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: | *received 92 bytes from 37.201.6.102:30512 on eth18
2022:12:09-09:59:10 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: parsing XAUTH reply
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: extended authentication was successful
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: sending XAUTH status
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: | *received 76 bytes from 37.201.6.102:30512 on eth18
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: parsing XAUTH ack
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: received XAUTH ack, established
2022:12:09-09:59:12 sgmrgt02-2 pluto[18480]: | instantiated "D_IPSec_Verwaltung-0" for 37.201.6.102
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: | *received 76 bytes from 37.201.6.102:30512 on eth18
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: parsing ModeCfg request
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: peer requested virtual IP %any
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: assigning virtual IP 192.168.6.1 to peer
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: sending ModeCfg reply
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6193: sent ModeCfg reply, established
2022:12:09-09:59:12 sgmrgt02-2 pluto[18480]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512: deleting connection "D_IPSec_Verwaltung-0"[21] instance with peer 37.201.6.102 {isakmp=#0/ipsec=#0}
2022:12:09-09:59:12 sgmrgt02-2 pluto[18480]: | instantiated "D_IPSec_Verwaltung-0" for 37.201.6.102
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: | *received 380 bytes from 37.201.6.102:30512 on eth18
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6194: responding to Quick Mode
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: | *received 60 bytes from 37.201.6.102:30512 on eth18
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: | route owner of "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 unrouted: NULL; eroute owner: NULL
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: | route owner of "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 unrouted: NULL; eroute owner: NULL
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: | eroute_connection add eroute 0.0.0.0/0:0 -> 192.168.6.1/32:0 => tun.0@37.201.6.102:0
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6194: ERROR: netlink XFRM_MSG_NEWPOLICY response for flow tun.0@37.201.6.102 included errno 17: File exists
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: | delete esp.f9a63162@37.201.6.102
2022:12:09-09:59:12 sgmrgt02-1 pluto[19105]: | route owner of "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 unrouted: NULL; eroute owner: NULL
2022:12:09-09:59:22 sgmrgt02-1 pluto[19105]: | handling event EVENT_RETRANSMIT for 37.201.6.102 "D_IPSec_Verwaltung-0" #6194
2022:12:09-09:59:22 sgmrgt02-1 pluto[19105]: | *received 60 bytes from 37.201.6.102:30512 on eth18
2022:12:09-09:59:22 sgmrgt02-1 pluto[19105]: | route owner of "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 unrouted: NULL; eroute owner: NULL
2022:12:09-09:59:22 sgmrgt02-1 pluto[19105]: "D_IPSec_Verwaltung-0"[21] 37.201.6.102:30512 #6194: ERROR: netlink response for Add SA esp.e20f12b6@IP_OF_FIREWALL included errno 3: No such process
2022:12:09-09:59:27 sgmrgt02-1 pluto[19105]: | *received 92 bytes from 37.201.6.102:30512 on eth18
2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30546: ignoring Vendor ID payload [01528bbbc00696121849ab9a1c5b2a5100000001] 2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30546: received Vendor ID payload [MS NT5 ISAKMPOAKLEY 00000009] 2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30546: received Vendor ID payload [RFC 3947] 2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30546: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] 2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30546: ignoring Vendor ID payload [FRAGMENTATION] 2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30546: ignoring Vendor ID payload [MS-Negotiation Discovery Capable] 2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30546: ignoring Vendor ID payload [Vid-Initial-Contact] 2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: packet from 37.201.6.102:30546: ignoring Vendor ID payload [IKE CGA version 1] 2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: "L_for admin"[227] 37.201.6.102:30546 #6104: responding to Main Mode from unknown peer 37.201.6.102:30546 2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: "L_for admin"[227] 37.201.6.102:30546 #6104: ECP_384 is not supported. Attribute OAKLEY_GROUP_DESCRIPTION 2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: "L_for admin"[227] 37.201.6.102:30546 #6104: ECP_256 is not supported. Attribute OAKLEY_GROUP_DESCRIPTION 2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: | *received 388 bytes from 37.201.6.102:30546 on eth18 2022:12:09-08:27:49 sgmrgt02-1 pluto[19105]: "L_for admin"[227] 37.201.6.102:30546 #6104: NAT-Traversal: Result using RFC 3947: peer is NATed 2022:12:09-08:27:59 sgmrgt02-1 pluto[19105]: | handling event EVENT_RETRANSMIT for 37.201.6.102 "L_for admin" #6104 2022:12:09-08:28:11 sgmrgt02-1 pluto[19105]: | handling event EVENT_RETRANSMIT for 37.201.6.102 "L_for admin" #6103 2022:12:09-08:28:11 sgmrgt02-1 pluto[19105]: "L_for admin"[227] 37.201.6.102:30546 #6103: max number of retransmissions (2) reached STATE_MAIN_R2 2022:12:09-08:28:19 sgmrgt02-1 pluto[19105]: | handling event EVENT_RETRANSMIT for 37.201.6.102 "L_for admin" #6104
Here are some logs.
Here is a little bit of context: Client calls, says VPN not working. I connect and try L2TP, it fails ( see Log ). Then I try IPSec, it fails. I then try a couple of things with turning the wifi on and off and try L2TP and IPSec. At one point for some reason IPSec starts to work ( see ipsec success_edited ). Later on in the day the client calls again and says that VPN is not working again. I connect and spend hours trying everything I find online and nothing helps ( see ipsec no success_edited ).
Now I have Tickets from all the clients that use L2TP and all of them say it is not working.
So I simply give them permission to use IPSec but that also sometimes does not work for certain users. ( see Screenshot from previous post, the IPSec client sends packets but does not receive them )
All of our clients use Windows 10 LTSC Version 21H2. This particular client for example had all the latest windows updates and the latest ipsec client.
I'm still looking at all of this, but I noticed in your IPSec fail connection log:
ERROR: netlink XFRM_MSG_NEWPOLICY response for flow
Looking around for that, there were two factors involved: HA is being used in the environment, and the IP ranges for the VPN pool were causing an issue.
Have you tried to change the IP pool numbers, or looked at those as a potential issue? It acts like there's a conflict.
I'm also a bit of a visual learner - are you able to screenshot your IPSec and L2TP VPN setups in UTM? Feel free to obfuscate any sensitive data.
OPNSense 64-bit | Intel Xeon 4-core v3 1225 3.20Ghz
16GB Memory | 500GB SSD HDD | ATT Fiber 1GB
(Former Sophos UTM Veteran, Former XG Rookie)
HA (High availability) is indeed being used. One unit as passive and the other as active. It is working correctly.
In regards to IP Pools. What I have noticed is that clients who have the issue with 0 bytes received on the IPSec Client have usually received the very first IP Address from the virtual Pool. (x.x.x.1)
Clients that do not have the issue usually never receive the first IP. I just checked the logs I sent and you can see that in the unsuccessful log the user gets 192.168.6.1 and in the successful log it gets 192.168.6.3.
I always assumed Sophos has some sort of mechanism that if there is a problem the user just gets some sort of default IP from the Pool just so that it has one.
We have different profiles for IPSec and each profile has a /23 private network pool. x.4.0 / 23, x.6.0 / 23 and so on. There should be more then enough IP Addresses in the Pool so the Problem can't be due to not enough Addresses. There is one exception of a IPSec Profile which has a larger Pool 172.30.0.0 / 16. Clients using that profile have had the same Problem.
These virtual Pools have a NAT Address assigned to them on two interfaces of the Firewall.
There is no DHCP Server within that private Pool, seems like the Firewall takes care of it automatically.
In regards to IP Pools. What I have noticed is that clients who have the issue with 0 bytes received on the IPSec Client have usually received the very first IP Address from the virtual Pool. (x.x.x.1)
That was the other issue with the IP addresses that I had found. Part of this would require you to change your pool a little bit so they aren't receiving that as part of the range of IPs to pick from. It's not a problem with not having enough, it has to do with the range.
This is the post I read related to this: L2TP not passing traffic - VPN: Site to Site and Remote Access - UTM Firewall - Sophos Community
OPNSense 64-bit | Intel Xeon 4-core v3 1225 3.20Ghz
16GB Memory | 500GB SSD HDD | ATT Fiber 1GB
(Former Sophos UTM Veteran, Former XG Rookie)
I changed the IP Pool of the above mentioned IPSec Profile from /23 to a /25 in order to not include the x.x.x.1.
My test device was still having the problem, after waiting for 10 minutes and trying again it started working. I have noticed that the Firewall takes a while to apply changes to anything VPN related.
One of the clients that had the problem reported today that it worked for them yesterday too. I am awaiting the results of other clients to confirm that the Problem is indeed solved.
Why is the Firewall not able to handle the first IP Address ? Its really ridiculous. And I have not found this information anywhere. Could it maybe be more about the Size of the Subnet rather than the "location" ? Like maybe the first /25 where the x.x.x.1 is included will also work just as long as its a /25 and not higher ?
Is there a way to exclude the first one ? Since its not a DHCP Pool but a static Pool I don't see any way of excluding any IP Addresses.
I also did the same for the L2TP VPN Pool, that did not help it. The L2TP still refuses to connect.
You could assign that single IP to a 'dummy' so that it isn't assigned. Create a bogus object then give it that IP.
As far as it not handling that IP, I don't know why, it could be an engineer/reseller question. Hope this helps at least solve your problem, please let us know if your users are reporting results one way or another.
OPNSense 64-bit | Intel Xeon 4-core v3 1225 3.20Ghz
16GB Memory | 500GB SSD HDD | ATT Fiber 1GB
(Former Sophos UTM Veteran, Former XG Rookie)
Ye that makes sense. Right now it is not necessary, but will keep it in mind if the pool will require an expansion.
So far the IPSec connection seems to be working, no client is reporting any Problems. Seems like this may have solved it.
The L2TP connection is still failing, although curiously enough it works on my test station. But since I need to rework the whole L2TP Profile anyway its fine.
The L2TP was mostly setup because the IPSec was so unreliable.
Will write something if IPSec starts to have the same Problem.
Thanks for the help.
Quote