SparkLabs Forum.

Community Help.


Random DHCP Errors

I have two connections to the same OpenVPN server. They both use the same Viscosity virtual adapter (i.e. their dev-node value is the same). Sometimes this error is thrown when the VPN is trying to connect:

Feb 16 03:59:43: NOTE: Release of DHCP-assigned IP address lease on TAP-Win32 adapter failed: The parameter is incorrect. (code=87)
Feb 16 03:59:43: WARNING: Failed to renew DHCP IP address lease on TAP-Win32 adapter: The system cannot find the file specified. (code=2)

This happens seemingly at random and it doesn't matter which connection I use. When I go in to device manager after this happens, the virtual adapter is always disabled. It usually works if I reconnect, but I'd like to find a way to avoid these errors all together.
Hi Aniki18,

Is this happening when you disconnect one connection then connect with the other?
Does this ever happen after opening Viscosity after a reboot?
Are you trying to connect with both connections simultaneously at all?
Also is this only happening when you connect, or does it sometimes happen when you are already connected?

Regards,

Eric
Hi Eric,

1). Probably not. I don't usually switch from one connection to another immediately, and I just tested that and it seemed to work fine.
2). I usually put my PC in hibernate, but I have noticed that it happens more often after waking or booting up. But, it can happen at other times as well.
3). No
4). No

The only difference between the two connections is that one runs some scripts. When I used to have the connections running off of two separate virtual adapters, the errors where much more frequent. I thought I solved the problem by switching to one virtual adapter, but it still happens from time to time. Thanks for the response :).
Hi Aniki18,

Thanks for the feedback. If you disable "Reconnect activate connections on wake", can you test two things for us:

1) If you are hibernating your PC with connections active, do they still try to reconnect when you wake your computer?
2) Does this help the situation at all if you manually reconnect after waking/booting your pc.

Thanks,

Eric.
I actually suspected that this might be a cause of the problem, so I disabled "Reconnect on wake" a while ago, but the errors continued to happen.
Hi Aniki18,

Thanks for the reply. Are you able to post a copy of the complete log when a connection fails? When the connection fails, does Viscosity claim it is still trying to connect, or does it disconnect?

Regards,

Eric
Hey again Eric,

Yeah, it definitely appears to be happening on wake. I hibernated and woke the PC up and reproduced the error. Here's the log:

Code: Select all

Feb 17 09:47:27: State changed to Connecting
Feb 17 09:47:27: Viscosity 1.4.2 (1178)
Feb 17 09:47:27: Running on Microsoft Windows 8 Pro
Feb 17 09:47:27: Bringing up interface...
Feb 17 09:47:27: Checking reachability status of connection...
Feb 17 09:47:29: Connection is reachable. Starting connection attempt.
Feb 17 09:47:29: OpenVPN 2.2.2 Win32-MSVC++ [SSL] [LZO2] [PKCS11] built on Jan  4 2012Feb 17 09:47:33: NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Feb 17 09:47:33: Control Channel Authentication: using 'ta.key' as a OpenVPN static key file
Feb 17 09:47:33: LZO compression initialized
Feb 17 09:47:33: UDPv4 link local: [undef]
Feb 17 09:47:33: UDPv4 link remote: 95.219.223.187:1194
Feb 17 09:47:33: WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Feb 17 09:47:35: [OpenVPN_Server] Peer Connection Initiated with 95.219.223.187:1194
Feb 17 09:47:37: Unrecognized option or missing parameter(s) in [PUSH-OPTIONS]:17: auth-token (2.2.2)
Feb 17 09:47:37: TAP-WIN32 device [Plex] opened: \\.\Global\{27C5B2AE-7256-4F89-BC9A-EE705B3E7436}.tap
Feb 17 09:47:37: Set TAP-Win32 TUN subnet mode network/local/netmask = 5.5.0.0/5.5.0.77/255.255.240.0 [SUCCEEDED]
Feb 17 09:47:37: Notified TAP-Win32 driver to set a DHCP IP/netmask of 5.5.0.77/255.255.240.0 on interface {27C5B2AE-7256-4F89-BC9A-EE705B3E7436} [DHCP-serv: 5.5.15.254, lease-time: 31536000]
Feb 17 09:47:37: Successful ARP Flush on interface [26] {27C5B2AE-7256-4F89-BC9A-EE705B3E7436}
Feb 17 09:47:37: NOTE: Release of DHCP-assigned IP address lease on TAP-Win32 adapter failed: The system cannot find the file specified.   (code=2)
Feb 17 09:47:37: WARNING: Failed to renew DHCP IP address lease on TAP-Win32 adapter: The system cannot find the file specified.   (code=2)
Feb 17 09:48:12: Warning: route gateway is not reachable on any active network adapters: 5.5.0.1
Feb 17 09:48:12: Warning: route gateway is not reachable on any active network adapters: 5.5.0.1
Feb 17 09:48:12: SYSTEM ROUTING TABLE
Feb 17 09:48:12: 0.0.0.0 0.0.0.0 192.168.2.1 p=0 i=12 t=4 pr=3 a=97929 h=0 m=21/0/0/0/0
Feb 17 09:48:12: 0.0.0.0 128.0.0.0 5.5.0.1 p=0 i=12 t=4 pr=3 a=0 h=0 m=21/0/0/0/0
Feb 17 09:48:12: 95.219.223.187 255.255.255.255 192.168.2.1 p=0 i=12 t=4 pr=3 a=0 h=0 m=20/0/0/0/0
Feb 17 09:48:12: 127.0.0.0 255.0.0.0 127.0.0.1 p=0 i=1 t=3 pr=2 a=97945 h=0 m=306/0/0/0/0
Feb 17 09:48:12: 127.0.0.1 255.255.255.255 127.0.0.1 p=0 i=1 t=3 pr=2 a=97945 h=0 m=306/0/0/0/0
Feb 17 09:48:12: 127.255.255.255 255.255.255.255 127.0.0.1 p=0 i=1 t=3 pr=2 a=97945 h=0 m=306/0/0/0/0
Feb 17 09:48:12: 128.0.0.0 128.0.0.0 5.5.0.1 p=0 i=12 t=4 pr=3 a=0 h=0 m=21/0/0/0/0
Feb 17 09:48:12: 192.168.2.0 255.255.255.0 192.168.2.150 p=0 i=12 t=3 pr=2 a=97926 h=0 m=276/0/0/0/0
Feb 17 09:48:12: 192.168.2.150 255.255.255.255 192.168.2.150 p=0 i=12 t=3 pr=2 a=97926 h=0 m=276/0/0/0/0
Feb 17 09:48:12: 192.168.2.255 255.255.255.255 192.168.2.150 p=0 i=12 t=3 pr=2 a=97926 h=0 m=276/0/0/0/0
Feb 17 09:48:12: 224.0.0.0 240.0.0.0 127.0.0.1 p=0 i=1 t=3 pr=2 a=97945 h=0 m=306/0/0/0/0
Feb 17 09:48:12: 224.0.0.0 240.0.0.0 192.168.2.150 p=0 i=12 t=3 pr=2 a=97929 h=0 m=276/0/0/0/0
Feb 17 09:48:12: 255.255.255.255 255.255.255.255 127.0.0.1 p=0 i=1 t=3 pr=2 a=97945 h=0 m=306/0/0/0/0
Feb 17 09:48:12: 255.255.255.255 255.255.255.255 192.168.2.150 p=0 i=12 t=3 pr=2 a=97929 h=0 m=276/0/0/0/0
Feb 17 09:48:12: SYSTEM ADAPTER LIST
Feb 17 09:48:12: Viscosity Virtual Adapter V9.1
Feb 17 09:48:12:   Index = 26
Feb 17 09:48:12:   GUID = {27C5B2AE-7256-4F89-BC9A-EE705B3E7436}
Feb 17 09:48:12:   IP = 0.0.0.0/0.0.0.0
Feb 17 09:48:12:   MAC = 00:ff:27:c5:b2:ae
Feb 17 09:48:12:   GATEWAY = 0.0.0.0/255.255.255.255
Feb 17 09:48:12:   DHCP SERV = 
Feb 17 09:48:12:   DHCP LEASE OBTAINED = Sun Feb 17 21:48:12 2013
Feb 17 09:48:12:   DHCP LEASE EXPIRES  = Wed May 06 07:33:56 1970
Feb 17 09:48:12:   DNS SERV = 
Feb 17 09:48:12: Microsoft Wi-Fi Direct Virtual Adapter #3
Feb 17 09:48:12:   Index = 20
Feb 17 09:48:12:   GUID = {813F268C-24A2-471E-B836-274B7C81559D}
Feb 17 09:48:12:   IP = 0.0.0.0/0.0.0.0
Feb 17 09:48:12:   MAC = de:85:de:7c:ba:5f
Feb 17 09:48:12:   GATEWAY = 0.0.0.0/255.255.255.255
Feb 17 09:48:12:   DHCP SERV = 
Feb 17 09:48:12:   DHCP LEASE OBTAINED = Sun Feb 17 21:48:12 2013
Feb 17 09:48:12:   DHCP LEASE EXPIRES  = Wed May 06 07:44:36 1970
Feb 17 09:48:12:   DNS SERV = 
Feb 17 09:48:12: Broadcom 802.11n Network Adapter
Feb 17 09:48:12:   Index = 19
Feb 17 09:48:12:   GUID = {0A416E8E-BF62-454F-9485-5F12E3A7185A}
Feb 17 09:48:12:   IP = 0.0.0.0/0.0.0.0
Feb 17 09:48:12:   MAC = dc:85:de:7c:ba:5f
Feb 17 09:48:12:   GATEWAY = 0.0.0.0/255.255.255.255
Feb 17 09:48:12:   DHCP SERV = 
Feb 17 09:48:12:   DHCP LEASE OBTAINED = Sun Feb 17 21:48:12 2013
Feb 17 09:48:12:   DHCP LEASE EXPIRES  = Wed May 06 07:55:16 1970
Feb 17 09:48:12:   DNS SERV = 
Feb 17 09:48:12: Bluetooth Device (Personal Area Network)
Feb 17 09:48:12:   Index = 16
Feb 17 09:48:12:   GUID = {065858F4-9DEF-46D5-ADDC-35751F9CA7A3}
Feb 17 09:48:12:   IP = 0.0.0.0/0.0.0.0
Feb 17 09:48:12:   MAC = dc:85:de:67:27:5e
Feb 17 09:48:12:   GATEWAY = 0.0.0.0/255.255.255.255
Feb 17 09:48:12:   DHCP SERV = 
Feb 17 09:48:12:   DHCP LEASE OBTAINED = Sun Feb 17 21:48:12 2013
Feb 17 09:48:12:   DHCP LEASE EXPIRES  = Wed Dec 31 16:00:00 1969
Feb 17 09:48:12:   DNS SERV = 
Feb 17 09:48:12: Intel(R) 82579V Gigabit Network Connection
Feb 17 09:48:12:   Index = 12
Feb 17 09:48:12:   GUID = {FC070ACD-3DD6-423A-8AB4-25CF4508DCB1}
Feb 17 09:48:12:   IP = 192.168.2.150/255.255.255.0
Feb 17 09:48:12:   MAC = 50:46:5d:4f:1d:9c
Feb 17 09:48:12:   GATEWAY = 192.168.2.1/255.255.255.255
Feb 17 09:48:12:   DNS SERV = 192.168.2.1/255.255.255.255
Feb 17 09:48:12: Initialization Sequence Completed With Errors ( see http://openvpn.net/faq.html#dhcpclientserv )
Feb 17 09:48:12: State changed to Connected


It still appears that it is connected, but it doesn't work. Then, after disconnecting and reconnecting, it works fine. Not a huge deal for me, but I'm trying to make this setup girlfriend-proof :lol:.
Hi Aniki18,

Thanks for that log. You can confirm the adapter is disabled when the log says the connection is connected? If so, we have some updates in the next version which should solve this specific issue, if not we'll need to look elsewhere.

Regards,

Eric
Hmmm... Weird, now I can't seem to replicate the problem. I'll get back to you when it happens again.
Hello again,

Same problem occurred this morning, but this time it was not after a wake or reboot, it was after switching from one connection to another. It says connected and the adapter is enabled, but it gives the same DHCP error in the log.

Log from 1st connection (worked fine):

Code: Select all

Feb 18 12:44:43: State changed to Connecting
Feb 18 12:44:43: Viscosity 1.4.2 (1178)
Feb 18 12:44:43: Running on Microsoft Windows 8 Pro
Feb 18 12:44:43: Bringing up interface...
Feb 18 12:44:43: Checking reachability status of connection...
Feb 18 12:44:44: Connection is reachable. Starting connection attempt.
Feb 18 12:44:44: OpenVPN 2.2.2 Win32-MSVC++ [SSL] [LZO2] [PKCS11] built on Jan  4 2012
Feb 18 12:44:48: NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Feb 18 12:44:48: Control Channel Authentication: using 'ta.key' as a OpenVPN static key file
Feb 18 12:44:48: LZO compression initialized
Feb 18 12:44:48: UDPv4 link local: [undef]
Feb 18 12:44:48: UDPv4 link remote: 95.219.223.187:1194
Feb 18 12:44:48: WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Feb 18 12:44:50: [OpenVPN_Server] Peer Connection Initiated with 95.219.223.187:1194
Feb 18 12:44:56: Unrecognized option or missing parameter(s) in [PUSH-OPTIONS]:17: auth-token (2.2.2)
Feb 18 12:44:56: TAP-WIN32 device [Plex] opened: \\.\Global\{27C5B2AE-7256-4F89-BC9A-EE705B3E7436}.tap
Feb 18 12:44:56: Set TAP-Win32 TUN subnet mode network/local/netmask = 5.5.0.0/5.5.0.2/255.255.240.0 [SUCCEEDED]
Feb 18 12:44:56: Notified TAP-Win32 driver to set a DHCP IP/netmask of 5.5.0.2/255.255.240.0 on interface {27C5B2AE-7256-4F89-BC9A-EE705B3E7436} [DHCP-serv: 5.5.15.254, lease-time: 31536000]
Feb 18 12:44:56: Successful ARP Flush on interface [26] {27C5B2AE-7256-4F89-BC9A-EE705B3E7436}
Feb 18 12:45:01: State changed to Disconnecting
Feb 18 12:45:01: State changed to Disconnected


Log from 2nd connection (errors):

Code: Select all

Feb 18 12:45:02: State changed to Connecting
Feb 18 12:45:03: Viscosity 1.4.2 (1178)
Feb 18 12:45:03: Running on Microsoft Windows 8 Pro
Feb 18 12:45:03: Bringing up interface...
Feb 18 12:45:03: Checking reachability status of connection...
Feb 18 12:45:04: Connection is reachable. Starting connection attempt.
Feb 18 12:45:04: OpenVPN 2.2.2 Win32-MSVC++ [SSL] [LZO2] [PKCS11] built on Jan  4 2012
Feb 18 12:45:04: NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Feb 18 12:45:04: Control Channel Authentication: using 'ta.key' as a OpenVPN static key file
Feb 18 12:45:04: LZO compression initialized
Feb 18 12:45:04: UDPv4 link local: [undef]
Feb 18 12:45:04: UDPv4 link remote: 95.219.223.187:1194
Feb 18 12:45:05: WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
Feb 18 12:45:06: [OpenVPN_Server] Peer Connection Initiated with 95.219.223.187:1194
Feb 18 12:45:09: Unrecognized option or missing parameter(s) in [PUSH-OPTIONS]:17: auth-token (2.2.2)
Feb 18 12:45:09: TAP-WIN32 device [Plex] opened: \\.\Global\{27C5B2AE-7256-4F89-BC9A-EE705B3E7436}.tap
Feb 18 12:45:09: Set TAP-Win32 TUN subnet mode network/local/netmask = 5.5.0.0/5.5.0.3/255.255.240.0 [SUCCEEDED]
Feb 18 12:45:09: Notified TAP-Win32 driver to set a DHCP IP/netmask of 5.5.0.3/255.255.240.0 on interface {27C5B2AE-7256-4F89-BC9A-EE705B3E7436} [DHCP-serv: 5.5.15.254, lease-time: 31536000]
Feb 18 12:45:09: Successful ARP Flush on interface [26] {27C5B2AE-7256-4F89-BC9A-EE705B3E7436}
Feb 18 12:45:09: NOTE: Release of DHCP-assigned IP address lease on TAP-Win32 adapter failed: The system cannot find the file specified.   (code=2)
Feb 18 12:45:09: WARNING: Failed to renew DHCP IP address lease on TAP-Win32 adapter: The system cannot find the file specified.   (code=2)
Feb 18 12:45:44: Warning: route gateway is not reachable on any active network adapters: 5.5.0.1
Feb 18 12:45:44: Warning: route gateway is not reachable on any active network adapters: 5.5.0.1
Feb 18 12:45:44: SYSTEM ROUTING TABLE
Feb 18 12:45:44: 0.0.0.0 0.0.0.0 192.168.2.1 p=0 i=12 t=4 pr=3 a=151766 h=0 m=21/0/0/0/0
Feb 18 12:45:44: 0.0.0.0 128.0.0.0 5.5.0.1 p=0 i=12 t=4 pr=3 a=0 h=0 m=21/0/0/0/0
Feb 18 12:45:44: 95.219.223.187 255.255.255.255 192.168.2.1 p=0 i=12 t=4 pr=3 a=0 h=0 m=20/0/0/0/0
Feb 18 12:45:44: 127.0.0.0 255.0.0.0 127.0.0.1 p=0 i=1 t=3 pr=2 a=151782 h=0 m=306/0/0/0/0
Feb 18 12:45:44: 127.0.0.1 255.255.255.255 127.0.0.1 p=0 i=1 t=3 pr=2 a=151782 h=0 m=306/0/0/0/0
Feb 18 12:45:44: 127.255.255.255 255.255.255.255 127.0.0.1 p=0 i=1 t=3 pr=2 a=151782 h=0 m=306/0/0/0/0
Feb 18 12:45:44: 128.0.0.0 128.0.0.0 5.5.0.1 p=0 i=12 t=4 pr=3 a=0 h=0 m=21/0/0/0/0
Feb 18 12:45:44: 192.168.2.0 255.255.255.0 192.168.2.150 p=0 i=12 t=3 pr=2 a=151763 h=0 m=276/0/0/0/0
Feb 18 12:45:44: 192.168.2.150 255.255.255.255 192.168.2.150 p=0 i=12 t=3 pr=2 a=151763 h=0 m=276/0/0/0/0
Feb 18 12:45:44: 192.168.2.255 255.255.255.255 192.168.2.150 p=0 i=12 t=3 pr=2 a=151763 h=0 m=276/0/0/0/0
Feb 18 12:45:44: 224.0.0.0 240.0.0.0 127.0.0.1 p=0 i=1 t=3 pr=2 a=151782 h=0 m=306/0/0/0/0
Feb 18 12:45:44: 224.0.0.0 240.0.0.0 192.168.2.150 p=0 i=12 t=3 pr=2 a=151766 h=0 m=276/0/0/0/0
Feb 18 12:45:44: 255.255.255.255 255.255.255.255 127.0.0.1 p=0 i=1 t=3 pr=2 a=151782 h=0 m=306/0/0/0/0
Feb 18 12:45:44: 255.255.255.255 255.255.255.255 192.168.2.150 p=0 i=12 t=3 pr=2 a=151766 h=0 m=276/0/0/0/0
Feb 18 12:45:44: SYSTEM ADAPTER LIST
Feb 18 12:45:44: Viscosity Virtual Adapter V9.1
Feb 18 12:45:44:   Index = 26
Feb 18 12:45:44:   GUID = {27C5B2AE-7256-4F89-BC9A-EE705B3E7436}
Feb 18 12:45:44:   IP = 0.0.0.0/0.0.0.0
Feb 18 12:45:44:   MAC = 00:ff:27:c5:b2:ae
Feb 18 12:45:44:   GATEWAY = 0.0.0.0/255.255.255.255
Feb 18 12:45:44:   DHCP SERV = 
Feb 18 12:45:44:   DHCP LEASE OBTAINED = Mon Feb 18 12:45:44 2013
Feb 18 12:45:44:   DHCP LEASE EXPIRES  = Sun May 03 11:02:28 1970
Feb 18 12:45:44:   DNS SERV = 
Feb 18 12:45:44: Microsoft Wi-Fi Direct Virtual Adapter #3
Feb 18 12:45:44:   Index = 20
Feb 18 12:45:44:   GUID = {813F268C-24A2-471E-B836-274B7C81559D}
Feb 18 12:45:44:   IP = 0.0.0.0/0.0.0.0
Feb 18 12:45:44:   MAC = de:85:de:7c:ba:5f
Feb 18 12:45:44:   GATEWAY = 0.0.0.0/255.255.255.255
Feb 18 12:45:44:   DHCP SERV = 
Feb 18 12:45:44:   DHCP LEASE OBTAINED = Mon Feb 18 12:45:44 2013
Feb 18 12:45:44:   DHCP LEASE EXPIRES  = Sun May 03 11:13:08 1970
Feb 18 12:45:44:   DNS SERV = 
Feb 18 12:45:44: Broadcom 802.11n Network Adapter
Feb 18 12:45:44:   Index = 19
Feb 18 12:45:44:   GUID = {0A416E8E-BF62-454F-9485-5F12E3A7185A}
Feb 18 12:45:44:   IP = 0.0.0.0/0.0.0.0
Feb 18 12:45:44:   MAC = dc:85:de:7c:ba:5f
Feb 18 12:45:44:   GATEWAY = 0.0.0.0/255.255.255.255
Feb 18 12:45:44:   DHCP SERV = 
Feb 18 12:45:44:   DHCP LEASE OBTAINED = Mon Feb 18 12:45:44 2013
Feb 18 12:45:44:   DHCP LEASE EXPIRES  = Sun May 03 11:23:48 1970
Feb 18 12:45:44:   DNS SERV = 
Feb 18 12:45:44: Bluetooth Device (Personal Area Network)
Feb 18 12:45:44:   Index = 16
Feb 18 12:45:44:   GUID = {065858F4-9DEF-46D5-ADDC-35751F9CA7A3}
Feb 18 12:45:44:   IP = 0.0.0.0/0.0.0.0
Feb 18 12:45:44:   MAC = dc:85:de:67:27:5e
Feb 18 12:45:44:   GATEWAY = 0.0.0.0/255.255.255.255
Feb 18 12:45:44:   DHCP SERV = 
Feb 18 12:45:44:   DHCP LEASE OBTAINED = Mon Feb 18 12:45:44 2013
Feb 18 12:45:44:   DHCP LEASE EXPIRES  = Wed Dec 31 16:00:00 1969
Feb 18 12:45:44:   DNS SERV = 
Feb 18 12:45:44: Intel(R) 82579V Gigabit Network Connection
Feb 18 12:45:44:   Index = 12
Feb 18 12:45:44:   GUID = {FC070ACD-3DD6-423A-8AB4-25CF4508DCB1}
Feb 18 12:45:44:   IP = 192.168.2.150/255.255.255.0
Feb 18 12:45:44:   MAC = 50:46:5d:4f:1d:9c
Feb 18 12:45:44:   GATEWAY = 192.168.2.1/255.255.255.255
Feb 18 12:45:44:   DNS SERV = 192.168.2.1/255.255.255.255
Feb 18 12:45:44: Initialization Sequence Completed With Errors ( see http://openvpn.net/faq.html#dhcpclientserv )
Feb 18 12:45:44: State changed to Connected


As a random test, I changed my assigned IP from dynamic to static in OpenVPN-AS, but it didn't help :(.
12 posts Page 1 of 2

Copyright © 2016 SparkLabs Pty Ltd. All Rights Reserved. Privacy Policy