Bridged TAP adapter fails after hibernation.

[arrowd]

I am using Windows Server 2012 R2. My network card adapter is bridged with TAP adapter, which is used by OpenVPN. Somewhere since November Windows update, when computer gets up from hibernation, my OpenVPN service started to stop working properly.

I've tracked this down to TAP adapter being recreated (or something like, dunno) after the wakeup. If i remove TAP adapter from the bridge and then re-add it back, it starts to work.

Any idea how to fix it?

[mattock]

Interesting problem... are you using OpenVPN 2.4.0?

[arrowd]

Yes, but this was the case with 2.3 too. I suspect the problem isn't within OpenVPN, but TAP driver, or even Windows.

When computer just wakes up from hibernation, TAP adapter statistics shows 0 bytes recieved/sent, just as the adapter was just created. My network card adapter statistics, on other hand, show all the traffic since the machine start.

[mattock]

OpenVPN 2.4 has a completely new OpenVPNService (openvpnserv2.exe) written in C#. So the behavior between 2.3.x and 2.4.x might differ.

Does the problem occur if you suspend (to RAM) instead of hibernate?

[arrowd]

OpenVPN 2.4 has a completely new OpenVPNService (openvpnserv2.exe) written in C#. So the behavior between 2.3.x and 2.4.x might differ.

I know, but unfortunately it is not the case for me.

Does the problem occur if you suspend (to RAM) instead of hibernate?

I found that putting server into Sleep is quite tricky. I used rundll32.exe powrprof.dll,SetSuspendState 0,1,0 and with that problem still occurs.

[selvanair]

On "power events" like sleep or hibernate the tap adapter stops and restarts on wakeup. I don't know whether this is the required behaviour for NDIS drivers.

In case of openvpn this causes connections to drop which we now handle by issuing a restart with a few seconds delay just before the sleep starts so the restart will happen on wakeup (earlier openvpn used disconnect on such events). In your case its the bridge setup that should cleanly handle such adapter disconnects and reconnects. Does it work correctly if a hardware adapter like a network card is bridged? If yes, the TAP driver's handling of power events probably needs some fix.

[arrowd]

Does it work correctly if a hardware adapter like a network card is bridged?

My bridge includes both TAP and hardware adapter. After wakeup hardware adapter works ok.

[selvanair]

Considering that you wrote the bridge has to be recreated after wake up, I was wondering whether a bridge that has only hardware adapters survives hibernation. But reading what you wrote again, its not clear the bridge is broken on wakeup. Could you please try starting the connection from command line with log on console, put the computer to sleep and see what happens on wake up. Openvpn logs on the console should show TAP disconnect causing openvpn to issue a restart which should trigger on wakeup.

[arrowd]

Whoa, you seem to be right. Here is the log on awakening:

Mon Jan 09 15:04:39 2017 us=264364 TUN/TAP I/O operation aborted, restarting Mon Jan 09 15:04:39 2017 us=264364 TCP/UDP: Closing socket Mon Jan 09 15:04:39 2017 us=264364 Closing TUN/TAP interface Mon Jan 09 15:04:39 2017 us=264364 SIGHUP[soft,tun-abort] received, process restarting Mon Jan 09 15:04:39 2017 us=265366 Current Parameter Settings: ... ... Mon Jan 09 15:04:39 2017 us=267368 OpenVPN 2.4.0 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Dec 27 2016 Mon Jan 09 15:04:39 2017 us=267368 Windows version 6.2 (Windows 8 or greater) 64bit Mon Jan 09 15:04:39 2017 us=267368 library versions: OpenSSL 1.0.2i 22 Sep 2016, LZO 2.09 Mon Jan 09 15:04:39 2017 us=267368 Restart pause, 2 second(s) Mon Jan 09 15:04:41 2017 us=268231 NOTE: when bridging your LAN adapter with the TAP adapter, note that the new bridge adapter will often take on its own IP address that is different from what the LAN adapter was previously set to Mon Jan 09 15:04:41 2017 us=268231 Diffie-Hellman initialized with 2048 bit key Mon Jan 09 15:04:41 2017 us=269232 TLS-Auth MTU parms [ L:1656 D:1210 EF:40 EB:0 ET:0 EL:3 ] Mon Jan 09 15:04:41 2017 us=269232 interactive service msg_channel=0 Mon Jan 09 15:04:41 2017 us=269232 open_tun Mon Jan 09 15:04:41 2017 us=269232 CreateFile failed on TAP device: \.\Global{E9ABA005-7E14-4840-9653-340B189EEFC4}.tap: The system cannot find the file specified. (errno=2) Mon Jan 09 15:04:41 2017 us=269232 Exiting due to fatal error

[selvanair]

Mon Jan 09 15:04:41 2017 us=269232 open_tun Mon Jan 09 15:04:41 2017 us=269232 CreateFile failed on TAP device: .\Global{E9ABA005-7E14-4840-9653-340B189EEFC4}.tap: The system cannot find the file specified. (errno=2) Mon Jan 09 15:04:41 2017 us=269232 Exiting due to fatal error

Hmm.. open tun failed. The tap device is supposed to come back up on wakeup. Does this happen even if not bridged? What happens if you rerun openvpn from cmd line after this failure -- is it just that tap needs more time to come up?

[arrowd]

Does this happen even if not bridged?

Yep, the same.

What happens if you rerun openvpn from cmd line after this failure -- is it just that tap needs more time to come up?

Seems so. Re-running is what i'm doing currently to work-around this - OpenVPN correctly opens tap device.

[selvanair]

Your logs showed a pause of only 2 seconds after tun-abort (caused by the driver shutdown on power event). IIRC, the SIGHUP restart (instead of terminate) in such cases was implemented with a longer than usual pause of 10 seconds. Are you running a customized version?

Further, even if openvpn terminates, the new service will repeatedly try restarting it as mattock mentioned. So, if restarting after a delay does work, I am not sure why your tunnel is not back up after the wakeup.

[arrowd]

Are you running a customized version?

Nope, official OpenVPN installer for Windows.

Here is today log:

Thu Jan 12 23:46:28 2017 us=607271 OpenVPN 2.4.0 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Dec 27 2016 Thu Jan 12 23:46:28 2017 us=607271 Windows version 6.2 (Windows 8 or greater) 64bit Thu Jan 12 23:46:28 2017 us=607271 library versions: OpenSSL 1.0.2i 22 Sep 2016, LZO 2.09 Thu Jan 12 23:46:28 2017 us=607271 Restart pause, 2 second(s)

Fri Jan 13 08:29:00 2017 us=164782 NOTE: when bridging your LAN adapter with the TAP adapter, note that the new bridge adapter will often take on its own IP address that is different from what the LAN adapter was previously set to Fri Jan 13 08:29:00 2017 us=164782 Diffie-Hellman initialized with 2048 bit key Fri Jan 13 08:29:07 2017 us=957457 TLS-Auth MTU parms [ L:1656 D:1210 EF:40 EB:0 ET:0 EL:3 ] Fri Jan 13 08:29:07 2017 us=957457 interactive service msg_channel=0 Fri Jan 13 08:29:07 2017 us=957457 open_tun Fri Jan 13 08:29:07 2017 us=957457 TAP-WIN32 device [OpenVPN] opened: \.\Global{E9ABA005-7E14-4840-9653-340B189EEFC4}.tap Fri Jan 13 08:29:07 2017 us=957457 TAP-Windows Driver Version 9.21 Fri Jan 13 08:29:07 2017 us=957457 TAP-Windows MTU=1500 Fri Jan 13 08:29:07 2017 us=958458 Sleeping for 10 seconds... Fri Jan 13 08:29:17 2017 us=958885 NOTE: FlushIpNetTable failed on interface [17] {E9ABA005-7E14-4840-9653-340B189EEFC4} (status=1168) : Element not found.

So now it looks working from the log perspective, but it still doesn't work in reality - pings from client can't reach the server. Moreover, here is output of ipconfig:

Ethernet adapter Network Bridge:

Connection-specific DNS Suffix . : Link-local IPv6 Address . . . . . : fe80::597d:3e29:e349:1e88%19 IPv4 Address. . . . . . . . . . . : 192.168.7.100 Subnet Mask . . . . . . . . . . . : 255.255.255.0 Default Gateway . . . . . . . . . : 192.168.7.1

Tunnel adapter isatap.{2E28971B-E1E6-46F7-8768-770FF8164D06}:

Media State . . . . . . . . . . . : Media disconnected Connection-specific DNS Suffix . :

GUID's are different and while ipconfig says the adapter is disconnected, it is shown as connected in "Network Connections" Windows. I'm completely lost with this.

[arrowd]

Ok, that GUID is thing seems unrelated. Even when everything is working fine, these GUIDs are different and ipconfig show that tap interface is disconnected.

[selvanair]

Openvpn TAP adapter will show up as an Ethernet adapter and the GUID should match with what is shown in the logs. (edited)

Also your logs are incomplete. After the wakeup I can only see a 10 second pause in the logs -- does the log show successful open_tun followed by IP setting?

[arrowd]

I've found another interesting thing. When problem manifests (that is, when OpenVPN itself is working, only packets aren't passing) there is another action that immediatly fixes it. I open TAP interface properties, click "Configure" and in "Advanced" tab i change property "Media Status". This triggers some sort of reinitialization somewhere within driver, the interface goes down for a brief time and then everything starts working. Actual value of "Media status" property doesn't matter.

So, if TAP driver would perform the same reinitialization on wakeup as it do when property changes, things should start working again.

After the wakeup I can only see a 10 second pause in the logs -- does the log show successful open_tun followed by IP setting?

You mean this lines?

Fri Jan 13 08:29:07 2017 us=957457 open_tun
Fri Jan 13 08:29:07 2017 us=957457 TAP-WIN32 device [OpenVPN] opened: \.\Global{E9ABA005-7E14-4840-9653-340B189EEFC4}.tap

[arrowd]

Just FYI, I've found a decent workaround for this. I run this .bat script

netsh interface set interface name=OpenVPN admin=DISABLED
netsh interface set interface name=OpenVPN admin=ENABLED

after OpenVPN service start, and it makes packets pass the bridge again.

[Kusig]

In my case I use Windows 2012 server and it is not related to hibernation but the symptoms are exactly the same. Connection succeeds allways but no pinging possible. It was working for years stable but suddenly not any more. Don't know what the trigger was (eg. Windows patch ....).

However, after starting the OpenVPN Server, disabling and reenabling the TAP Network driver resolves this. Now I have to use the following script to start the service in order to make it work:

sc stop OpenVPNService timeout /t 5 /nobreak sc start OpenVPNService timeout /t 10 /nobreak netsh interface set interface name="OpenVPN-Net" admin=DISABLED timeout /t 5 /nobreak netsh interface set interface name="OpenVPN-Net" admin=ENABLED

[colorenz]

Any News for this issue?

[selvanair]

I haven't seen a follow up on my question about the logs, so no idea where its failing and the problem in one of the openvpn components or elsewhere.