one day an openvpn that used to carry traffic for the last 7 years started to misbehave. openvpn’s own built in watchdog was restarting it every few minutes. one of the tunnels endpoints – a- is behind NAT that we don’t control, another – b – is a host with public ip address.
server b was claiming that keys are out of sync:
Apr 29 08:25:16 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:17 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:18 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:19 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:20 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:21 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:22 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:23 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:24 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:25 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:26 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:27 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:27 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:41408 [0]
Apr 29 08:25:30 brtr0 openvpn-a-B[27745]: [a-c] Peer Connection Initiated with [AF_INET]93.1.2.158:41408
Apr 29 08:26:31 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:49193 [0]
Apr 29 08:26:36 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:49193 [0]
Apr 29 08:26:41 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:49193 [0]
Apr 29 08:26:42 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:49193 [0]
Apr 29 08:26:42 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:49193 [0]
Apr 29 08:26:43 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:49193 [0]
Apr 29 08:26:45 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:49193 [0]
Apr 29 08:26:47 brtr0 openvpn-a-B[27745]: [a-c] Inactivity timeout (--ping-restart), restarting
Apr 29 08:26:47 brtr0 openvpn-a-B[27745]: SIGUSR1[soft,ping-restart] received, process restarting
Apr 29 08:26:49 brtr0 openvpn-a-B[27745]: NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Apr 29 08:26:49 brtr0 openvpn-a-B[27745]: Re-using SSL/TLS context
Apr 29 08:26:49 brtr0 openvpn-a-B[27745]: LZO compression initialized
Apr 29 08:26:49 brtr0 openvpn-a-B[27745]: Preserving previous TUN/TAP instance: tun2
Apr 29 08:26:49 brtr0 openvpn-a-B[27745]: UDPv4 link local (bound): [AF_INET]213.1.2.10:1779
Apr 29 08:26:49 brtr0 openvpn-a-B[27745]: UDPv4 link remote: [undef]
Apr 29 08:26:51 brtr0 openvpn-a-B[27745]: [a-c] Peer Connection Initiated with [AF_INET]93.1.2.158:49193
Apr 29 08:26:52 brtr0 openvpn-a-B[27745]: Initialization Sequence Completed
Apr 29 08:28:04 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:15472 [0]
Apr 29 08:28:06 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:15472 [0]
Apr 29 08:28:12 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:15472 [0]
Apr 29 08:28:13 brtr0 openvpn-a-B[27745]: TLS Error: local/remote TLS keys are out of sync: [AF_INET]93.1.2.158:15472 [0]
Apr 29 08:28:19 brtr0 openvpn-a-B[27745]: [a-c] Inactivity timeout (--ping-restart), restarting
Apr 29 08:28:19 brtr0 openvpn-a-B[27745]: SIGUSR1[soft,ping-restart] received, process restarting
Apr 29 08:28:21 brtr0 openvpn-a-B[27745]: NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Apr 29 08:28:21 brtr0 openvpn-a-B[27745]: Re-using SSL/TLS context
Apr 29 08:28:21 brtr0 openvpn-a-B[27745]: LZO compression initialized
Apr 29 08:28:21 brtr0 openvpn-a-B[27745]: Preserving previous TUN/TAP instance: tun2
Apr 29 08:28:21 brtr0 openvpn-a-B[27745]: UDPv4 link local (bound): [AF_INET]213.1.2.10:1779
Apr 29 08:28:21 brtr0 openvpn-a-B[27745]: UDPv4 link remote: [undef]
Apr 29 08:28:22 brtr0 openvpn-a-B[27745]: [a-c] Peer Connection Initiated with [AF_INET]93.1.2.158:15472
Apr 29 08:28:23 brtr0 openvpn-a-B[27745]: Initialization Sequence Completed
which led to restarts of the vpn on the server a:
Apr 29 08:25:28 artr0 openvpn-A-b[5011]: [b-s] Inactivity timeout (--ping-restart), restarting
Apr 29 08:25:28 artr0 openvpn-A-b[5011]: SIGUSR1[soft,ping-restart] received, process restarting
Apr 29 08:25:30 artr0 openvpn-A-b[5011]: WARNING: Make sure you understand the semantics of --tls-remote before using it (see the man page).
Apr 29 08:25:30 artr0 openvpn-A-b[5011]: NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Apr 29 08:25:30 artr0 openvpn-A-b[5011]: Re-using SSL/TLS context
Apr 29 08:25:30 artr0 openvpn-A-b[5011]: LZO compression initialized
Apr 29 08:25:30 artr0 openvpn-A-b[5011]: Preserving previous TUN/TAP instance: tun1
Apr 29 08:25:30 artr0 openvpn-A-b[5011]: UDPv4 link local (bound): [undef]
Apr 29 08:25:30 artr0 openvpn-A-b[5011]: UDPv4 link remote: [AF_INET]213.1.2.10:1779
Apr 29 08:25:30 artr0 openvpn-A-b[5011]: [b-s] Peer Connection Initiated with [AF_INET]213.1.2.10:1779
Apr 29 08:25:31 artr0 openvpn-A-b[5011]: Initialization Sequence Completed
Apr 29 08:26:49 artr0 openvpn-A-b[5011]: [b-s] Inactivity timeout (--ping-restart), restarting
Apr 29 08:26:49 artr0 openvpn-A-b[5011]: SIGUSR1[soft,ping-restart] received, process restarting
Apr 29 08:26:51 artr0 openvpn-A-b[5011]: WARNING: Make sure you understand the semantics of --tls-remote before using it (see the man page).
Apr 29 08:26:51 artr0 openvpn-A-b[5011]: NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Apr 29 08:26:51 artr0 openvpn-A-b[5011]: Re-using SSL/TLS context
Apr 29 08:26:51 artr0 openvpn-A-b[5011]: LZO compression initialized
Apr 29 08:26:51 artr0 openvpn-A-b[5011]: Preserving previous TUN/TAP instance: tun1
Apr 29 08:26:51 artr0 openvpn-A-b[5011]: UDPv4 link local (bound): [undef]
Apr 29 08:26:51 artr0 openvpn-A-b[5011]: UDPv4 link remote: [AF_INET]213.1.2.10:1779
Apr 29 08:26:51 artr0 openvpn-A-b[5011]: [b-s] Peer Connection Initiated with [AF_INET]213.1.2.10:1779
Apr 29 08:26:52 artr0 openvpn-A-b[5011]: Initialization Sequence Completed
Apr 29 08:28:17 artr0 openvpn-A-b[5011]: [b-s] Inactivity timeout (--ping-restart), restarting
Apr 29 08:28:17 artr0 openvpn-A-b[5011]: SIGUSR1[soft,ping-restart] received, process restarting
Apr 29 08:28:19 artr0 openvpn-A-b[5011]: WARNING: Make sure you understand the semantics of --tls-remote before using it (see the man page).
Apr 29 08:28:19 artr0 openvpn-A-b[5011]: NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
Apr 29 08:28:19 artr0 openvpn-A-b[5011]: Re-using SSL/TLS context
Apr 29 08:28:19 artr0 openvpn-A-b[5011]: LZO compression initialized
Apr 29 08:28:19 artr0 openvpn-A-b[5011]: Preserving previous TUN/TAP instance: tun1
Apr 29 08:28:19 artr0 openvpn-A-b[5011]: UDPv4 link local (bound): [undef]
Apr 29 08:28:19 artr0 openvpn-A-b[5011]: UDPv4 link remote: [AF_INET]213.1.2.10:1779
Apr 29 08:28:19 artr0 openvpn-A-b[5011]: read UDPv4 [ECONNREFUSED]: Connection refused (code=111)
Apr 29 08:28:22 artr0 openvpn-A-b[5011]: [b-s] Peer Connection Initiated with [AF_INET]213.1.2.10:1779
Apr 29 08:28:23 artr0 openvpn-A-b[5011]: Initialization Sequence Completed
both a and b had in their configs:
ping 5
ping-restart 20
which lead to the restarts on the server a after communication breakdowns.
i still don’t understand real culprit of the problems. i suspect it might have something to do with the NAT behind which machine a is connected. but increasing the ping frequency from every 5s to every 1s has resolved the issue. for now at least:
ping 1
ping-restart 20
i had 409 vpn restarts 2 days ago, after applying this change.