Share via


*UPDATED* Windows 10 anniversary update drops IKEv2 VPN connection to Cisco router in exactly 60 seconds after last data exchange

Question

Tuesday, January 17, 2017 8:08 PM | 3 votes

I have a Cisco IOS router, 892 model, which I'm setting up IKEv2 with EAP-MSCHAPv2 as remote authentication (backed by a Windows 2012 Server Network Policy Server) and local certificate authentication. Everything works, I can connect to the VPN and ping a loopback address on the router. Windows 7 and 8.1 work fine, Android with Strongswan too.

However, on Windows 10 (10.0.14393 - fully up to date 16 jan 2017), exactly 60 seconds after the last data exchange (like a ping), Windows drops the connection. So:

* T+0 VPN connection opened
* T+60 VPN connection drops

* T+0 VPN connection opened
* T+20 1 Ping to 172.16.0.5, reply received
* T+80 VPN connection drops

**Update 3: 22 Jan 2016**
I've narrowed down the update that causes this problem: KB3201845 OS Build 14393.479 from December 9 2016. I went through all these updates step by step.

Looking at the changes files manifest, these files have been changed:

* agilevpn.sys
* vpnike.dll

Other topics I've created:

Reddit /r/networking

Microsoft Feedback Hub

Superuser.com: http://superuser.com/questions/1168204/windows-10-drops-ikev2-vpn-connection-to-cisco-router-in-exactly-60-seconds-afte

  • Windows 10 pre-anniversary (version 10.0.10586) works fine
  • Windows 10 post-anniversary (version 10.0.14393) drops, so the problem is with the anniversary update.

I can connect using two pre-anniversary Windows hosts fine

If I connect 1 anniversary Windows host to the VPN and keep it alive artificially by pinging, I cannot connect a second host to the VPN. In the router's "debug crypto ikev2", this happens:

    Jan 17 19:20:35.811: IKEv2:(SESSION ID = 25,SA ID = 2):Session present in ID PAIR TREE, but absent in TUPLE TREE
    Jan 17 19:20:35.811: IKEv2:(SESSION ID = 25,SA ID = 2):: Failed to add new SA into session DB
    Jan 17 19:20:35.811: IKEv2:(SESSION ID = 25,SA ID = 2):Queuing IKE SA delete request reason: unknown
    Jan 17 19:20:35.811: IKEv2:(SESSION ID = 25,SA ID = 2):Sending DELETE INFO message for IPsec SA [SPI: 0x3DA95352]
    Jan 17 19:20:35.811: IKEv2:(SESSION ID = 25,SA ID = 2):Check for existing IPSEC SA
    Jan 17 19:20:35.811: IKEv2:(SESSION ID = 25,SA ID = 2):Delete all IKE SAs
    Jan 17 19:20:35.811: IKEv2:(SESSION ID = 25,SA ID = 2):Sending DELETE INFO message for IKEv2 SA [ISPI: 0x3B52B7EBA8A353B1 RSPI: 0x16F36D79AAE675A5]

The VPN is dropped with the following message in the System event log:

Source: RasClient

Event ID: 20226

CoId={43121588-861C-447A-A510-C44C2BA86639}: The user LAPTOP-GLENN\Glenn dialed a connection named ikev2-test which has terminated. The reason code returned on termination is 829.

So I started digging and enabled RAS debugging on the client:

    netsh ras diagnostics * state=enabled

The only relevant stuff I could find was in C:\Windows\tracing\rasman.log (20:11:51 is when the disconnect happens - interesting bits prefixed with "***"):

    [1384] 01-16 20:11:51:216: FreeInterfaceLuidIndex: Luid = 0
    [1384] 01-16 20:11:51:216: RasUpdateVpnLuidCache: Luid: 17000000000000, fAddLuid:0
    [1384] 01-16 20:11:51:216: RasUpdateVpnLuidCache: Removed Luid 17000000000000 from cache
    [1384] 01-16 20:11:51:216: FreeInterfaceLuidIndex: done 0
    [1384] 01-16 20:11:51:216: DeallocateRouteRequestCommon: pBundle=0xa50adde0, type=0x800
    [1384] 01-16 20:11:51:232: DeActivated Route , bundlehandle 0x4, prottype = 2048
    [1384] 01-16 20:11:51:232: DeAllocateRoute: PI_Type=0x800, PI_AdapterName=\DEVICE\{93A76D72-2010-45BB-9096-244B06735879}, PI_Allocated=-1
    [3524] 01-16 20:11:51:248: SendProtocolResultToRasman: msgid=1, hPort: 6.
    *** [3524] 01-16 20:11:51:248: Setting last error for port VPN2-1 to ppp error 0x3635
    [3524] 01-16 20:11:51:248: SetProtocolResultAvailableEvent: Notification handle event for port 6 is not registered.
    [2640] 01-16 20:11:51:248: WorkerThread: Disconnect event signaled on port: VPN2-1
    [2640] 01-16 20:11:51:248: OVEVT_DEV_STATECHANGE. pOverlapped = 0xa4611940
    [2640] 01-16 20:11:51:248: onecoreuap\net\rras\ras\rasman\rasman\worker.c, 2031: Disconnecting port 6, connection 0xa6af47e0, reason 1
    [2640] 01-16 20:11:51:248: Disconnecting Port 0xVPN2-1, reason 1
    [2640] 01-16 20:11:51:248: DisconnectPort: Saving Bundle stats for port VPN2-1
    [2640] 01-16 20:11:51:263: RevertPostConnectionActions
    [2640] 01-16 20:11:51:263: RasImpersonateUser. 0x0
    [2640] 01-16 20:11:51:263: DeleteCredentialsFromCredMan
    [2640] 01-16 20:11:51:263: DeleteCredentialsFromCredMan Done: 0
    [2640] 01-16 20:11:51:263: RasRevertToSelf. 0x0
    [2640] 01-16 20:11:51:263: QueueCloseConnections: no dependent connections
    [2640] 01-16 20:11:51:263: 10. Throwing away handle 0x0!
    [2640] 01-16 20:11:51:263: onecoreuap\net\rras\ras\rasman\rasman\util.c, 2315:Setting port 6 for autoclosure...
    [2640] 01-16 20:11:51:263: onecoreuap\net\rras\ras\rasman\rasman\util.c 2327: Disconnected Port 6, reason 1. rc=0x0
    [2640] 01-16 20:11:51:263: FreeBundle: freeing pBundle=0xa50adde0
    [2640] 01-16 20:11:51:263: onecoreuap\net\rras\ras\rasman\rasman\util.c: 2443: port 6 state chg: prev=2, new=3
    [2640] 01-16 20:11:51:263: onecoreuap\net\rras\ras\rasman\rasman\util.c: 2459: port 6 state chg: prev=3, new=4
    [2640] 01-16 20:11:51:263: 5. Notifying of disconnect on port 6
    [2640] 01-16 20:11:51:263: SignalPortDisconnect: Notification handle event for port 6 is not registered.
    [2640] 01-16 20:11:51:263: onecoreuap\net\rras\ras\rasman\rasman\util.c: 2573: port 6 async reqtype chg: prev=0, new=0
    [2640] 01-16 20:11:51:263: ***** DisconnectType=1,DisconnectReason=4,pConn=0xa6af47e0,cbports=1,signaled=1,hEvent=0xffffffff,fRedial=0
    [2640] 01-16 20:11:51:263: Calling DwQueueRedial
    [2640] 01-16 20:11:51:263: DwQueueRedial
    [2640] 01-16 20:11:51:263: DwQueueRedial returned 0x0
    [2640] 01-16 20:11:51:263: onecoreuap\net\rras\ras\rasman\rasman\util.c, 2634: Autoclosing port 6
    [2640] 01-16 20:11:51:263: PortClose: port (6). OpenInstances = 1
    [2640] 01-16 20:11:51:263: Freeing the notifier list for port 6
    [2640] 01-16 20:11:51:263: PortClose (6). OpenInstances = 0
    [2640] 01-16 20:11:51:263: onecoreuap\net\rras\ras\rasman\rasman\request.c: 3845: port 6 async reqtype chg: prev=0, new=0
    [2640] 01-16 20:11:51:263: onecoreuap\net\rras\ras\rasman\rasman\request.c: 3848: port 6 state chg: prev=4, new=4
    [2640] 01-16 20:11:51:263: PortClose: Resetting PCB_OpenedUsage for port: 6.
    [2640] 01-16 20:11:51:263: RemoveConnectionPort: port 6, fOwnerClose=0, pConn=0xa6af47e0, pConn->CB_Ports=0

    *** [2640] 01-16 20:11:51:263: Completely disconnected connection: Reason: ERROR_LINK_FAILURE (829)
    [2640] 01-16 20:11:51:263: SendSensNotification(_RAS_DISCONNECT) for 0x00040000 returns 0x00000000
    [2640] 01-16 20:11:51:263: Successfully notified event(128, C:\Users\Glenn\AppData\Roaming\Microsoft\Network\Connections\Pbk\rasphone.pbk, ikev2-test) to the caller.
    [2640] 01-16 20:11:51:263: SignalNetman: IRasEventNotify::RasEvent returned S_FALSE
    [2640] 01-16 20:11:51:263: DwSendNotificationInternal(ENTRY_DISCONNECTED) rc=0x1
    [2640] 01-16 20:11:51:263: RemoveConnectionPort: FreeConnection hconn=0x40000, pconn=0xa6af47e0, AutoClose=1
    [2640] 01-16 20:11:51:263: FreeConnection: pConn=0xa6af47e0, 1
    [2640] 01-16 20:11:51:263: onecoreuap\net\rras\ras\rasman\rasman\request.c, 3918: Clearing the autoclose flag for port 6
    [2640] 01-16 20:11:51:263: fAnyConnectedPorts: 0
    [2640] 01-16 20:11:51:263: SetRasmanServiceStopControl: Enabled 1
    [2640] 01-16 20:11:51:263: PortClose: DisableAutoWPPTracing failed with error 0x2 
    [2640] 01-16 20:11:51:263: DisconnectPort Complete
    [2640] 01-16 20:11:51:263: onecoreuap\net\rras\ras\rasman\rasman\worker.c: 2077: port 6 state chg: prev=4, new=4
    [2640] 01-16 20:11:51:263: onecoreuap\net\rras\ras\rasman\rasman\worker.c: 2081: port 6 async reqtype chg: prev=0, new=0
    [1276] 01-16 20:11:51:263: The specified notification entry with cookie 2 found.
    [1276] 01-16 20:11:51:263: Dequed notification entry: (128, C:\Users\Glenn\AppData\Roaming\Microsoft\Network\Connections\Pbk\rasphone.pbk, ikev2-test) from the queue.
  • Ran the same config on a Cisco CSR1000v router and the exact same thing happened.
  • Created a REG_DWORD named "InactivityIdleSeconds" under HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Class\4d36e972-e325-11ce-bfc1-08002be10318}\0012 (WAN Miniport (IKEv2)) and played with its value but that didn't change anything (see here why I tried that)
  • Played around with Dead Peer Detection but that didn't change anything either

I can't find what the criteria are for Windows 10 to consider an IKEv2 connection dead or what state changes cause Windows 10 to think the VPN has to be disconnected.

Soooo... any pointers?

Microsoft Technet: Error 829 means ERROR_LINK_FAILURE The modem (or other connecting device) was disconnected due to link failure.

Microsoft Technet: 0x3635 means 13877 ERROR_IPSEC_IKE_RPC_DELETE "Deleted via RPC call."

The Cisco IOS router configuration

Cisco IOS router IKEv2 debug logs

Zipfile of the complete C:\Windows\tracing directory

All replies (27)

Wednesday, January 18, 2017 2:51 AM

Hi,

I find a documentation for you, please check it to see if can be helpful.

Troubleshooting IKEv2 VPN Connections

https://technet.microsoft.com/en-us/library/dd941612(v=ws.10).aspx

As you mentioned, connection issue doesn’t appear on previous Windows 8.1 or Windows 10 1511, so roll back to previous Windows version can be a workaround, but to my knowledge, there is not an official channel to get 1511 iso image. If you have a 1511 machine, you could use media creation tool to create an installation disk on that 1511 machine.

In addition, I suggest to contact Cisco support for help and feedback this situation through Feedback Hub app.

Regards

Please remember to mark the replies as answers if they help.
If you have feedback for TechNet Subscriber Support, contact [email protected].


Wednesday, January 18, 2017 7:16 PM

Those troubleshooting steps are only related to certificate problems. The VPN router's certificate is in order, otherwise the VPN would've not connected at all.


Thursday, January 19, 2017 9:22 AM | 3 votes

We can reproduce this issue on Windows 10 Version 1607 OS Build 14393.693 with other vendor IPsec/IKEv2 Gateways, i.e. from a Windows 10 client to a StrongSwan VPN server.

As the issue occurs independent of the remote VPN server, it must have been introduced with a Windows Update. It is a behavioral change on idle VPN connections which seems to ignore any RAS VPN specific configuration/settings (i.e. MOBIKE timeout) and sets a hard 60 seconds timer.

We suspect the behaviour was not changed right away with the Anniversary update from Version 1511 to 1607, otherwise customers would have complained earlier. We tried to isolate the update within Version 1607 build 14939 (possibly the last one 693 or the one before 571) that introduces this issue.  Alas, the update descriptions are not detailed enough to identify such a possible change. Going back to older versions of the Anniversary build cannot be done easily.


Thursday, January 19, 2017 2:08 PM | 1 vote

The criteria to determine an (IKEv2) VPN connection as dead is the IdleDisconnectSeconds value within the respective RAS phonebook entry. When editing the properties of a phonebook entry, the parameter is under Options and is called "Idle time before hanging up". The default value is "0" which is supposed to mean "never".

This still works in the Windows 10.0.14393.105 Update from August 31 2016. I have tried it with "never" to hang up and the connection was happy for hours. I then switched to 1 minute and the connection was disconnected after 1 minute exactly. Tried with 5 minutes, connection was disconnected after 5 minutes. 

I can confirm it is definitely broken since the following update: January 10, 2017 - see KB3213986 (OS Build 14393.693)

It seems a regression was introduced in one of the latest updates and the idle disconnect seconds value is ignored and a hard-coded value of 60 seconds is used instead.

Where can we properly report this bug?


Sunday, January 22, 2017 8:28 PM | 1 vote

I've narrowed down the update that causes this problem: KB3201845 OS Build 14393.479 from December 9 2016. See update 3 in original topic.


Sunday, January 22, 2017 8:28 PM | 1 vote

I've narrowed down the update that causes this problem: KB3201845 OS Build 14393.479 from December 9 2016. See update 3 in original topic.


Sunday, January 22, 2017 8:28 PM | 1 vote

I've narrowed down the update that causes this problem: KB3201845 OS Build 14393.479 from December 9 2016. See update 3 in original topic.


Thursday, January 26, 2017 5:13 PM

Bump


Saturday, January 28, 2017 1:39 PM | 2 votes

I can confirm that issue with two of my StrongSwan VPN servers. One is 5.5.0 version (compiled from sources), the other one is default from Debian's repository (5.2.1).

Configuration of the first one (second one configured similarly, but contains also classic L2TP+IPsec conn, which is NOT affected):

config setup
        charondebug="cfg 2, ike 4, net 2, esp 2"
        uniqueids = no
        strictcrlpolicy=yes

conn %default
        auto=add
        left=%any
        right=%any
        rekey=no
        fragmentation=yes
        ike=aes256-sha1-modp2048,aes256-sha1-modp1024,aes256-sha256-modp2048!
        esp=aes256-sha1,aes128-sha1,aes256-sha256!
        dpdaction=clear

conn IKEV2-pubkey
        keyexchange=ikev2
        leftauth=pubkey
        leftcert=<FQDN_name_of_my_server>.crt
        leftsendcert=always
        leftid="<FQDN_name_of_my_server>"
        leftsubnet=0.0.0.0/0
        rightauth=pubkey
        rightsourceip=192.168.20.0/27
        rightdns=8.8.8.8,8.8.4.4

What happens before 60-th second:

Jan 28 16:06:23 server_name charon: 09[IKE] sending DPD request
Jan 28 16:06:23 server_name charon: 09[IKE] queueing IKE_DPD task
Jan 28 16:06:23 server_name charon: 09[IKE] activating new tasks
Jan 28 16:06:23 server_name charon: 09[IKE]   activating IKE_DPD task
Jan 28 16:06:23 server_name charon: 09[ENC] generating INFORMATIONAL request 0 [ ]
Jan 28 16:06:23 server_name charon: 09[NET] sending packet: from <SERVER'S_IP>[4500] to <CLIENT'S_IP>[4500] (76 bytes)
Jan 28 16:06:23 server_name charon: 04[NET] sending packet: from <SERVER'S_IP>[4500] to <CLIENT'S_IP>[4500]
Jan 28 16:06:23 server_name charon: 03[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500]
Jan 28 16:06:23 server_name charon: 16[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500] (76 bytes)
Jan 28 16:06:23 server_name charon: 16[ENC] parsed INFORMATIONAL response 0 [ ]
Jan 28 16:06:23 server_name charon: 16[IKE] activating new tasks
Jan 28 16:06:23 server_name charon: 16[IKE] nothing to initiate
Jan 28 16:06:23 server_name charon: 03[NET] waiting for data on sockets
Jan 28 16:06:35 server_name charon: 03[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500]
Jan 28 16:06:35 server_name charon: 03[NET] waiting for data on sockets
Jan 28 16:06:38 server_name charon: 03[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500]
Jan 28 16:06:38 server_name charon: 03[NET] waiting for data on sockets
Jan 28 16:06:38 server_name charon: 09[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500] (76 bytes)
Jan 28 16:06:38 server_name charon: 09[ENC] parsed INFORMATIONAL request 2 [ D ]
Jan 28 16:06:38 server_name charon: 09[IKE] received DELETE for ESP CHILD_SA with SPI d31264e0
Jan 28 16:06:38 server_name charon: 09[IKE] closing CHILD_SA IKEV2-pubkey{3} with SPIs 48e65518_i (17398 bytes) d31264e0_o (0 bytes) and TS 0.0.0.0/0 === 192.168.20.1/32
Jan 28 16:06:38 server_name charon: 09[IKE] sending DELETE for ESP CHILD_SA with SPI 48e65518
Jan 28 16:06:38 server_name charon: 09[IKE] CHILD_SA closed
Jan 28 16:06:38 server_name charon: 09[ESP] deleting policy 0.0.0.0/0 === 192.168.20.1/32 out
Jan 28 16:06:38 server_name charon: 09[ESP] deleting policy 192.168.20.1/32 === 0.0.0.0/0 in
Jan 28 16:06:38 server_name charon: 09[ESP] deleted inbound SAD entry with SPI 48e65518
Jan 28 16:06:38 server_name charon: 09[ESP] deleted outbound SAD entry with SPI d31264e0
Jan 28 16:06:38 server_name charon: 09[ENC] generating INFORMATIONAL response 2 [ D ]
Jan 28 16:06:38 server_name charon: 09[NET] sending packet: from <SERVER'S_IP>[4500] to <CLIENT'S_IP>[4500] (76 bytes)
Jan 28 16:06:38 server_name charon: 04[NET] sending packet: from <SERVER'S_IP>[4500] to <CLIENT'S_IP>[4500]
Jan 28 16:06:38 server_name charon: 03[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500]
Jan 28 16:06:38 server_name charon: 12[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500] (76 bytes)
Jan 28 16:06:38 server_name charon: 12[ENC] parsed INFORMATIONAL request 3 [ D ]
Jan 28 16:06:38 server_name charon: 12[IKE] received DELETE for IKE_SA IKEV2-pubkey[20]
Jan 28 16:06:38 server_name charon: 12[IKE] deleting IKE_SA IKEV2-pubkey[20] between <SERVER'S_IP>[<FQDN_of_my_server>]...<CLIENT'S_IP>[CN=home]
Jan 28 16:06:38 server_name charon: 12[IKE] IKE_SA IKEV2-pubkey[20] state change: ESTABLISHED => DELETING
Jan 28 16:06:38 server_name charon: 12[IKE] IKE_SA deleted
Jan 28 16:06:38 server_name charon: 12[ENC] generating INFORMATIONAL response 3 [ ]
Jan 28 16:06:38 server_name charon: 12[NET] sending packet: from <SERVER'S_IP>[4500] to <CLIENT'S_IP>[4500] (76 bytes)
Jan 28 16:06:38 server_name charon: 12[IKE] IKE_SA IKEV2-pubkey[20] state change: DELETING => DESTROYING
Jan 28 16:06:38 server_name charon: 12[CFG] lease 192.168.20.1 by 'CN=home' went offline
Jan 28 16:06:38 server_name charon: 04[NET] sending packet: from <SERVER'S_IP>[4500] to <CLIENT'S_IP>[4500]
Jan 28 16:06:38 server_name charon: 03[NET] waiting for data on sockets

Nothing changes in general if I set dpdaction to none:

Jan 28 16:10:06 server_name charon: 16[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500] (76 bytes)
Jan 28 16:10:06 server_name charon: 16[ENC] parsed INFORMATIONAL request 2 [ D ]
Jan 28 16:10:06 server_name charon: 16[IKE] received DELETE for ESP CHILD_SA with SPI 8760b6aa
Jan 28 16:10:06 server_name charon: 16[IKE] closing CHILD_SA IKEV2-pubkey{1} with SPIs 504e81f5_i (19036 bytes) 8760b6aa_o (0 bytes) and TS 0.0.0.0/0 === 192.168.20.1/32
Jan 28 16:10:06 server_name charon: 16[IKE] sending DELETE for ESP CHILD_SA with SPI 504e81f5
Jan 28 16:10:06 server_name charon: 16[IKE] CHILD_SA closed
Jan 28 16:10:06 server_name charon: 16[ESP] deleting policy 0.0.0.0/0 === 192.168.20.1/32 out
Jan 28 16:10:06 server_name charon: 16[ESP] deleting policy 192.168.20.1/32 === 0.0.0.0/0 in
Jan 28 16:10:06 server_name charon: 16[ESP] deleted inbound SAD entry with SPI 504e81f5
Jan 28 16:10:06 server_name charon: 16[ESP] deleted outbound SAD entry with SPI 8760b6aa
Jan 28 16:10:06 server_name charon: 16[ENC] generating INFORMATIONAL response 2 [ D ]
Jan 28 16:10:06 server_name charon: 16[NET] sending packet: from <SERVER'S_IP>[4500] to <CLIENT'S_IP>[4500] (76 bytes)
Jan 28 16:10:06 server_name charon: 04[NET] sending packet: from <SERVER'S_IP>[4500] to <CLIENT'S_IP>[4500]
Jan 28 16:10:06 server_name charon: 03[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500]
Jan 28 16:10:06 server_name charon: 15[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500] (76 bytes)
Jan 28 16:10:06 server_name charon: 15[ENC] parsed INFORMATIONAL request 3 [ D ]
Jan 28 16:10:06 server_name charon: 15[IKE] received DELETE for IKE_SA IKEV2-pubkey[1]
Jan 28 16:10:06 server_name charon: 15[IKE] deleting IKE_SA IKEV2-pubkey[1] between <SERVER'S_IP>[<FQDN_of_my_server>]...<CLIENT'S_IP>[CN=home]
Jan 28 16:10:06 server_name charon: 15[IKE] IKE_SA IKEV2-pubkey[1] state change: ESTABLISHED => DELETING
Jan 28 16:10:06 server_name charon: 15[IKE] IKE_SA deleted
Jan 28 16:10:06 server_name charon: 15[ENC] generating INFORMATIONAL response 3 [ ]
Jan 28 16:10:06 server_name charon: 15[NET] sending packet: from <SERVER'S_IP>[4500] to <CLIENT'S_IP>[4500] (76 bytes)
Jan 28 16:10:06 server_name charon: 15[IKE] IKE_SA IKEV2-pubkey[1] state change: DELETING => DESTROYING
Jan 28 16:10:06 server_name charon: 15[CFG] lease 192.168.20.1 by 'CN=home' went offline
Jan 28 16:10:06 server_name charon: 04[NET] sending packet: from <SERVER'S_IP>[4500] to <CLIENT'S_IP>[4500]
Jan 28 16:10:06 server_name charon: 03[NET] waiting for data on sockets

DPD request didn't send, but still by some reason Win10-client suddenly initiates DELETE sequence and server has no choice but to approve that request and to break connection.

In both cases we have some regular packets exchanging like that before disconnect:

Jan 28 16:09:15 server_name charon: 07[ESP] parsed ESP header with SPI 504e81f5 [seq 116]
Jan 28 16:09:15 server_name charon: 03[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500]
Jan 28 16:09:15 server_name charon: 03[NET] waiting for data on sockets
Jan 28 16:09:15 server_name charon: 07[ESP] parsed ESP header with SPI 504e81f5 [seq 117]
Jan 28 16:09:15 server_name charon: 03[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500]
Jan 28 16:09:15 server_name charon: 03[NET] waiting for data on sockets
Jan 28 16:09:15 server_name charon: 07[ESP] parsed ESP header with SPI 504e81f5 [seq 118]
Jan 28 16:09:16 server_name charon: 03[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500]
Jan 28 16:09:16 server_name charon: 03[NET] waiting for data on sockets
Jan 28 16:09:16 server_name charon: 07[ESP] parsed ESP header with SPI 504e81f5 [seq 119]
Jan 28 16:09:18 server_name charon: 03[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500]
Jan 28 16:09:18 server_name charon: 03[NET] waiting for data on sockets
Jan 28 16:09:18 server_name charon: 07[ESP] parsed ESP header with SPI 504e81f5 [seq 120]
Jan 28 16:09:21 server_name charon: 03[NET] received packet: from <CLIENT'S_IP>[4500] to <SERVER'S_IP>[4500]
Jan 28 16:09:21 server_name charon: 03[NET] waiting for data on sockets
Jan 28 16:09:21 server_name charon: 07[ESP] parsed ESP header with SPI 504e81f5 [seq 121]

And of course if I perform some activity like echo-requests though the established tunnel, then nothing breaks at all.

This behavior appeared at the end of previous year, and I almost immediately suspected in that some of recent Updates, but Googling gives me nothing before that day exclude this famous DHCP problem (Google for "windows 10 dhcp problem 2016" since I can't attach any hyperlinks). And I'm not surprised that this caused by the same update as you guys have already figured out. And only God knows what kind of issues in network-related functionality could be affected in addition.


Saturday, January 28, 2017 6:04 PM | 2 votes

I feel your pain. In the past few weeks I've been trying to establish various IKEv2 connections and it's been my experience that IKEv2 implementations from various vendors are broken AF. Unfortunately I can't help you with your problem, I can only confirm it. Same thing happening here.


Wednesday, February 1, 2017 8:38 PM | 2 votes

Same thing happend here - only at vpn connection to isp hide.me, also set up with IKEv2 with EAP-MSCHAPv2.
Also after installing the kb3216755-x64 the problem persists.


Tuesday, February 7, 2017 5:54 PM | 2 votes

Same thing here. Using ikev2 vpn on pfsense for 2 years then suddenly all client updated in January showed this symptoms.

same DELETE request every time then the connection obviously terminates. This is definitely a bug. for now I solved it with a ping to keep connection open but it's definitely to fix.

Homines, dum docent, discunt.


Saturday, February 11, 2017 1:28 PM

Bump


Friday, February 17, 2017 6:56 PM

Bump


Sunday, February 19, 2017 7:49 AM

I had this problem in a laptop that we were blocking outbound connections by default.

I was able to fix it by allowing protocol 4 in through outbound rules of windows firewall.

I noticed the vpn was using protocol 4 in wf.msc in the Monitoring->Security Associations->Quick Mode section, that's what gave me the hint. It seems to be internal to windows because my vpn server isn't receiving protocol 4 traffic, but it is using protocol 50 traffic for the vpn...

hope this helps,

Shawn


Saturday, February 25, 2017 5:07 PM

That didn't work for me.


Tuesday, February 28, 2017 5:03 AM | 2 votes

I'm also seeing the same issue.

StrongSwan 5.4.0 VPN server

Windows 10 build 1607 client, using the built in VPN provider to create an IKEv2 tunnel

The VPN session will stay open for 60 seconds, then gets dropped from the client.


Tuesday, February 28, 2017 9:22 PM

I will raise this issue up to the PG to see if they are aware of anything. I will be in contact if we need to gather any sorts of logs or data.

Regards,

Adam Rudell | Windows Networking Beta | Microsoft Corporation


Wednesday, March 1, 2017 4:54 AM

I believe I have the same issue using StrongSwan 5.3.2 IKEv2 w EAP-MSCHAPv2 and Windows 10 1607 14393.693. Connects for 60 seconds then closes the connection. I also receive 0 bytes of data while connected.


Wednesday, March 1, 2017 10:59 AM

This bug is definitely in the Windows 10 Client and it is also not a 3rd-party vendor issue.

To prove this, we've setup a test environment and established an IKEv2 VPN between a Windows 10 Client and a Windows 2016 Server. Both systems are updated to OS Build 14939.693. The client has idle-timeout set to "never", the server uses 5 minutes. Client RAS connection config uses split-tunneling w/ no class based routes set. Authentication via machine certificates.

Idle disconnect happens after 60 seconds when the client deletes the CHILD_SA.


Wednesday, March 1, 2017 11:05 AM

We have an open case with MS Support on this for a month now and it is not really progressing. Support was unable to reproduce the issue in their lab (using pure Windows environment). As I wrote above, we could reproduce the issue in a Windows 10 <=> Windows 2016 Server environment ourselves, so the issue is not 3rd-party vendor related and must be a bug in Windows 10.


Wednesday, March 1, 2017 2:38 PM

I heard back from the PG and this has already been fixed in the RS2 (WIP) and RS1builds. The fix was included in the 2017.01 D update (KB 3216755) and was originally going to go out patch Tuesday (2017.02 B), however we had to delay the release. Please go to the update catalog and download the KB package manually. Otherwise the fix should be available in March 2017 via normal WU process.<o:p></o:p>

Edit: Fix did not make 2017.01 D as originally indicated above. Fix will be release in the March 2017 CU for RS1 clients. Fix is already in the Release Preview ring.

Adam Rudell | Windows Networking Beta | Microsoft Corporation


Wednesday, March 1, 2017 4:21 PM

We tried the KB 3216755 (OS Build 14393.726) update already and it does NOT fix the issue. The idle disconnect still happens after 60 seconds.

Checking the contents of the 726 update, the `Vpnike.dll` file has not been exchanged and is still from OS Build 14393.479.


Wednesday, March 1, 2017 7:33 PM

I made adjustments above. The fix did not make it into the release as originally thought, however will be in the March 2017 CU.

Adam Rudell | Windows Networking Beta | Microsoft Corporation


Thursday, March 2, 2017 11:02 AM

These are good news, thanks for the clarification! Looking forward to the update :-)


Tuesday, March 14, 2017 8:42 PM

Just installed latest updates for Windows 10 and now everything seems to be fine! Connection doesn't break anymore after 60, 120 and more seconds without traffic passing through.

Anyone can confirm that too?


Thursday, March 16, 2017 11:10 AM

I concur, the latest Update (14393.953) fixes the issue.