Bug #13722
closedOpenVPN connection fail after service restart
0%
Description
I am using OPenVPN client. When service is started from Status -> OpenVPN (stop, then start) I always getting "TLS Error: TLS handshake failed" connection error.
But if I go to VPN -> OpenVPN -> Clients -> Edit connection -> Save (without any changes) it connects immediately without problem.
I suspect service is not reading config file properly (or multiple configs), but if profile has been saved start sequence reads all of them
pfsense v. 2.6.0-RELEASE
fail after service start:
Dec 5 13:39:31 openvpn 11695 SIGTERM[hard,init_instance] received, process exiting Dec 5 13:39:27 openvpn 11695 Restart pause, 5 second(s) Dec 5 13:39:27 openvpn 11695 SIGUSR1[soft,tls-error] received, process restarting Dec 5 13:39:27 openvpn 11695 TLS Error: TLS handshake failed Dec 5 13:39:27 openvpn 11695 TLS Error: TLS object -> incoming plaintext read error Dec 5 13:39:27 openvpn 11695 TLS_ERROR: BIO read tls_read_plaintext error Dec 5 13:39:27 openvpn 11695 OpenSSL: error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed Dec 5 13:39:27 openvpn 11695 VERIFY KU ERROR Dec 5 13:39:27 openvpn 11695 Certificate does not have key usage extension Dec 5 13:39:27 openvpn 11695 VERIFY OK: depth=1, CN=OpenVPN CA Dec 5 13:39:27 openvpn 11695 VERIFY WARNING: depth=1, unable to get certificate CRL: CN=OpenVPN CA Dec 5 13:39:27 openvpn 11695 VERIFY WARNING: depth=0, unable to get certificate CRL: CN=OpenVPN Server Dec 5 13:39:27 openvpn 11695 TLS: Initial packet from [AF_INET]XXX.XXX.XXX.XXX:1194, sid=23694d68 3d4a11bf Dec 5 13:39:27 openvpn 11695 UDPv4 link remote: [AF_INET]XXX.XXX.XXX.XXX:1194 Dec 5 13:39:27 openvpn 11695 UDPv4 link local (bound): [AF_INET]YYY.YYY.YYY.YYY:0 Dec 5 13:39:27 openvpn 11695 Socket Buffers: R=[42080->42080] S=[57344->57344] Dec 5 13:39:27 openvpn 11695 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:1194 Dec 5 13:39:27 openvpn 11695 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication Dec 5 13:39:27 openvpn 11695 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication Dec 5 13:39:27 openvpn 11695 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts Dec 5 13:39:22 openvpn 11695 Restart pause, 5 second(s) Dec 5 13:39:22 openvpn 11695 SIGUSR1[soft,tls-error] received, process restarting Dec 5 13:39:22 openvpn 11695 TLS Error: TLS handshake failed Dec 5 13:39:22 openvpn 11695 TLS Error: TLS object -> incoming plaintext read error Dec 5 13:39:22 openvpn 11695 TLS_ERROR: BIO read tls_read_plaintext error Dec 5 13:39:22 openvpn 11695 OpenSSL: error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed Dec 5 13:39:22 openvpn 11695 VERIFY KU ERROR Dec 5 13:39:22 openvpn 11695 Certificate does not have key usage extension Dec 5 13:39:22 openvpn 11695 VERIFY OK: depth=1, CN=OpenVPN CA Dec 5 13:39:22 openvpn 11695 VERIFY WARNING: depth=1, unable to get certificate CRL: CN=OpenVPN CA Dec 5 13:39:22 openvpn 11695 VERIFY WARNING: depth=0, unable to get certificate CRL: CN=OpenVPN Server Dec 5 13:39:21 openvpn 11695 TLS: Initial packet from [AF_INET]XXX.XXX.XXX.XXX:1194, sid=94971a21 3da7ec5e Dec 5 13:39:21 openvpn 11695 UDPv4 link remote: [AF_INET]XXX.XXX.XXX.XXX:1194 Dec 5 13:39:21 openvpn 11695 UDPv4 link local (bound): [AF_INET]YYY.YYY.YYY.YYY:0 Dec 5 13:39:21 openvpn 11695 Socket Buffers: R=[42080->42080] S=[57344->57344] Dec 5 13:39:21 openvpn 11695 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:1194 Dec 5 13:39:21 openvpn 11695 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication Dec 5 13:39:21 openvpn 11695 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication Dec 5 13:39:21 openvpn 11695 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts Dec 5 13:39:20 openvpn 11695 MANAGEMENT: Client disconnected Dec 5 13:39:20 openvpn 11695 MANAGEMENT: CMD 'state 1' Dec 5 13:39:20 openvpn 11695 MANAGEMENT: Client connected from /var/etc/openvpn/client1/sock Dec 5 13:39:16 openvpn 11695 Restart pause, 5 second(s) Dec 5 13:39:16 openvpn 11695 SIGUSR1[soft,tls-error] received, process restarting Dec 5 13:39:16 openvpn 11695 TLS Error: TLS handshake failed Dec 5 13:39:16 openvpn 11695 TLS Error: TLS object -> incoming plaintext read error Dec 5 13:39:16 openvpn 11695 TLS_ERROR: BIO read tls_read_plaintext error Dec 5 13:39:16 openvpn 11695 OpenSSL: error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed Dec 5 13:39:16 openvpn 11695 VERIFY KU ERROR Dec 5 13:39:16 openvpn 11695 Certificate does not have key usage extension Dec 5 13:39:16 openvpn 11695 VERIFY OK: depth=1, CN=OpenVPN CA Dec 5 13:39:16 openvpn 11695 VERIFY WARNING: depth=1, unable to get certificate CRL: CN=OpenVPN CA Dec 5 13:39:16 openvpn 11695 VERIFY WARNING: depth=0, unable to get certificate CRL: CN=OpenVPN Server Dec 5 13:39:15 openvpn 11695 TLS: Initial packet from [AF_INET]XXX.XXX.XXX.XXX:1194, sid=54a533b8 4acb7ccc Dec 5 13:39:15 openvpn 11695 UDPv4 link remote: [AF_INET]XXX.XXX.XXX.XXX:1194 Dec 5 13:39:15 openvpn 11695 UDPv4 link local (bound): [AF_INET]YYY.YYY.YYY.YYY:0 Dec 5 13:39:15 openvpn 11695 Socket Buffers: R=[42080->42080] S=[57344->57344] Dec 5 13:39:15 openvpn 11695 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:1194 Dec 5 13:39:15 openvpn 11695 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication Dec 5 13:39:15 openvpn 11695 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication Dec 5 13:39:15 openvpn 11695 WARNING: experimental option --capath /var/etc/openvpn/client1/ca Dec 5 13:39:15 openvpn 11695 Initializing OpenSSL support for engine 'rdrand' Dec 5 13:39:15 openvpn 11695 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts Dec 5 13:39:15 openvpn 11695 MANAGEMENT: unix domain socket listening on /var/etc/openvpn/client1/sock Dec 5 13:39:15 openvpn 11646 library versions: OpenSSL 1.1.1l-freebsd 24 Aug 2021, LZO 2.10 Dec 5 13:39:15 openvpn 11646 OpenVPN 2.5.4 amd64-portbld-freebsd12.3 [SSL (OpenSSL)] [LZO] [LZ4] [MH/RECVDA] [AEAD] built on Jan 12 2022
success after edit/save connection:
Dec 5 13:39:39 openvpn 37140 Initialization Sequence Completed Dec 5 13:39:34 openvpn 37140 MANAGEMENT: Client disconnected Dec 5 13:39:34 openvpn 37140 MANAGEMENT: CMD 'state 1' Dec 5 13:39:34 openvpn 37140 MANAGEMENT: Client connected from /var/etc/openvpn/client1/sock Dec 5 13:39:33 openvpn 37140 /usr/local/sbin/ovpn-linkup ovpnc1 1500 1624 172.27.232.14 255.255.248.0 init Dec 5 13:39:33 openvpn 37140 /sbin/route add -net 172.27.232.0 172.27.232.1 255.255.248.0 Dec 5 13:39:33 openvpn 37140 /sbin/ifconfig ovpnc1 172.27.232.14 172.27.232.1 mtu 1500 netmask 255.255.248.0 up Dec 5 13:39:33 openvpn 37140 TUN/TAP device /dev/tun1 opened Dec 5 13:39:33 openvpn 37140 TUN/TAP device ovpnc1 exists previously, keep at program end Dec 5 13:39:33 openvpn 37140 Incoming Data Channel: Using 160 bit message hash 'SHA1' for HMAC authentication Dec 5 13:39:33 openvpn 37140 Incoming Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key Dec 5 13:39:33 openvpn 37140 Outgoing Data Channel: Using 160 bit message hash 'SHA1' for HMAC authentication Dec 5 13:39:33 openvpn 37140 Outgoing Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key Dec 5 13:39:33 openvpn 37140 Using peer cipher 'AES-256-CBC' Dec 5 13:39:33 openvpn 37140 OPTIONS IMPORT: adjusting link_mtu to 1624 Dec 5 13:39:33 openvpn 37140 OPTIONS IMPORT: peer-id set Dec 5 13:39:33 openvpn 37140 OPTIONS IMPORT: route-related options modified Dec 5 13:39:33 openvpn 37140 OPTIONS IMPORT: --ifconfig/up options modified Dec 5 13:39:33 openvpn 37140 OPTIONS IMPORT: compression parms modified Dec 5 13:39:33 openvpn 37140 OPTIONS IMPORT: explicit notify parm(s) modified Dec 5 13:39:33 openvpn 37140 OPTIONS IMPORT: timers and/or timeouts modified Dec 5 13:39:33 openvpn 37140 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this Dec 5 13:39:33 openvpn 37140 Options error: option 'block-ipv6' cannot be used in this context ([PUSH-OPTIONS]) Dec 5 13:39:33 openvpn 37140 Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:17: register-dns (2.5.4) Dec 5 13:39:33 openvpn 37140 Options error: option 'dhcp-option' cannot be used in this context ([PUSH-OPTIONS]) Dec 5 13:39:33 openvpn 37140 Options error: option 'dhcp-option' cannot be used in this context ([PUSH-OPTIONS]) Dec 5 13:39:33 openvpn 37140 Options error: option 'redirect-gateway' cannot be used in this context ([PUSH-OPTIONS]) Dec 5 13:39:33 openvpn 37140 Options error: option 'redirect-gateway' cannot be used in this context ([PUSH-OPTIONS]) Dec 5 13:39:33 openvpn 37140 Options error: option 'redirect-gateway' cannot be used in this context ([PUSH-OPTIONS]) Dec 5 13:39:33 openvpn 37140 Options error: option 'route-metric' cannot be used in this context ([PUSH-OPTIONS]) Dec 5 13:39:33 openvpn 37140 Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:6: dhcp-release (2.5.4) Dec 5 13:39:33 openvpn 37140 Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:5: dhcp-renew (2.5.4) Dec 5 13:39:33 openvpn 37140 Options error: Unrecognized option or missing or extra parameter(s) in [PUSH-OPTIONS]:4: dhcp-pre-release (2.5.4) Dec 5 13:39:33 openvpn 37140 PUSH: Received control message: 'PUSH_REPLY,explicit-exit-notify,topology subnet,route-delay 5 30,dhcp-pre-release,dhcp-renew,dhcp-release,route-metric 101,ping 12,ping-restart 50,compress stub-v2,redirect-gateway def1,redirect-gateway bypass-dhcp,redirect-gateway autolocal,route-gateway 172.27.232.1,dhcp-option DNS 8.8.8.8,dhcp-option DNS 8.8.4.4,register-dns,block-ipv6,ifconfig 172.27.232.14 255.255.248.0,peer-id 9,auth-tokenSESS_ID' Dec 5 13:39:33 openvpn 37140 SENT CONTROL [OpenVPN Server]: 'PUSH_REQUEST' (status=1) Dec 5 13:39:32 openvpn 37140 [OpenVPN Server] Peer Connection Initiated with [AF_INET]XXX.XXX.XXX.XXX:1194 Dec 5 13:39:32 openvpn 37140 Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, peer certificate: 2048 bit RSA, signature: RSA-SHA256 Dec 5 13:39:32 openvpn 37140 WARNING: 'comp-lzo' is present in remote config but missing in local config, remote='comp-lzo' Dec 5 13:39:32 openvpn 37140 WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1557', remote='link-mtu 1558' Dec 5 13:39:32 openvpn 37140 VERIFY OK: depth=0, CN=OpenVPN Server Dec 5 13:39:32 openvpn 37140 VERIFY OK: depth=1, CN=OpenVPN CA Dec 5 13:39:32 openvpn 37140 VERIFY WARNING: depth=1, unable to get certificate CRL: CN=OpenVPN CA Dec 5 13:39:32 openvpn 37140 VERIFY WARNING: depth=0, unable to get certificate CRL: CN=OpenVPN Server Dec 5 13:39:31 openvpn 37140 TLS: Initial packet from [AF_INET]XXX.XXX.XXX.XXX:1194, sid=fbb809f4 f355a4d8 Dec 5 13:39:31 openvpn 37140 UDPv4 link remote: [AF_INET]XXX.XXX.XXX.XXX:1194 Dec 5 13:39:31 openvpn 37140 UDPv4 link local (bound): [AF_INET]YYY.YYY.YYY.YYY:0 Dec 5 13:39:31 openvpn 37140 Socket Buffers: R=[42080->42080] S=[57344->57344] Dec 5 13:39:31 openvpn 37140 TCP/UDP: Preserving recently used remote address: [AF_INET]XXX.XXX.XXX.XXX:1194 Dec 5 13:39:31 openvpn 37140 Incoming Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication Dec 5 13:39:31 openvpn 37140 Outgoing Control Channel Authentication: Using 160 bit message hash 'SHA1' for HMAC authentication Dec 5 13:39:31 openvpn 37140 WARNING: experimental option --capath /var/etc/openvpn/client1/ca Dec 5 13:39:31 openvpn 37140 Initializing OpenSSL support for engine 'rdrand' Dec 5 13:39:31 openvpn 37140 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts Dec 5 13:39:31 openvpn 37140 WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info. Dec 5 13:39:31 openvpn 37140 MANAGEMENT: unix domain socket listening on /var/etc/openvpn/client1/sock Dec 5 13:39:31 openvpn 36962 library versions: OpenSSL 1.1.1l-freebsd 24 Aug 2021, LZO 2.10 Dec 5 13:39:31 openvpn 36962 OpenVPN 2.5.4 amd64-portbld-freebsd12.3 [SSL (OpenSSL)] [LZO] [LZ4] [MH/RECVDA] [AEAD] built on Jan 12 2022
Updated by Jim Pingle over 2 years ago
- Status changed from New to Not a Bug
I can't reproduce that problem as stated. Edit/Save does sometimes take actions the service restart does not, but if that makes a difference then it's likely you have some other issue causing the problem. This site is not for support or diagnostic discussion to locate the problem with your environment, however.
For assistance in solving problems, please post on the Netgate Forum .
See Reporting Issues with pfSense Software for more information.