Hi!
I'm facing a strange issue on Windows 8.
It happens very often that the TUN/TAP adapter is not started and
OpenVPN is unable to setup IPs and routes.
openvpn.exe writes over and over "Waiting for TUN/TAP interface to come up...".
After ~30 seconds it continues without a proper network configuration.
This is very nasty because from the users point of few it looks like
the tunnel is up but nothing works.
On the net I found some halve baked "solutions" for that issue.
Like disabling the Windows Firewall, disabling IPv6, setting the
DHCP-Client service to autostart, and so on. But nothing helped so far
nor really explained the root issue.
Please see the attached log file.
(It is sightly censored to hide my customers name and public IP.)
I ran also Wireshark on my TUN/TAP device while connecting.
When facing the issue zero packets were captured. So, it is not really
a networking issue between server and client.
Can you please help me?
--
Thanks,
//richard
Wed Jul 10 13:52:07 2013 OpenVPN 2.3.2 i686-w64-mingw32 [SSL (OpenSSL)] [LZO]
[PKCS11] [eurephia] [IPv6] built on Jun 3 2013
Wed Jul 10 13:52:07 2013 MANAGEMENT: TCP Socket listening on
[AF_INET]127.0.0.1:25340
Wed Jul 10 13:52:07 2013 Need hold release from management interface, waiting...
Wed Jul 10 13:52:08 2013 MANAGEMENT: Client connected from
[AF_INET]127.0.0.1:25340
Wed Jul 10 13:52:08 2013 MANAGEMENT: CMD 'state on'
Wed Jul 10 13:52:08 2013 MANAGEMENT: CMD 'log all on'
Wed Jul 10 13:52:08 2013 MANAGEMENT: CMD 'hold off'
Wed Jul 10 13:52:08 2013 MANAGEMENT: CMD 'hold release'
Wed Jul 10 13:52:08 2013 Socket Buffers: R=[128000->128000] S=[49152->49152]
Wed Jul 10 13:52:08 2013 UDPv4 link local: [undef]
Wed Jul 10 13:52:08 2013 UDPv4 link remote: [AF_INET]1.2.3.4:1194
Wed Jul 10 13:52:08 2013 MANAGEMENT: >STATE:1373457128,WAIT,,,
Wed Jul 10 13:52:08 2013 MANAGEMENT: >STATE:1373457128,AUTH,,,
Wed Jul 10 13:52:08 2013 TLS: Initial packet from [AF_INET]1.2.3.4:1194,
sid=b3fcdce9 c45bc68a
Wed Jul 10 13:52:10 2013 VERIFY OK: depth=1, C=AT, ST=T, L=City, O=customer,
OU=VPN, CN=server_customer, name=server_customer, emailAddress=vpn@customer
Wed Jul 10 13:52:10 2013 VERIFY OK: nsCertType=SERVER
Wed Jul 10 13:52:10 2013 VERIFY OK: depth=0, C=AT, ST=T, L=City, O=customer,
OU=VPN, CN=server_customer, name=server_customer, emailAddress=vpn@customer
Wed Jul 10 13:52:12 2013 Data Channel Encrypt: Cipher 'BF-CBC' initialized with
128 bit key
Wed Jul 10 13:52:12 2013 Data Channel Encrypt: Using 160 bit message hash
'SHA1' for HMAC authentication
Wed Jul 10 13:52:12 2013 Data Channel Decrypt: Cipher 'BF-CBC' initialized with
128 bit key
Wed Jul 10 13:52:12 2013 Data Channel Decrypt: Using 160 bit message hash
'SHA1' for HMAC authentication
Wed Jul 10 13:52:12 2013 Control Channel: TLSv1, cipher TLSv1/SSLv3
DHE-RSA-AES256-SHA, 2048 bit RSA
Wed Jul 10 13:52:12 2013 [server_customer] Peer Connection Initiated with
[AF_INET]1.2.3.4:1194
Wed Jul 10 13:52:13 2013 MANAGEMENT: >STATE:1373457133,GET_CONFIG,,,
Wed Jul 10 13:52:14 2013 SENT CONTROL [server_customer]: 'PUSH_REQUEST'
(status=1)
Wed Jul 10 13:52:14 2013 PUSH: Received control message:
'PUSH_REPLY,redirect-gateway def1 bypass-dhcp,dhcp-option DNS 192.168.0.2,route
10.100.1.1,topology net30,ping 10,ping-restart 120,ifconfig 10.100.1.18
10.100.1.17'
Wed Jul 10 13:52:14 2013 OPTIONS IMPORT: timers and/or timeouts modified
Wed Jul 10 13:52:14 2013 OPTIONS IMPORT: --ifconfig/up options modified
Wed Jul 10 13:52:14 2013 OPTIONS IMPORT: route options modified
Wed Jul 10 13:52:14 2013 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option
options modified
Wed Jul 10 13:52:14 2013 do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Wed Jul 10 13:52:14 2013 MANAGEMENT: >STATE:1373457134,ASSIGN_IP,,10.100.1.18,
Wed Jul 10 13:52:14 2013 open_tun, tt->ipv6=0
Wed Jul 10 13:52:14 2013 TAP-WIN32 device [LAN-Verbindung] opened:
\\.\Global\{C0F981D7-4C8D-4EF5-930D-B0A0E3065C4C}.tap
Wed Jul 10 13:52:14 2013 TAP-Windows Driver Version 9.9
Wed Jul 10 13:52:14 2013 Notified TAP-Windows driver to set a DHCP IP/netmask
of 10.100.1.18/255.255.255.252 on interface
{C0F981D7-4C8D-4EF5-930D-B0A0E3065C4C} [DHCP-serv: 10.100.1.17, lease-time:
31536000]
Wed Jul 10 13:52:14 2013 Successful ARP Flush on interface [17]
{C0F981D7-4C8D-4EF5-930D-B0A0E3065C4C}
Wed Jul 10 13:52:20 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:20 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:24 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:24 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:25 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:25 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:26 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:26 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:27 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:27 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:28 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:28 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:29 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:29 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:30 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:30 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:32 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:32 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:33 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:33 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:34 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:34 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:35 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:35 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:36 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:36 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:38 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:38 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:39 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:39 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:40 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:40 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:41 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:41 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:42 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:42 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:44 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:44 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:45 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:45 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:46 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:46 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:48 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:48 2013 Route: Waiting for TUN/TAP interface to come up...
Wed Jul 10 13:52:49 2013 TEST ROUTES: 0/0 succeeded len=1 ret=0 a=0 u/d=down
Wed Jul 10 13:52:49 2013 C:\Windows\system32\route.exe ADD 1.2.3.4 MASK
255.255.255.255 46.207.175.154
Wed Jul 10 13:52:49 2013 ROUTE: CreateIpForwardEntry succeeded with
dwForwardMetric1=30 and dwForwardType=4
Wed Jul 10 13:52:49 2013 Route addition via IPAPI succeeded [adaptive]
Wed Jul 10 13:52:49 2013 C:\Windows\system32\route.exe ADD 0.0.0.0 MASK
128.0.0.0 10.100.1.17
Wed Jul 10 13:52:49 2013 Warning: route gateway is not reachable on any active
network adapters: 10.100.1.17
Wed Jul 10 13:52:49 2013 Route addition via IPAPI failed [adaptive]
Wed Jul 10 13:52:49 2013 Route addition fallback to route.exe
Wed Jul 10 13:52:49 2013 env_block: add
PATH=C:\Windows\System32;C:\WINDOWS;C:\WINDOWS\System32\Wbem
Wed Jul 10 13:52:49 2013 C:\Windows\system32\route.exe ADD 128.0.0.0 MASK
128.0.0.0 10.100.1.17
Wed Jul 10 13:52:49 2013 Warning: route gateway is not reachable on any active
network adapters: 10.100.1.17
Wed Jul 10 13:52:49 2013 Route addition via IPAPI failed [adaptive]
Wed Jul 10 13:52:49 2013 Route addition fallback to route.exe
Wed Jul 10 13:52:49 2013 env_block: add
PATH=C:\Windows\System32;C:\WINDOWS;C:\WINDOWS\System32\Wbem
Wed Jul 10 13:52:49 2013 MANAGEMENT: >STATE:1373457169,ADD_ROUTES,,,
Wed Jul 10 13:52:49 2013 C:\Windows\system32\route.exe ADD 10.100.1.1 MASK
255.255.255.255 10.100.1.17
Wed Jul 10 13:52:49 2013 Warning: route gateway is not reachable on any active
network adapters: 10.100.1.17
Wed Jul 10 13:52:49 2013 Route addition via IPAPI failed [adaptive]
Wed Jul 10 13:52:49 2013 Route addition fallback to route.exe
Wed Jul 10 13:52:49 2013 env_block: add
PATH=C:\Windows\System32;C:\WINDOWS;C:\WINDOWS\System32\Wbem
Wed Jul 10 13:52:49 2013 SYSTEM ROUTING TABLE
Wed Jul 10 13:52:49 2013 0.0.0.0 0.0.0.0 46.207.175.154 p=0 i=22 t=3 pr=3 a=59
h=0 m=31/0/0/0/0
Wed Jul 10 13:52:49 2013 0.0.0.0 128.0.0.0 10.100.1.17 p=0 i=22 t=4 pr=3 a=0
h=0 m=31/0/0/0/0
Wed Jul 10 13:52:49 2013 10.100.1.1 255.255.255.255 10.100.1.17 p=0 i=22 t=4
pr=3 a=0 h=0 m=31/0/0/0/0
Wed Jul 10 13:52:49 2013 46.207.175.154 255.255.255.255 46.207.175.154 p=0 i=22
t=3 pr=2 a=59 h=0 m=286/0/0/0/0
Wed Jul 10 13:52:49 2013 1.2.3.4 255.255.255.255 46.207.175.154 p=0 i=22 t=3
pr=3 a=0 h=0 m=30/0/0/0/0
Wed Jul 10 13:52:49 2013 127.0.0.0 255.0.0.0 127.0.0.1 p=0 i=1 t=3 pr=2 a=182
h=0 m=4531/0/0/0/0
Wed Jul 10 13:52:49 2013 127.0.0.1 255.255.255.255 127.0.0.1 p=0 i=1 t=3 pr=2
a=182 h=0 m=4531/0/0/0/0
Wed Jul 10 13:52:49 2013 127.255.255.255 255.255.255.255 127.0.0.1 p=0 i=1 t=3
pr=2 a=182 h=0 m=4531/0/0/0/0
Wed Jul 10 13:52:49 2013 128.0.0.0 128.0.0.0 10.100.1.17 p=0 i=22 t=4 pr=3 a=0
h=0 m=31/0/0/0/0
Wed Jul 10 13:52:49 2013 224.0.0.0 240.0.0.0 127.0.0.1 p=0 i=1 t=3 pr=2 a=182
h=0 m=4531/0/0/0/0
Wed Jul 10 13:52:49 2013 224.0.0.0 240.0.0.0 46.207.175.154 p=0 i=22 t=3 pr=3
a=59 h=0 m=31/0/0/0/0
Wed Jul 10 13:52:49 2013 255.255.255.255 255.255.255.255 127.0.0.1 p=0 i=1 t=3
pr=2 a=182 h=0 m=4531/0/0/0/0
Wed Jul 10 13:52:49 2013 255.255.255.255 255.255.255.255 46.207.175.154 p=0
i=22 t=3 pr=2 a=59 h=0 m=286/0/0/0/0
Wed Jul 10 13:52:49 2013 SYSTEM ADAPTER LIST
Wed Jul 10 13:52:49 2013 A1
Wed Jul 10 13:52:49 2013 Index = 22
Wed Jul 10 13:52:49 2013 GUID = {101D13DC-2136-4C00-8BAA-98DDD05D706D}
Wed Jul 10 13:52:49 2013 IP = 46.207.175.154/255.255.255.255
Wed Jul 10 13:52:49 2013 MAC =
Wed Jul 10 13:52:49 2013 GATEWAY = 0.0.0.0/255.255.255.255
Wed Jul 10 13:52:49 2013 PRI WINS = 10.11.12.13/255.255.255.255
Wed Jul 10 13:52:49 2013 SEC WINS = 10.11.12.14/255.255.255.255
Wed Jul 10 13:52:49 2013 DNS SERV = 194.48.139.254/255.255.255.255
194.48.124.200/255.255.255.255
Wed Jul 10 13:52:49 2013 TAP-Windows Adapter V9
Wed Jul 10 13:52:49 2013 Index = 17
Wed Jul 10 13:52:49 2013 GUID = {C0F981D7-4C8D-4EF5-930D-B0A0E3065C4C}
Wed Jul 10 13:52:49 2013 IP = 0.0.0.0/0.0.0.0
Wed Jul 10 13:52:49 2013 MAC = 00:ff:c0:f9:81:d7
Wed Jul 10 13:52:49 2013 GATEWAY = 0.0.0.0/255.255.255.255
Wed Jul 10 13:52:49 2013 DHCP SERV =
Wed Jul 10 13:52:49 2013 DHCP LEASE OBTAINED = Wed Jul 10 13:52:49 2013
Wed Jul 10 13:52:49 2013 DHCP LEASE EXPIRES = Wed Jul 10 13:52:49 2013
Wed Jul 10 13:52:49 2013 DNS SERV =
Wed Jul 10 13:52:49 2013 L1 Gigabit-Ethernet-10/100/1000Base-T-Controller von
Atheros
Wed Jul 10 13:52:49 2013 Index = 12
Wed Jul 10 13:52:49 2013 GUID = {1ECAEA96-70C0-452D-A8A0-53B769462AE0}
Wed Jul 10 13:52:49 2013 IP = 0.0.0.0/0.0.0.0
Wed Jul 10 13:52:49 2013 MAC = 00:1d:60:7f:8a:84
Wed Jul 10 13:52:49 2013 GATEWAY = 0.0.0.0/255.255.255.255
Wed Jul 10 13:52:49 2013 DHCP SERV =
Wed Jul 10 13:52:49 2013 DHCP LEASE OBTAINED = Wed Jul 10 13:52:49 2013
Wed Jul 10 13:52:49 2013 DHCP LEASE EXPIRES = Wed Jul 10 13:52:49 2013
Wed Jul 10 13:52:49 2013 DNS SERV =
Wed Jul 10 13:52:49 2013 Initialization Sequence Completed With Errors ( see
http://openvpn.net/faq.html#dhcpclientserv )
Wed Jul 10 13:52:49 2013 MANAGEMENT:
>STATE:1373457169,CONNECTED,ERROR,10.100.1.18,1.2.3.4------------------------------------------------------------------------------
See everything from the browser to the database with AppDynamics
Get end-to-end visibility with application monitoring from AppDynamics
Isolate bottlenecks and diagnose root cause in seconds.
Start your free trial of AppDynamics Pro today!
http://pubads.g.doubleclick.net/gampad/clk?id=48808831&iu=/4140/ostg.clktrk
_______________________________________________
Openvpn-users mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/openvpn-users
