天天看点

卧槽,VPN又断开了!!

问题定位

排查了各种问题,包括:网络、服务、数据库、服务器资源占用,结果都没啥问题。于是我把目标瞄准到了VPN,为啥要确定是否是VPN的问题呢?因为服务A和服务B不在同一个网段内,服务A调用服务B是通过VPN连接的。

于是我先看了下VPN客户端的信息,如下所示。

Tue Jun 15 22:19:59 2021 OpenVPN 2.4.9 x86_64-redhat-linux-gnu [Fedora EPEL patched] [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Apr 24 2020
Tue Jun 15 22:19:59 2021 library versions: OpenSSL 1.0.2k-fips  26 Jan 2017, LZO 2.06
Tue Jun 15 22:19:59 2021 WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.
Tue Jun 15 22:19:59 2021 TCP/UDP: Preserving recently used remote address: [AF_INET]xxx.xxx.xxx.xxx:1194
Tue Jun 15 22:19:59 2021 Socket Buffers: R=[87380->87380] S=[16384->16384]
Tue Jun 15 22:19:59 2021 Attempting to establish TCP connection with [AF_INET]xxx.xxx.xxx.xxx:1194 [nonblock]
Tue Jun 15 22:20:00 2021 TCP connection established with [AF_INET]xxx.xxx.xxx.xxx:1194
Tue Jun 15 22:20:00 2021 TCP_CLIENT link local: (not bound)
Tue Jun 15 22:20:00 2021 TCP_CLIENT link remote: [AF_INET]xxx.xxx.xxx.xxx:1194
Tue Jun 15 22:20:00 2021 TLS: Initial packet from [AF_INET]xxx.xxx.xxx.xxx:1194, sid=500dc68d 98cc6b0a
Tue Jun 15 22:20:00 2021 VERIFY OK: depth=1, CN=xxxx.com
Tue Jun 15 22:20:00 2021 VERIFY OK: depth=0, CN=xxxx.com
Tue Jun 15 22:20:00 2021 Connection reset, restarting [0]
Tue Jun 15 22:20:00 2021 SIGUSR1[soft,connection-reset] received, process restarting
Tue Jun 15 22:20:00 2021 Restart pause, 5 second(s)      
卧槽,VPN又断开了!!

在VPN客户端输出的日志信息中,存在如下一行信息。

Tue Jun 15 22:19:59 2021 WARNING: No server certificate verification method has been enabled.  See http://openvpn.net/howto.html#mitm for more info.      

再来看VPN服务端的日志信息,如下所示。

Tue Jun 15 22:51:22 2021 TCP connection established with [AF_INET]125.71.159.19:42744
Tue Jun 15 22:51:23 2021 125.71.159.19:42744 TLS: Initial packet from [AF_INET]125.71.159.19:42744, sid=a64a2771 594d7351
Tue Jun 15 22:51:23 2021 125.71.159.19:42744 WARNING: Failed to stat CRL file, not (re)loading CRL.
Tue Jun 15 22:51:23 2021 125.71.159.19:42744 VERIFY ERROR: depth=0, error=CRL has expired: CN=client01
Tue Jun 15 22:51:23 2021 125.71.159.19:42744 OpenSSL: error:14089086:SSL routines:ssl3_get_client_certificate:certificate verify failed
Tue Jun 15 22:51:23 2021 125.71.159.19:42744 TLS_ERROR: BIO read tls_read_plaintext error
Tue Jun 15 22:51:23 2021 125.71.159.19:42744 TLS Error: TLS object -> incoming plaintext read error
Tue Jun 15 22:51:23 2021 125.71.159.19:42744 TLS Error: TLS handshake failed
Tue Jun 15 22:51:23 2021 125.71.159.19:42744 Fatal TLS error (check_tls_errors_co), restarting
Tue Jun 15 22:51:23 2021 125.71.159.19:42744 SIGUSR1[soft,tls-error] received, client-instance restarting      
卧槽,VPN又断开了!!

在VPN服务端的输出信息中,存在如下一行信息。

Tue Jun 15 22:51:23 2021 125.71.159.19:42744 VERIFY ERROR: depth=0, error=CRL has expired: CN=client01      

VPN的客户端和服务端都输出了对应的错误日志信息,基本可以定位到时VPN的问题了。那么,问题来了,具体是什么问题呢?我们继续往下分析。

造成VPN连接失败往往有如下几种原因:

  • 客户端与服务端时间不一致,也就是说VPN服务端所在的服务器和VPN客户端所在的服务器时间不一致。
  • 证书过期。
  • CRL证书过期。

这里,我们可以通过VPN服务端输出的日志信息中的如下信息

Tue Jun 15 22:51:23 2021 125.71.159.19:42744 VERIFY ERROR: depth=0, error=CRL has expired: CN=client01      

看到

error=CRL has expired

,看来是CRL证书过期了。

到这里,我们就定位到具体问题了,定位到问题就好办了,接下来,就是要解决问题了。

问题验证

前面我们已经通过

error=CRL has expired

,定位到时CRL证书过期引起的VPN不能访问了。如何解决呢?其实很简单,我们继续往下看。

这里,我们需要找到OpenVPN配置文件目录下的easyrsa文件,例如,我这里的easyrsa文件的目录为

/etc/openvpn/easy-rsa/3/easyrsa

打开这个文件,找到如下信息。

set_var EASYRSA_CA_EXPIRE       3650
set_var EASYRSA_CERT_EXPIRE     825 # new default of 36 months  
set_var EASYRSA_CERT_RENEW      30
set_var EASYRSA_CRL_DAYS        180      
卧槽,VPN又断开了!!

可以看到CRL证书的过期时间为180天。而我,差不多也是在半年前左右安装并配置的VPN,这里也再次验证了确实是CRL证书过期引起的问题。

问题解决

只要定位和明确了问题,就比较好解决了。这里,主要有两种解决方案:

  • OpenVPN 2.4新证书撤销列表法。
  • 注释掉VPN配置文件的CRL证书选项。

OpenVPN 2.4新证书撤销列表法

这种方法需要执行命令重新生成CRL证书,如下所示。

cd /vpn根目录
./easyrsa gen-crl #使用EasyRSA的CRL生成新的CRL证书      

例如,针对我这里的环境,我执行了如下命令。

cd /etc/openvpn/easy-rsa/3/
./easyrsa gen-crl      

注释掉VPN配置文件的CRL证书选项

这种方式只需要将VPN服务端的配置文件server.conf中关于CRL证书的选项注释掉,例如,我这里执行的命令如下。

vim /etc/openvpn/server.conf      

找到如下代码行,并将其注释掉。

crl-verify /etc/openvpn/server/crl.pem      

如下所示。

卧槽,VPN又断开了!!

验证解决方案

问题解决后,我们再次启动VPN服务端和客户端,发现VPN服务端输出了如下的日志信息。

Tue Jun 15 23:03:28 2021 client01/125.71.159.19:42748 Connection reset, restarting [0]
Tue Jun 15 23:03:28 2021 client01/125.71.159.19:42748 SIGUSR1[soft,connection-reset] received, client-instance restarting
Tue Jun 15 23:03:54 2021 TCP connection established with [AF_INET]125.71.159.19:42750
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 TLS: Initial packet from [AF_INET]125.71.159.19:42750, sid=f7bb2dcd 605146c3
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 VERIFY OK: depth=1, CN=xxxx.com
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 VERIFY OK: depth=0, CN=client01
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 peer info: IV_VER=2.4.9
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 peer info: IV_PLAT=linux
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 peer info: IV_PROTO=2
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 peer info: IV_NCP=2
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 peer info: IV_LZ4=1
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 peer info: IV_LZ4v2=1
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 peer info: IV_LZO=1
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 peer info: IV_COMP_STUB=1
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 peer info: IV_COMP_STUBv2=1
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 peer info: IV_TCPNL=1
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Tue Jun 15 23:03:55 2021 125.71.159.19:42750 [client01] Peer Connection Initiated with [AF_INET]125.71.159.19:42750
Tue Jun 15 23:03:55 2021 client01/125.71.159.19:42750 MULTI_sva: pool returned IPv4=10.3.31.6, IPv6=(Not enabled)
Tue Jun 15 23:03:55 2021 client01/125.71.159.19:42750 MULTI: Learn: 10.3.31.6 -> client01/125.71.159.19:42750
Tue Jun 15 23:03:55 2021 client01/125.71.159.19:42750 MULTI: primary virtual IP for client01/125.71.159.19:42750: 10.3.31.6
Tue Jun 15 23:03:56 2021 client01/125.71.159.19:42750 PUSH: Received control message: 'PUSH_REQUEST'
Tue Jun 15 23:03:56 2021 client01/125.71.159.19:42750 SENT CONTROL [client01]: 'PUSH_REPLY,redirect-gateway def1,dhcp-option DNS 84.200.69.80,dhcp-option DNS 84.200.70.40,route 10.3.31.1,topology net30,ping 20,ping-restart 60,ifconfig 10.3.31.6 10.3.31.5,peer-id 0,cipher AES-256-GCM' (status=1)
Tue Jun 15 23:03:56 2021 client01/125.71.159.19:42750 Data Channel: using negotiated cipher 'AES-256-GCM'
Tue Jun 15 23:03:56 2021 client01/125.71.159.19:42750 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Tue Jun 15 23:03:56 2021 client01/125.71.159.19:42750 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key      
卧槽,VPN又断开了!!

此时,再次通过VPN客户端服务器向VPN服务端服务器发送请求,连接就成功了。服务A调用服务B也成功了。

至此,整个问题就解决完了。