OpenVPN连接问题排查

2011年9月20日 | 分类: 翻墙相关 | 标签: , ,

OpenVPN相对于PPTP的一大优势,就是有完整的log,可以根据客户端的log来发现无法连接的问题所在。以下为本人的VPN用户经常遇到的问题,希望对其他搭建OpenVPN服务的人有所帮助。

注意:本日志主要用于本人的OpenVPN服务(https://yegle.net/openvpn/)的用户用于自行排查问题用,转载请保留此信息,谢谢:-)

各个平台下OpenVPN连接log所在的位置:

Windows下:如果使用OpenVPN GUI进行连接,默认的log会存放在OpenVPN安装目录下log文件夹。
Linux下:在OpenVPN配置文件中添加一行:log-append /path/to/logfile,连接后/path/to/logfile即为连接log。
Mac OS下:tunnelblick里,Details菜单(感谢@tianyi提供信息:-))
Android下:tunneldroid里,按menu查看log。

OpenVPN的log文件为普通文本文件,可以用各种文本编辑器,例如记事本、写字板、VIM等工具打开。一般情况下为了方便查看问题所在,建议在OpenVPN的配置文件中添加verb 5,可以在log里输出更多有效信息。

正常连接时,log的最后一行是:

Fri Mar 5 09:58:04 2010 Initialization Sequence Completed

这表明OpenVPN成功建立了连接并成功修改了路由表,已经可以正常使用VPN。

问题1:

Mon Mar 01 21:42:13 2010 us=78000 CreateFile failed on TAP device: \\.\Global\{3D3B7076-EC34-48DE-82A4-B34956532951}.tap
Mon Mar 01 21:42:13 2010 us=78000 All TAP-Win32 adapters on this system are currently in use.
Mon Mar 01 21:42:13 2010 us=78000 Exiting

解答:这个问题仅在Windows上出现。原因未知,怀疑与防火墙软件有关。通常情况下可以通过重启系统解决。如果没有解决的话,可以到 OpenVPN安装目录下bin文件夹,依次执行delalltap.bat和addtap.bat,即可解决。注意,如果使用的是Vista/Win7 /Win2003Win2008这样的带UAC的Windows系统,需要用管理员权限执行这两个脚本。

问题2:

Thu Dec 03 22:46:07 2009 us=651000 C:\WINDOWS\system32\route.exe ADD 128.0.0.0 MASK 128.0.0.0 10.7.0.1
Thu Dec 03 22:46:07 2009 us=667000 ROUTE: route addition failed using CreateIpForwardEntry: 拒绝访问。 [status=5 if_index=14]
Thu Dec 03 22:46:07 2009 us=667000 Route addition via IPAPI failed [adaptive]
Thu Dec 03 22:46:07 2009 us=667000 Route addition fallback to route.exe
Thu Dec 03 22:46:07 2009 us=667000 ERROR: Windows route add command failed [adaptive]: returned error code 1

解答:这是在Vista/Win7/Win2003Win2008等系统中没有用管理员权限安装及启动OpenVPN GUI造成的,OpenVPN进程没有相应权限修改系统路由表。解决方法是重新用管理员权限安装OpenVPN,并在启动OpenVPN GUI时右键选择使用管理员权限打开。

问题3:

Mon Feb 1 18:44:52 2010 us=241882 /system/xbin/bb/route add -net 128.0.0.0 netmask 128.0.0.0 gw 10.7.0.1
Mon Feb 1 18:44:52 2010 us=244293 ERROR: Linux route add command failed: could not execute external program
Mon Feb 1 18:44:52 2010 us=244628 Initialization Sequence Completed

解答:这是Android下,Cyanogen Mod和OpenEclair两个ROM,曾经有段时间使用了错误的OpenVPN二进制文件,导致的无法调用busybox添加ip和路由。具体请参考Android上OpenVPN的设置与使用这篇日志,重新安装OpenVPN二进制文件,相应地修复busybox

问题4:

Sat Mar 06 16:31:42 2010 us=107000 There are no TAP-Win32 adapters on this system. You should be able to create a TAP-Win32 adapter by going to Start -> All Programs -> OpenVPN -> Add a new TAP-Win32 virtual ethernet adapter.

解答:这个问题在Windows上发生,原因未知。解决方案如log所述:开始->所有程序->OpenVPN->Add a new TAP-Win32 virtual ethernet adapter。如果是Vista/Win7,用管理员权限执行
(待续)

原文http://yegle.net/2010/03/05/debug-openvpn-log/

  1. 石头
    2011年9月20日21:23

    博主是不是学计算机的呀 感觉在这方面很内行呀

    • iGFW
      2011年9月20日21:42

      不是,专业的东西我基本不懂

  2. 石头
    2011年9月20日21:22

    只有几个端口可用 可以连接

  3. 石头
    2011年9月20日20:57

    莫非是服务器那边的问题 感觉证书认证没通过

    • iGFW
      2011年9月20日21:12

      也许吧,不清楚

  4. 石头
    2011年9月20日20:54

    Tue Sep 20 20:49:46 2011 OpenVPN 2.2.1 Win32-MSVC++ [SSL] [LZO2] built on Jul 1 2011
    Tue Sep 20 20:49:46 2011 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info.
    Tue Sep 20 20:49:46 2011 NOTE: OpenVPN 2.1 requires ‘–script-security 2’ or higher to call user-defined scripts or executables
    Tue Sep 20 20:49:46 2011 Control Channel MTU parms [ L:1541 D:138 EF:38 EB:0 ET:0 EL:0 ]
    Tue Sep 20 20:49:46 2011 Socket Buffers: R=[8192->8192] S=[8192->8192]
    Tue Sep 20 20:49:46 2011 Data Channel MTU parms [ L:1541 D:1450 EF:41 EB:4 ET:0 EL:0 ]
    Tue Sep 20 20:49:46 2011 Local Options hash (VER=V4): ‘3514370b’
    Tue Sep 20 20:49:46 2011 Expected Remote Options hash (VER=V4): ‘239669a8’
    Tue Sep 20 20:49:46 2011 UDPv4 link local: [undef]
    Tue Sep 20 20:49:46 2011 UDPv4 link remote: 108.59.10.152:443
    Tue Sep 20 20:49:46 2011 TLS: Initial packet from 108.59.10.152:443, sid=636694bd 908cd0fe
    Tue Sep 20 20:49:46 2011 WARNING: this configuration may cache passwords in memory — use the auth-nocache option to prevent this
    Tue Sep 20 20:49:48 2011 VERIFY OK: depth=1, /C=FR/ST=FRANCE/L=Paris/O=Real-VPN/CN=Real-VPN_CA/emailAddress=support@real-vpn.co
    Tue Sep 20 20:49:48 2011 VERIFY OK: depth=0, /C=FR/ST=FRANCE/L=Paris/O=Real-VPN/CN=server/emailAddress=support@real-vpn.co
    Tue Sep 20 20:49:50 2011 Data Channel Encrypt: Cipher ‘BF-CBC’ initialized with 128 bit key
    Tue Sep 20 20:49:50 2011 Data Channel Encrypt: Using 160 bit message hash ‘SHA1’ for HMAC authentication
    Tue Sep 20 20:49:50 2011 Data Channel Decrypt: Cipher ‘BF-CBC’ initialized with 128 bit key
    Tue Sep 20 20:49:50 2011 Data Channel Decrypt: Using 160 bit message hash ‘SHA1’ for HMAC authentication
    Tue Sep 20 20:49:50 2011 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
    Tue Sep 20 20:49:50 2011 [server] Peer Connection Initiated with 108.59.10.152:443
    Tue Sep 20 20:49:52 2011 SENT CONTROL [server]: ‘PUSH_REQUEST’ (status=1)
    Tue Sep 20 20:49:52 2011 AUTH: Received AUTH_FAILED control message
    Tue Sep 20 20:49:52 2011 TCP/UDP: Closing socket
    Tue Sep 20 20:49:52 2011 SIGTERM[soft,auth-failure] received, process exiting

    这个应该是什么原因 用443端口不行 用80就可以