Hello everyone,
We have a Sophos UTM 9 (9.307-6 as of this morning) at our headquarters and a branch office with a UTM 9 (9.306-6 - I haven't gotten around to installing the most recent update, yet), connected by an IPsec site to site tunnel.
Recently, this VPN connection has experienced intermittent connection failures, which gets the users in that branch office rather upset (not that I can blame them).
We have not made any changes to the VPN settings, but we have recently opened one new branch office and replaced the aging Draytek Vigor router in the other one, now both of these branch offices have Fritz!Boxes (a 7272 and a 7390, in case it matters).
I set up the IPsec tunnels to both of these branch offices myself, something I have never done before. Initially, both of these offices experienced intermittent connection failures (at the VPN level, the DSL lines were fine!). Today, I recreated the configuration files for the VPN tunnels for these offices from scratch and uploaded them to the Fritz!Boxes. Neither office has experienced any trouble today, which leads me to believe that I got it right this time.
But the first branch office, the one with the UTM 9, has experienced yet another failure of their VPN tunnel today. When Nagios notified me of the problem, I checked if could reach the UTM on its public IP address (this office does not have a static IP, AND their UTM sits behind an EasyBox provided by Vodafon, which has already been replaced once), pinged it, logged into the Web Interface, but when I had logged in, the connection was already working again.
I checked the IPsec log on the remote UTM, and found the following lines around the time of the connection failure:
2015:02:04-13:03:57 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #494: responding to Main Mode
2015:02:04-13:03:57 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #494: NAT-Traversal: Result using RFC 3947: i am NATed
2015:02:04-13:03:57 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #494: next payload type of ISAKMP Identification Payload has an unknown value: 91
2015:02:04-13:03:57 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #494: malformed payload in packet. Probable authentication failure (mismatch of preshared secrets?)
2015:02:04-13:03:57 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #494: sending encrypted notification PAYLOAD_MALFORMED to 62.153.71.106:4500
2015:02:04-13:04:07 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #494: next payload type of ISAKMP Identification Payload has an unknown value: 91
2015:02:04-13:04:07 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #494: malformed payload in packet. Probable authentication failure (mismatch of preshared secrets?)
2015:02:04-13:04:07 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #494: sending encrypted notification PAYLOAD_MALFORMED to 62.153.71.106:4500
2015:02:04-13:04:27 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #494: next payload type of ISAKMP Identification Payload has an unknown value: 91
2015:02:04-13:04:27 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #494: malformed payload in packet. Probable authentication failure (mismatch of preshared secrets?)
2015:02:04-13:04:27 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #494: sending encrypted notification PAYLOAD_MALFORMED to 62.153.71.106:4500
Oh yes, I forgot to mention: The connection is secured by preshared keys (PSK). Which I am told is kind of a bad idea, but it has been like that when I started working here, and I am kind of hesitant to change this now, unless someone can plausibly explain to me that it will make these connection issues go away.
Also, when I looked at the log a little longer, the above messages show up all the time.
The one thing that stood out the time of the connection failure is this:
2015:02:04-13:06:13 wellmann pluto[1625]: listening for IKE messages
2015:02:04-13:06:13 wellmann pluto[1625]: forgetting secrets
2015:02:04-13:06:13 wellmann pluto[1625]: loading secrets from "/etc/ipsec.secrets"
2015:02:04-13:06:13 wellmann pluto[1625]: loaded private key from 'REF_CaHosIphone.pem'
2015:02:04-13:06:13 wellmann pluto[1625]: loaded PSK secret for 192.168.2.100 10.20.30.40
2015:02:04-13:06:13 wellmann pluto[1625]: forgetting secrets
2015:02:04-13:06:13 wellmann pluto[1625]: loading secrets from "/etc/ipsec.secrets"
2015:02:04-13:06:13 wellmann pluto[1625]: loaded private key from 'REF_CaHosIphone.pem'
2015:02:04-13:06:13 wellmann pluto[1625]: loaded PSK secret for 192.168.2.100 10.20.30.40
2015:02:04-13:06:13 wellmann pluto[1625]: loading ca certificates from '/etc/ipsec.d/cacerts'
2015:02:04-13:06:13 wellmann pluto[1625]: loaded ca certificate from '/etc/ipsec.d/cacerts/REF_CaVerVpnSigniCaThu.pem'
2015:02:04-13:06:13 wellmann pluto[1625]: loaded ca certificate from '/etc/ipsec.d/cacerts/REF_UaZXRTYgfQ.pem'
2015:02:04-13:06:13 wellmann pluto[1625]: loaded ca certificate from '/etc/ipsec.d/cacerts/REF_CaVerVpnSigniCaThu2.pem'
2015:02:04-13:06:13 wellmann pluto[1625]: loading aa certificates from '/etc/ipsec.d/aacerts'
2015:02:04-13:06:13 wellmann pluto[1625]: loading ocsp certificates from '/etc/ipsec.d/ocspcerts'
2015:02:04-13:06:13 wellmann pluto[1625]: loading attribute certificates from '/etc/ipsec.d/acerts'
2015:02:04-13:06:13 wellmann pluto[1625]: Changing to directory '/etc/ipsec.d/crls'
2015:02:04-13:06:13 wellmann ipsec_starter[5945]: no default route - cannot cope with %defaultroute!!!
2015:02:04-13:06:13 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0": deleting connection
2015:02:04-13:06:13 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #495: deleting state (STATE_MAIN_R2)
2015:02:04-13:06:13 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #487: deleting state (STATE_QUICK_I2)
2015:02:04-13:06:13 wellmann pluto[1625]: id="2204" severity="info" sys="SecureNet" sub="vpn" event="Site-to-site VPN down" variant="ipsec" connection="REF_YWvtzADrXH" address="192.168.2.10" local_net="192.168.1.0/24" remote_net="192.168.80.0/24"
2015:02:04-13:06:13 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #447: deleting state (STATE_QUICK_I2)
2015:02:04-13:06:13 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #433: deleting state (STATE_MAIN_I4)
2015:02:04-13:06:14 wellmann pluto[1625]: added connection description "S_REF_YWvtzADrXH_0"
2015:02:04-13:06:14 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #496: initiating Main Mode
2015:02:04-13:06:14 wellmann pluto[1625]: ERROR: "S_REF_YWvtzADrXH_0" #496: sendto on eth3 to 10.20.30.40:500 failed in main_outI1. Errno 1: Operation not permitted
2015:02:04-13:06:24 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #496: received Vendor ID payload [strongSwan]
2015:02:04-13:06:24 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #496: ignoring Vendor ID payload [Cisco-Unity]
2015:02:04-13:06:24 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #496: received Vendor ID payload [XAUTH]
2015:02:04-13:06:24 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #496: received Vendor ID payload [Dead Peer Detection]
2015:02:04-13:06:24 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #496: received Vendor ID payload [RFC 3947]
2015:02:04-13:06:24 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #496: enabling possible NAT-traversal with method 3
2015:02:04-13:06:24 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #496: NAT-Traversal: Result using RFC 3947: i am NATed
2015:02:04-13:06:24 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #496: Peer ID is ID_IPV4_ADDR: '10.20.30.40'
2015:02:04-13:06:24 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #496: Dead Peer Detection (RFC 3706) enabled
2015:02:04-13:06:24 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #496: ISAKMP SA established
2015:02:04-13:06:24 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #497: initiating Quick Mode PSK+ENCRYPT+TUNNEL+UP {using isakmp#496}
2015:02:04-13:06:24 wellmann pluto[1625]: id="2203" severity="info" sys="SecureNet" sub="vpn" event="Site-to-site VPN up" variant="ipsec" connection="REF_YWvtzADrXH" address="192.168.2.100" local_net="192.168.1.0/24" remote_net="192.168.80.0/24"
2015:02:04-13:06:24 wellmann pluto[1625]: "S_REF_YWvtzADrXH_0" #497: sent QI2, IPsec SA established {ESP=>0x0092a666 0x4cad06ec
This thread was automatically locked due to age.
