IPSEC Mobile VPN (BUG?) stops passing traffic if no activity

[kapara]

I noticed that the VPN stops passing traffic if there is no activity for 5 minutes or so.  If I keep a constant ping it stays connected but if not I must disconnect and re-connect the VPN.  Any advice on what can be done or any info I should provide that might shed light as to why?

I am using Windows 10 Native client

Logs from connection (Can PING)

Code: [Select]

Sep 4 06:07:25 charon: 10[NET] <con1|3> sending packet: from 51.81.XXX.XXX[4500] to 50.76.XXX.XXX[38909] (320 bytes)
Sep 4 06:07:25 charon: 10[ENC] <con1|3> generating IKE_AUTH response 5 [ AUTH CPRP(ADDR SUBNET U_DEFDOM U_SPLITDNS (25)) N(ESP_TFC_PAD_N) SA TSi TSr N(AUTH_LFT) N(MOBIKE_SUP) N(ADD_4_ADDR) ]
Sep 4 06:07:25 charon: 10[IKE] <con1|3> CHILD_SA con1{22} established with SPIs cdbd2a89_i 0930f7e0_o and TS 192.168.127.128/27 === 10.10.80.1/32
Sep 4 06:07:25 charon: 10[CFG] <con1|3> selected proposal: ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ
Sep 4 06:07:25 charon: 10[IKE] <con1|3> no virtual IP found for %any6 requested by 'user@domain.local'
Sep 4 06:07:25 charon: 10[IKE] <con1|3> peer requested virtual IP %any6
Sep 4 06:07:25 charon: 10[IKE] <con1|3> assigning virtual IP 10.10.80.1 to peer 'user@domain.local'
Sep 4 06:07:25 charon: 10[CFG] <con1|3> reassigning offline lease to 'user@domain.local'
Sep 4 06:07:25 charon: 10[IKE] <con1|3> peer requested virtual IP %any
Sep 4 06:07:25 charon: 10[IKE] <con1|3> maximum IKE_SA lifetime 28470s
Sep 4 06:07:25 charon: 10[IKE] <con1|3> scheduling reauthentication in 27930s
Sep 4 06:07:25 charon: 10[IKE] <con1|3> IKE_SA con1[3] established between 51.81.XXX.XXX[dc.domain.org]...50.76.XXX.XXX[10.20.30.10]
Sep 4 06:07:25 charon: 10[IKE] <con1|3> authentication of 'dc.domain.org' (myself) with EAP
Sep 4 06:07:25 charon: 10[IKE] <con1|3> authentication of '10.20.30.10' with EAP successful
Sep 4 06:07:25 charon: 10[ENC] <con1|3> parsed IKE_AUTH request 5 [ AUTH ]
Sep 4 06:07:25 charon: 10[NET] <con1|3> received packet: from 50.76.XXX.XXX[38909] to 51.81.XXX.XXX[4500] (112 bytes)
Sep 4 06:07:25 charon: 10[NET] <con1|3> sending packet: from 51.81.XXX.XXX[4500] to 50.76.XXX.XXX[38909] (80 bytes)
Sep 4 06:07:25 charon: 10[ENC] <con1|3> generating IKE_AUTH response 4 [ EAP/SUCC ]
Sep 4 06:07:25 charon: 10[IKE] <con1|3> EAP method EAP_MSCHAPV2 succeeded, MSK established
Sep 4 06:07:25 charon: 10[ENC] <con1|3> parsed IKE_AUTH request 4 [ EAP/RES/MSCHAPV2 ]
Sep 4 06:07:25 charon: 10[NET] <con1|3> received packet: from 50.76.XXX.XXX[38909] to 51.81.XXX.XXX[4500] (80 bytes)
Sep 4 06:07:25 charon: 10[NET] <con1|3> sending packet: from 51.81.XXX.XXX[4500] to 50.76.XXX.XXX[38909] (144 bytes)
Sep 4 06:07:25 charon: 10[ENC] <con1|3> generating IKE_AUTH response 3 [ EAP/REQ/MSCHAPV2 ]
Sep 4 06:07:25 charon: 10[ENC] <con1|3> parsed IKE_AUTH request 3 [ EAP/RES/MSCHAPV2 ]
Sep 4 06:07:25 charon: 10[NET] <con1|3> received packet: from 50.76.XXX.XXX[38909] to 51.81.XXX.XXX[4500] (160 bytes)
Sep 4 06:07:24 charon: 10[NET] <con1|3> sending packet: from 51.81.XXX.XXX[4500] to 50.76.XXX.XXX[38909] (112 bytes)
Sep 4 06:07:24 charon: 10[ENC] <con1|3> generating IKE_AUTH response 2 [ EAP/REQ/MSCHAPV2 ]
Sep 4 06:07:24 charon: 10[IKE] <con1|3> initiating EAP_MSCHAPV2 method (id 0xBD)
Sep 4 06:07:24 charon: 10[IKE] <con1|3> received EAP identity 'user@domain.local'
Sep 4 06:07:24 charon: 10[ENC] <con1|3> parsed IKE_AUTH request 2 [ EAP/RES/ID ]
Sep 4 06:07:24 charon: 10[NET] <con1|3> received packet: from 50.76.XXX.XXX[38909] to 51.81.XXX.XXX[4500] (96 bytes)
Sep 4 06:07:24 charon: 16[NET] <con1|3> sending packet: from 51.81.XXX.XXX[4500] to 50.76.XXX.XXX[38909] (1236 bytes)
Sep 4 06:07:24 charon: 16[ENC] <con1|3> generating IKE_AUTH response 1 [ EF(2/2) ]
Sep 4 06:07:24 charon: 16[ENC] <con1|3> generating IKE_AUTH response 1 [ EF(1/2) ]
Sep 4 06:07:24 charon: 16[ENC] <con1|3> splitting IKE message (1696 bytes) into 2 fragments
Sep 4 06:07:24 charon: 16[ENC] <con1|3> generating IKE_AUTH response 1 [ IDr CERT AUTH EAP/REQ/ID ]
Sep 4 06:07:24 charon: 16[IKE] <con1|3> sending end entity cert "C=US, ST=CA, L=San Rafael, O=IT Department, E=user@domain.local, CN=dc.domain.org, subjectAltName=DNS:dc.domain.org,IP:51.81.XXX.XXX"
Sep 4 06:07:24 charon: 16[IKE] <con1|3> authentication of 'dc.domain.org' (myself) with RSA signature successful
Sep 4 06:07:24 charon: 16[IKE] <con1|3> peer supports MOBIKE
Sep 4 06:07:24 charon: 16[IKE] <con1|3> initiating EAP_IDENTITY method (id 0x00)
Sep 4 06:07:24 charon: 16[CFG] <con1|3> selected peer config 'con1'
Sep 4 06:07:24 charon: 16[CFG] <3> looking for peer configs matching 51.81.XXX.XXX[%any]...50.76.XXX.XXX[10.20.30.10]
Sep 4 06:07:24 charon: 16[IKE] <3> received 56 cert requests for an unknown ca
Sep 4 06:07:24 charon: 16[IKE] <3> received cert request for "C=US, ST=CA, L=San Rafael, O=IT Department, E=user@domain.local, CN=internal-ca"
Sep 4 06:07:24 charon: 16[ENC] <3> parsed IKE_AUTH request 1 [ IDi CERTREQ N(MOBIKE_SUP) CPRQ(ADDR DNS NBNS SRV ADDR6 DNS6 SRV6) SA TSi TSr ]
Sep 4 06:07:24 charon: 16[ENC] <3> received fragment #3 of 3, reassembled fragmented IKE message (1440 bytes)
Sep 4 06:07:24 charon: 16[ENC] <3> parsed IKE_AUTH request 1 [ EF(3/3) ]
Sep 4 06:07:24 charon: 16[NET] <3> received packet: from 50.76.XXX.XXX[38909] to 51.81.XXX.XXX[4500] (452 bytes)
Sep 4 06:07:24 charon: 16[ENC] <3> received fragment #2 of 3, waiting for complete IKE message
Sep 4 06:07:24 charon: 16[ENC] <3> parsed IKE_AUTH request 1 [ EF(2/3) ]

Log from when traffic stops:

Code: [Select]

Sep 4 06:12:40 charon: 09[NET] <con1|3> sending packet: from 51.81.XXX.XXX[4500] to 50.76.XXX.XXX[38909] (80 bytes)
Sep 4 06:12:40 charon: 09[ENC] <con1|3> generating INFORMATIONAL response 6 [ D ]
Sep 4 06:12:40 charon: 09[IKE] <con1|3> CHILD_SA closed
Sep 4 06:12:40 charon: 09[IKE] <con1|3> sending DELETE for ESP CHILD_SA with SPI cdbd2a89
Sep 4 06:12:40 charon: 09[IKE] <con1|3> closing CHILD_SA con1{22} with SPIs cdbd2a89_i (240 bytes) 0930f7e0_o (496 bytes) and TS 192.168.127.128/27 === 10.10.80.1/32
Sep 4 06:12:40 charon: 09[IKE] <con1|3> received DELETE for ESP CHILD_SA with SPI 0930f7e0
Sep 4 06:12:40 charon: 09[ENC] <con1|3> parsed INFORMATIONAL request 6 [ D ]
Sep 4 06:12:40 charon: 09[NET] <con1|3> received packet: from 50.76.XXX.XXX[38909] to 51.81.XXX.XXX[4500] (80 bytes)
And this is the following logs which oddly says that "no acceptable proposal found"?

Code: [Select]

Sep 4 06:14:03 charon: 10[NET] <con1|3> sending packet: from 51.81.XXX.XXX[4500] to 50.76.XXX.XXX[38909] (80 bytes)
Sep 4 06:14:03 charon: 10[ENC] <con1|3> generating CREATE_CHILD_SA response 10 [ N(NO_PROP) ]
Sep 4 06:14:03 charon: 10[IKE] <con1|3> failed to establish CHILD_SA, keeping IKE_SA
Sep 4 06:14:03 charon: 10[IKE] <con1|3> no acceptable proposal found
Sep 4 06:14:03 charon: 10[CFG] <con1|3> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ
Sep 4 06:14:03 charon: 10[CFG] <con1|3> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
Sep 4 06:14:03 charon: 10[ENC] <con1|3> parsed CREATE_CHILD_SA request 10 [ SA No TSi TSr KE ]
Sep 4 06:14:03 charon: 10[NET] <con1|3> received packet: from 50.76.XXX.XXX[38909] to 51.81.XXX.XXX[4500] (384 bytes)
Sep 4 06:13:58 charon: 10[NET] <con1|3> sending packet: from 51.81.XXX.XXX[4500] to 50.76.XXX.XXX[38909] (80 bytes)
Sep 4 06:13:58 charon: 10[ENC] <con1|3> generating CREATE_CHILD_SA response 9 [ N(NO_PROP) ]
Sep 4 06:13:58 charon: 10[IKE] <con1|3> failed to establish CHILD_SA, keeping IKE_SA
Sep 4 06:13:58 charon: 10[IKE] <con1|3> no acceptable proposal found
Sep 4 06:13:58 charon: 10[CFG] <con1|3> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ
Sep 4 06:13:58 charon: 10[CFG] <con1|3> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
Sep 4 06:13:58 charon: 10[ENC] <con1|3> parsed CREATE_CHILD_SA request 9 [ SA No TSi TSr KE ]
Sep 4 06:13:58 charon: 10[NET] <con1|3> received packet: from 50.76.XXX.XXX[38909] to 51.81.XXX.XXX[4500] (384 bytes)
Sep 4 06:13:53 charon: 10[NET] <con1|3> sending packet: from 51.81.XXX.XXX[4500] to 50.76.XXX.XXX[38909] (80 bytes)
Sep 4 06:13:53 charon: 10[ENC] <con1|3> generating CREATE_CHILD_SA response 8 [ N(NO_PROP) ]
Sep 4 06:13:53 charon: 10[IKE] <con1|3> failed to establish CHILD_SA, keeping IKE_SA
Sep 4 06:13:53 charon: 10[IKE] <con1|3> no acceptable proposal found
Sep 4 06:13:53 charon: 10[CFG] <con1|3> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ
Sep 4 06:13:53 charon: 10[CFG] <con1|3> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
Sep 4 06:13:53 charon: 10[ENC] <con1|3> parsed CREATE_CHILD_SA request 8 [ SA No TSi TSr KE ]
Sep 4 06:13:53 charon: 10[NET] <con1|3> received packet: from 50.76.XXX.XXX[38909] to 51.81.XXX.XXX[4500] (384 bytes)
Sep 4 06:13:48 charon: 10[NET] <con1|3> sending packet: from 51.81.XXX.XXX[4500] to 50.76.XXX.XXX[38909] (80 bytes)
Sep 4 06:13:48 charon: 10[ENC] <con1|3> generating CREATE_CHILD_SA response 7 [ N(NO_PROP) ]
Sep 4 06:13:48 charon: 10[IKE] <con1|3> failed to establish CHILD_SA, keeping IKE_SA
Sep 4 06:13:48 charon: 10[IKE] <con1|3> no acceptable proposal found
Sep 4 06:13:48 charon: 10[CFG] <con1|3> configured proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/NO_EXT_SEQ
Sep 4 06:13:48 charon: 10[CFG] <con1|3> received proposals: ESP:AES_CBC_256/HMAC_SHA2_256_128/ECP_256/NO_EXT_SEQ
Sep 4 06:13:48 charon: 10[ENC] <con1|3> parsed CREATE_CHILD_SA request 7 [ SA No TSi TSr KE ]
Sep 4 06:13:48 charon: 10[NET] <con1|3> received packet: from 50.76.XXX.XXX[38909] to 51.81.XXX.XXX[4500] (384 bytes)

[kapara]

ok so now for even stranger issues.  So if I try to transfer a 512mb zip file over the VPN when it hits about 43% completed ping fails.  If I do not transfer any files, ping does not fail.

Update:

So vpn fails everytime at 43% of 512mb zip file transfer.  I also tested this on my mobile hotspot.  Same result at 43%.  And I am pinging both the remote LAN interface and the computer I am transferring from using smb file share on remote machine.

Also even with constant ping connection dropped after 45 minutes.

[mimugmail]

For the timeout try setting Interface : LAN : MSS to 1300, regarding the timeout it seems to be your gateway (of client) which doesn't handle IPSec properly (better switch to OpenVPN).

[kapara]

Odd because I never have this problem with my pfSense boxes.  Really would prefer to stick with Opnsense but it looks like the implementation of IPSEC is buggy or something else.  If I dont get this resolved soon I will have to switch back to pfSense.

I must use IPSEC as the users must be able to authenticate to the VPN prior to login.  Native IPSEC allows this.  OpenVPN client cannot do this.

[kapara]

For the timeout try setting Interface : LAN : MSS to 1300, regarding the timeout it seems to be your gateway (of client) which doesn't handle IPSec properly (better switch to OpenVPN).

For LAN and not WAN?

Issue is on remote client.

MSS of 1300 did nothing.

[kapara]

Recreated VPN and working now.  Not sure what the issue was but working.

[kapara]

I had to manually create VPN in Windows Powershell if I wanted to use SHA256 instead of SHA1.  It seems by default it only supports SHA1 unless configured via powershell...

Add-VpnConnection -Name "VPN TEST" -ServerAddress "firewall.system.xxx" -TunnelType IKEv2 -EncryptionLevel Required -AuthenticationMethod EAP -SplitTunneling -AllUserConnection
Set-VpnConnectionIPsecConfiguration -ConnectionName "VPN TEST" -AuthenticationTransformConstants SHA256 -CipherTransformConstants AES256 -DHGroup Group14 -EncryptionMethod AES256 -IntegrityCheckMethod SHA256
Add-VpnConnectionRoute -ConnectionName "VPN TEST" -DestinationPrefix 192.168.127.128/27 -PassThru