ssh timeouts (does not appear to be MTU)

Need help configuring your VPN? Just post here and you'll get that help.
Forum rules
Please use the [oconf] BB tag for openvpn Configurations. See viewtopic.php?f=30&t=21589 for an example.
Post Reply
wayne_ovpn
OpenVpn Newbie
Posts: 6
Joined: Tue May 19, 2020 4:56 pm

ssh timeouts (does not appear to be MTU)

Post by wayne_ovpn » Tue May 19, 2020 5:20 pm

I'm getting ssh timeouts from a client after ~55 seconds due to OpenVPN on one of my links. I do not think it's MTU because it happens even with no traffic going across the link, just sitting at a shell prompt after login.

Code: Select all

FreeBSD client---EdgeRouter 1 (OpenVPN version 2.4.0)---FreeBSD server #1 (OpenVPN version 2.4.8)   Fails
FreeBSD client------------------------------------------FreeBSD server #1 (via public IP)           Works
FreeBSD client---Edgerouter 2 (Openvpn version 2.3.2)---FreeBSD server #2 (Openvpn version 2.4.4)   Works
In all of the above the client is the same.

I've tried mssfix and fragment with no improvement. Adding ServerAliveInterval and/or TCPKeepAlive to ssh config does not help.

Any suggestions on how to debug this?

User avatar
TinCanTech
OpenVPN Protagonist
Posts: 7604
Joined: Fri Jun 03, 2016 1:17 pm

Re: ssh timeouts (does not appear to be MTU)

Post by TinCanTech » Tue May 19, 2020 5:39 pm


wayne_ovpn
OpenVpn Newbie
Posts: 6
Joined: Tue May 19, 2020 4:56 pm

Re: ssh timeouts (does not appear to be MTU)

Post by wayne_ovpn » Tue May 19, 2020 6:06 pm

Client config
port 1194
dev tun
ifconfig-pool-persist ipp.txt
keepalive 10 120
cipher AES-256-CBC
persist-key
persist-tun
verb 3
explicit-exit-notify 1
local <SERVER PUBLIC IP ADDRESS>
proto udp4
mode server
tls-server
ca ca.crt
cert r4-server.crt
key r4-server.key
dh dh.pem
tls-auth r4-ta.key 0
topology subnet
server 172.16.6.0 255.255.255.0
push "route <Subnet on server> 255.255.255.224"
status /var/log/openvpn/openvpn-status.log
log-append /var/log/openvpn/openvpn.log
client-config-dir /usr/local/etc/openvpn/ccd
verb 3
route <CLIENT NET> 255.255.255.128 172.16.6.3
client-to-client
push "route <CLIENT NET> 255.255.255.128"
mtu-test # Added for testing
remote-cert-tls client


Client config
client
proto udp
remote <SERVER PUBLIC IP ADDRESS>
# udp port
port 1194
dev tun
nobind
cipher AES-256-CBC
user nobody
group nogroup
persist-key
persist-tun
key-direction 1
remote-cert-tls server
<ca>
</ca>
<cert>
</cert>
<key>
</key>
<tls-auth>
</tls-auth>
Last edited by Pippin on Tue May 19, 2020 6:13 pm, edited 1 time in total.
Reason: Formatting

User avatar
TinCanTech
OpenVPN Protagonist
Posts: 7604
Joined: Fri Jun 03, 2016 1:17 pm

Re: ssh timeouts (does not appear to be MTU)

Post by TinCanTech » Tue May 19, 2020 8:54 pm

  • Your server log file at --verb 4
    Which means put the words "verb 4" into your configuration file and restart your server
    Please use BBCODE [code]
  • Your client log file at --verb 4
    Which means put the words "verb 4" into your configuration file and restart your client
    Please use BBCODE [code]

wayne_ovpn
OpenVpn Newbie
Posts: 6
Joined: Tue May 19, 2020 4:56 pm

Re: ssh timeouts (does not appear to be MTU)

Post by wayne_ovpn » Wed May 27, 2020 6:04 pm

Server log with verb 4

Code: Select all

Wed May 27 13:39:09 2020 CLIENT.IP:38952 TLS: Initial packet from [AF_INET]CLIENT.IP:38952, sid=a9559d13 31e68fc7
Wed May 27 13:39:10 2020 CLIENT.IP:38952 VERIFY OK: depth=1, CN=SERVER.name
Wed May 27 13:39:10 2020 CLIENT.IP:38952 VERIFY KU OK
Wed May 27 13:39:10 2020 CLIENT.IP:38952 Validating certificate extended key usage
Wed May 27 13:39:10 2020 CLIENT.IP:38952 ++ Certificate has EKU (str) TLS Web Client Authentication, expects TLS Web Client Authentication
Wed May 27 13:39:10 2020 CLIENT.IP:38952 VERIFY EKU OK
Wed May 27 13:39:10 2020 CLIENT.IP:38952 VERIFY OK: depth=0, CN=scu1-r4-client
Wed May 27 13:39:10 2020 CLIENT.IP:38952 peer info: IV_VER=2.4.0
Wed May 27 13:39:10 2020 CLIENT.IP:38952 peer info: IV_PLAT=linux
Wed May 27 13:39:10 2020 CLIENT.IP:38952 peer info: IV_PROTO=2
Wed May 27 13:39:10 2020 CLIENT.IP:38952 peer info: IV_NCP=2
Wed May 27 13:39:10 2020 CLIENT.IP:38952 peer info: IV_LZ4=1
Wed May 27 13:39:10 2020 CLIENT.IP:38952 peer info: IV_LZ4v2=1
Wed May 27 13:39:10 2020 CLIENT.IP:38952 peer info: IV_LZO=1
Wed May 27 13:39:10 2020 CLIENT.IP:38952 peer info: IV_COMP_STUB=1
Wed May 27 13:39:10 2020 CLIENT.IP:38952 peer info: IV_COMP_STUBv2=1
Wed May 27 13:39:10 2020 CLIENT.IP:38952 peer info: IV_TCPNL=1
Wed May 27 13:39:10 2020 CLIENT.IP:38952 Control Channel: TLSv1.2, cipher TLSv1.2 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
Wed May 27 13:39:10 2020 CLIENT.IP:38952 [scu1-r4-client] Peer Connection Initiated with [AF_INET]CLIENT.IP:38952
Wed May 27 13:39:10 2020 MULTI: new connection by client 'scu1-r4-client' will cause previous active sessions by this client to be dropped.  Remember to use the --duplicate-cn option if you want multiple clients using the same certificate or username to concurrently connect.
Wed May 27 13:39:10 2020 OPTIONS IMPORT: reading client specific options from: /usr/local/etc/openvpn/ccd/scu1-r4-client
Wed May 27 13:39:10 2020 MULTI: Learn: 172.16.6.3 -> scu1-r4-client/CLIENT.IP:38952
Wed May 27 13:39:10 2020 MULTI: primary virtual IP for scu1-r4-client/CLIENT.IP:38952: 172.16.6.3
Wed May 27 13:39:10 2020 MULTI: internal route CLIENT.net/25 -> scu1-r4-client/CLIENT.IP:38952
Wed May 27 13:39:10 2020 MULTI: Learn: CLIENT.net/25 -> scu1-r4-client/CLIENT.IP:38952
Wed May 27 13:39:10 2020 REMOVE PUSH ROUTE: 'route CLIENT.net 255.255.255.128'
Wed May 27 13:39:11 2020 scu1-r4-client/CLIENT.IP:38952 PUSH: Received control message: 'PUSH_REQUEST'
Wed May 27 13:39:11 2020 scu1-r4-client/CLIENT.IP:38952 SENT CONTROL [scu1-r4-client]: 'PUSH_REPLY,route SERVER.net 255.255.255.224,route-gateway 172.16.6.1,topology subnet,ping 10,ping-restart 120,ifconfig 172.16.6.3 255.255.255.0,peer-id 1,cipher AES-256-GCM' (status=1)
Wed May 27 13:39:11 2020 scu1-r4-client/CLIENT.IP:38952 Data Channel: using negotiated cipher 'AES-256-GCM'
Wed May 27 13:39:11 2020 scu1-r4-client/CLIENT.IP:38952 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed May 27 13:39:11 2020 scu1-r4-client/CLIENT.IP:38952 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Wed May 27 13:39:24 2020 scu1-r4-client/CLIENT.IP:38952 MULTI: Learn: WORKSTATION.IP -> scu1-r4-client/CLIENT.IP:38952
Client log with verb 4

Code: Select all

May 27 13:39:04 scu1 openvpn[4819]: SIGUSR1[soft,tls-error] received, process restarting
May 27 13:39:04 scu1 openvpn[4819]: Restart pause, 5 second(s)
May 27 13:39:09 scu1 openvpn[4819]: Re-using SSL/TLS context
May 27 13:39:09 scu1 openvpn[4819]: Control Channel MTU parms [ L:1621 D:1184 EF:66 EB:0 ET:0 EL:3 ]
May 27 13:39:09 scu1 openvpn[4819]: Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
May 27 13:39:09 scu1 openvpn[4819]: Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1557,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
May 27 13:39:09 scu1 openvpn[4819]: Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1557,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
May 27 13:39:09 scu1 openvpn[4819]: TCP/UDP: Preserving recently used remote address: [AF_INET]SERVER.IP:1194
May 27 13:39:09 scu1 openvpn[4819]: Socket Buffers: R=[294912->294912] S=[294912->294912]
May 27 13:39:09 scu1 openvpn[4819]: UDP link local: (not bound)
May 27 13:39:09 scu1 openvpn[4819]: UDP link remote: [AF_INET]SERVER.IP:1194
May 27 13:39:09 scu1 openvpn[4819]: TLS: Initial packet from [AF_INET]SERVER.IP:1194, sid=59e5f2cc 8a64390b
May 27 13:39:09 scu1 openvpn[4819]: VERIFY OK: depth=1, CN=SERVER.name
May 27 13:39:09 scu1 openvpn[4819]: Validating certificate key usage
May 27 13:39:09 scu1 openvpn[4819]: ++ Certificate has key usage  00a0, expects 00a0
May 27 13:39:09 scu1 openvpn[4819]: VERIFY KU OK
May 27 13:39:09 scu1 openvpn[4819]: Validating certificate extended key usage
May 27 13:39:09 scu1 openvpn[4819]: ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
May 27 13:39:09 scu1 openvpn[4819]: VERIFY EKU OK
May 27 13:39:09 scu1 openvpn[4819]: VERIFY OK: depth=0, CN=r4-server
May 27 13:39:10 scu1 openvpn[4819]: Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
May 27 13:39:10 scu1 openvpn[4819]: [r4-server] Peer Connection Initiated with [AF_INET]SERVER.IP:1194
May 27 13:39:11 scu1 openvpn[4819]: SENT CONTROL [r4-server]: 'PUSH_REQUEST' (status=1)
May 27 13:39:11 scu1 openvpn[4819]: PUSH: Received control message: 'PUSH_REPLY,route SERVER.net 255.255.255.224,route-gateway 172.16.6.1,topology subnet,ping 10,ping-restart 120,ifconfig 172.16.6.3 255.255.255.0,peer-id 1,cipher AES-256-GCM'
May 27 13:39:11 scu1 openvpn[4819]: OPTIONS IMPORT: timers and/or timeouts modified
May 27 13:39:11 scu1 openvpn[4819]: OPTIONS IMPORT: --ifconfig/up options modified
May 27 13:39:11 scu1 openvpn[4819]: OPTIONS IMPORT: route options modified
May 27 13:39:11 scu1 openvpn[4819]: OPTIONS IMPORT: route-related options modified
May 27 13:39:11 scu1 openvpn[4819]: OPTIONS IMPORT: peer-id set
May 27 13:39:11 scu1 openvpn[4819]: OPTIONS IMPORT: adjusting link_mtu to 1624
May 27 13:39:11 scu1 openvpn[4819]: OPTIONS IMPORT: data channel crypto options modified
May 27 13:39:11 scu1 openvpn[4819]: Data Channel MTU parms [ L:1552 D:1450 EF:52 EB:406 ET:0 EL:3 ]
May 27 13:39:11 scu1 openvpn[4819]: Data Channel Encrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
May 27 13:39:11 scu1 openvpn[4819]: Data Channel Decrypt: Cipher 'AES-256-GCM' initialized with 256 bit key
May 27 13:39:11 scu1 openvpn[4819]: ROUTE_GATEWAY CLIENT.net/255.255.255.128 IFACE=eth2 HWADDR=80:2a:a8:8f:3f:d4
May 27 13:39:11 scu1 openvpn[4819]: TUN/TAP device vtun4 opened
May 27 13:39:11 scu1 openvpn[4819]: TUN/TAP TX queue length set to 100
May 27 13:39:11 scu1 openvpn[4819]: do_ifconfig, tt->did_ifconfig_ipv6_setup=0
May 27 13:39:11 scu1 openvpn[4819]: /sbin/ip link set dev vtun4 up mtu 1500
May 27 13:39:11 scu1 openvpn[4819]: /sbin/ip addr add dev vtun4 172.16.6.3/24 broadcast 172.16.6.255
May 27 13:39:11 scu1 openvpn[4819]: /sbin/ip route add SERVER.net/27 via 172.16.6.1
May 27 13:39:11 scu1 openvpn[4819]: GID set to nogroup
May 27 13:39:11 scu1 openvpn[4819]: UID set to nobody
May 27 13:39:11 scu1 openvpn[4819]: Initialization Sequence Completed
Last edited by Pippin on Wed May 27, 2020 8:12 pm, edited 1 time in total.
Reason: Formatting, please use Preview before Submit, thanks.

User avatar
TinCanTech
OpenVPN Protagonist
Posts: 7604
Joined: Fri Jun 03, 2016 1:17 pm

Re: ssh timeouts (does not appear to be MTU)

Post by TinCanTech » Wed May 27, 2020 6:30 pm

wayne_ovpn wrote:
Wed May 27, 2020 6:04 pm
Wed May 27 13:39:10 2020 MULTI: new connection by client 'scu1-r4-client' will cause previous active sessions by this client to be dropped. Remember to use the --duplicate-cn option if you want multiple clients using the same certificate or username to concurrently connect.

wayne_ovpn
OpenVpn Newbie
Posts: 6
Joined: Tue May 19, 2020 4:56 pm

Re: ssh timeouts (does not appear to be MTU)

Post by wayne_ovpn » Wed May 27, 2020 6:58 pm

There is only one connection using that config. If OpenVPN sees a new connection it should drop the old one.
Note that the OpenVPN connection stay up just fine. pings continue to function.
ssh (only across the OpenVPN connection) times out after ~55 seconds
New ssh connections function just fine, for ~55 seconds.

User avatar
TinCanTech
OpenVPN Protagonist
Posts: 7604
Joined: Fri Jun 03, 2016 1:17 pm

Re: ssh timeouts (does not appear to be MTU)

Post by TinCanTech » Wed May 27, 2020 7:58 pm

Had you posted your complete logs then we would be able to see what came before this:
wayne_ovpn wrote:
Wed May 27, 2020 6:04 pm
May 27 13:39:04 scu1 openvpn[4819]: SIGUSR1[soft,tls-error] received, process restarting
But you chose to omit those details .. so your guess is as good as mine ..

wayne_ovpn
OpenVpn Newbie
Posts: 6
Joined: Tue May 19, 2020 4:56 pm

Re: ssh timeouts (does not appear to be MTU)

Post by wayne_ovpn » Wed May 27, 2020 8:10 pm

That is when I restarted OpenVPN on the client. Here is everything from the previous restart. There is nothing in the logs that indicates that the connection has issues.

Code: Select all

May 27 13:37:59 scu1 openvpn[4819]: SIGUSR1[soft,tls-error] received, process restarting
May 27 13:37:59 scu1 openvpn[4819]: Restart pause, 5 second(s)
May 27 13:38:04 scu1 openvpn[4819]: Re-using SSL/TLS context
May 27 13:38:04 scu1 openvpn[4819]: Control Channel MTU parms [ L:1621 D:1184 EF:66 EB:0 ET:0 EL:3 ]
May 27 13:38:04 scu1 openvpn[4819]: Data Channel MTU parms [ L:1621 D:1450 EF:121 EB:406 ET:0 EL:3 ]
May 27 13:38:04 scu1 openvpn[4819]: Local Options String (VER=V4): 'V4,dev-type tun,link-mtu 1557,tun-mtu 1500,proto UDPv4,keydir 1,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-client'
May 27 13:38:04 scu1 openvpn[4819]: Expected Remote Options String (VER=V4): 'V4,dev-type tun,link-mtu 1557,tun-mtu 1500,proto UDPv4,keydir 0,cipher AES-256-CBC,auth SHA1,keysize 256,tls-auth,key-method 2,tls-server'
May 27 13:38:04 scu1 openvpn[4819]: TCP/UDP: Preserving recently used remote address: [AF_INET]SERVER.IP:1194
May 27 13:38:04 scu1 openvpn[4819]: Socket Buffers: R=[294912->294912] S=[294912->294912]
May 27 13:38:04 scu1 openvpn[4819]: UDP link local: (not bound)
May 27 13:38:04 scu1 openvpn[4819]: UDP link remote: [AF_INET]SERVER.IP:1194
May 27 13:39:04 scu1 openvpn[4819]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
May 27 13:39:04 scu1 openvpn[4819]: TLS Error: TLS handshake failed
May 27 13:39:04 scu1 openvpn[4819]: TCP/UDP: Closing socket
May 27 13:39:04 scu1 openvpn[4819]: SIGUSR1[soft,tls-error] received, process restarting
Last edited by Pippin on Wed May 27, 2020 8:13 pm, edited 1 time in total.
Reason: Formatting, please use Preview before Submit, thanks.

User avatar
TinCanTech
OpenVPN Protagonist
Posts: 7604
Joined: Fri Jun 03, 2016 1:17 pm

Re: ssh timeouts (does not appear to be MTU)

Post by TinCanTech » Wed May 27, 2020 8:42 pm

wayne_ovpn wrote:
Wed May 27, 2020 8:10 pm
There is nothing in the [OpenVPN] logs that indicates that the connection has issues
Because openvpn is behaving exactly as it should. Something on your network is not.

You understand that ssh does not need to be wrapped by a VPN at all ?

wayne_ovpn
OpenVpn Newbie
Posts: 6
Joined: Tue May 19, 2020 4:56 pm

Re: ssh timeouts (does not appear to be MTU)

Post by wayne_ovpn » Thu May 28, 2020 5:50 pm

OpenVPN is doing something odd. Note the original post; the same client talking to the same server has no issues when ssh is used to the public IP address, yet always times out after about a minute when using the OpenVPN connection.

While it might not be OpenVPN, I'd appreciate suggestions as to where else to look?

Post Reply