Viktor Jaep
Part of the Furniture
Every so often, I'll check my IP location, and find that my RT-AC86U (386.3_2) is not connected to NordVPN... This happens occasionally, maybe 1x every few weeks. I'm using VPNMGR (big thanks to @Jack Yaz ). I have it resetting its connection at midnight. The way I get it to connect again is by going into VPNMGR, click on "refresh" cached data, and hit "save". This will reconnect the VPN successfully to NordVPN. I'm trying to figure out why it is not able to recover from this by itself, and included some logs below? Might it be prudent of VPNMGR to automatically force another refresh of NordVPN server data if it gets a failed connect or two? I can understand that VPNMGR has now passed the baton, and is no longer aware of whats happening after it forces the reset... so I'm just trying to figure out what can be done here?
Dec 6 00:00:00 vpnmgr: Refreshing NordVPN country data...
Dec 6 00:00:02 vpnmgr: No changes in PIA OpenVPN file archives
Dec 6 00:00:02 vpnmgr: No changes in WeVPN OpenVPN file archives
Dec 6 00:02:00 vpnmgr: Retrieving recommended VPN server using NordVPN API with below parameters
Dec 6 00:02:00 vpnmgr: Protocol: UDP - Type: Standard - Country: United States
Dec 6 00:02:01 vpnmgr: Updating VPN client 2 to NordVPN server
Dec 6 00:02:01 rc_service: service 23130:notify_rc restart_vpnclient2
Dec 6 00:02:01 custom_script: Running /jffs/scripts/service-event (args: restart vpnclient2)
Dec 6 00:02:01 vpnmgr: VPN client 2 updated successfully (US6696 Standard UDP)
Dec 6 00:02:01 ovpn-client2[2457]: event_wait : Interrupted system call (code=4)
Dec 6 00:02:01 ovpn-client2[2457]: SIGTERM received, sending exit notification to peer
Dec 6 00:02:02 ovpn-client2[2457]: ovpn-route-pre-down tun12 1500 1584 10.8.2.4 255.255.255.0 init
Dec 6 00:02:02 ovpn-client2[2457]: Closing TUN/TAP interface
Dec 6 00:02:02 ovpn-client2[2457]: /usr/sbin/ip addr del dev tun12 10.8.2.4/24
Dec 6 00:02:02 ovpn-client2[2457]: ovpn-down 2 client tun12 1500 1584 10.8.2.4 255.255.255.0 init
Dec 6 00:02:02 ovpn-client2[2457]: SIGTERM[soft,exit-with-notification] received, process exiting
Dec 6 00:02:02 openvpn-routing: Clearing routing table for VPN client 2
Dec 6 00:02:02 ovpn-client2[23253]: --cipher is not set. Previous OpenVPN version defaulted to BF-CBC as fallback when cipher negotiation failed in this case. If you need this fallback please add '--data-ciphers-fallback BF-CBC' to your configuration and/or add BF-CBC to --data-ciphers.
Dec 6 00:02:02 ovpn-client2[23253]: OpenVPN 2.5.3 arm-buildroot-linux-gnueabi [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Aug 6 2021
Dec 6 00:02:02 ovpn-client2[23253]: library versions: OpenSSL 1.1.1k 25 Mar 2021, LZO 2.08
Dec 6 00:02:02 ovpn-client2[23254]: WARNING: --ping should normally be used with --ping-restart or --ping-exit
Dec 6 00:02:02 ovpn-client2[23254]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Dec 6 00:02:02 ovpn-client2[23254]: Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Dec 6 00:02:02 ovpn-client2[23254]: Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Dec 6 00:02:02 ovpn-client2[23254]: TCP/UDP: Preserving recently used remote address: [AF_INET]89.157.17.191:1194
Dec 6 00:02:02 ovpn-client2[23254]: Socket Buffers: R=[524288->1048576] S=[524288->1048576]
Dec 6 00:02:02 ovpn-client2[23254]: UDP link local: (not bound)
Dec 6 00:02:02 ovpn-client2[23254]: UDP link remote: [AF_INET]89.157.17.191:1194
Dec 6 00:02:02 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:02:04 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:02:08 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:02:16 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:02:32 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:03:02 ovpn-client2[23254]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Dec 6 00:03:02 ovpn-client2[23254]: TLS Error: TLS handshake failed
Dec 6 00:03:02 ovpn-client2[23254]: SIGUSR1[soft,tls-error] received, process restarting
Dec 6 00:03:02 ovpn-client2[23254]: Restart pause, 5 second(s)
Dec 6 00:03:07 ovpn-client2[23254]: WARNING: --ping should normally be used with --ping-restart or --ping-exit
Dec 6 00:03:07 ovpn-client2[23254]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Dec 6 00:03:07 ovpn-client2[23254]: Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Dec 6 00:03:07 ovpn-client2[23254]: Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Dec 6 00:03:07 ovpn-client2[23254]: TCP/UDP: Preserving recently used remote address: [AF_INET]89.157.17.191:1194
Dec 6 00:03:07 ovpn-client2[23254]: Socket Buffers: R=[524288->1048576] S=[524288->1048576]
Dec 6 00:03:07 ovpn-client2[23254]: UDP link local: (not bound)
Dec 6 00:03:07 ovpn-client2[23254]: UDP link remote: [AF_INET]89.157.17.191:1194
Dec 6 00:03:07 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:03:09 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:03:13 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:03:21 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:03:37 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
....
And it just keeps looping like this until I manually intervene.
This is the custom config I'm using:
remote-random
resolv-retry infinite
remote-cert-tls server
ping 15
ping-restart 0
ping-timer-rem
persist-key
persist-tun
reneg-sec 0
fast-io
disable-occ
mute-replay-warnings
auth-nocache
sndbuf 524288
rcvbuf 524288
push "sndbuf 524288"
push "rcvbuf 524288"
pull-filter ignore "auth-token"
pull-filter ignore "ifconfig-ipv6"
pull-filter ignore "route-ipv6"
explicit-exit-notify 3
tun-mtu 1500
tun-mtu-extra 32
mssfix 1450
As always, your help with this is very much appreciated!
Dec 6 00:00:00 vpnmgr: Refreshing NordVPN country data...
Dec 6 00:00:02 vpnmgr: No changes in PIA OpenVPN file archives
Dec 6 00:00:02 vpnmgr: No changes in WeVPN OpenVPN file archives
Dec 6 00:02:00 vpnmgr: Retrieving recommended VPN server using NordVPN API with below parameters
Dec 6 00:02:00 vpnmgr: Protocol: UDP - Type: Standard - Country: United States
Dec 6 00:02:01 vpnmgr: Updating VPN client 2 to NordVPN server
Dec 6 00:02:01 rc_service: service 23130:notify_rc restart_vpnclient2
Dec 6 00:02:01 custom_script: Running /jffs/scripts/service-event (args: restart vpnclient2)
Dec 6 00:02:01 vpnmgr: VPN client 2 updated successfully (US6696 Standard UDP)
Dec 6 00:02:01 ovpn-client2[2457]: event_wait : Interrupted system call (code=4)
Dec 6 00:02:01 ovpn-client2[2457]: SIGTERM received, sending exit notification to peer
Dec 6 00:02:02 ovpn-client2[2457]: ovpn-route-pre-down tun12 1500 1584 10.8.2.4 255.255.255.0 init
Dec 6 00:02:02 ovpn-client2[2457]: Closing TUN/TAP interface
Dec 6 00:02:02 ovpn-client2[2457]: /usr/sbin/ip addr del dev tun12 10.8.2.4/24
Dec 6 00:02:02 ovpn-client2[2457]: ovpn-down 2 client tun12 1500 1584 10.8.2.4 255.255.255.0 init
Dec 6 00:02:02 ovpn-client2[2457]: SIGTERM[soft,exit-with-notification] received, process exiting
Dec 6 00:02:02 openvpn-routing: Clearing routing table for VPN client 2
Dec 6 00:02:02 ovpn-client2[23253]: --cipher is not set. Previous OpenVPN version defaulted to BF-CBC as fallback when cipher negotiation failed in this case. If you need this fallback please add '--data-ciphers-fallback BF-CBC' to your configuration and/or add BF-CBC to --data-ciphers.
Dec 6 00:02:02 ovpn-client2[23253]: OpenVPN 2.5.3 arm-buildroot-linux-gnueabi [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Aug 6 2021
Dec 6 00:02:02 ovpn-client2[23253]: library versions: OpenSSL 1.1.1k 25 Mar 2021, LZO 2.08
Dec 6 00:02:02 ovpn-client2[23254]: WARNING: --ping should normally be used with --ping-restart or --ping-exit
Dec 6 00:02:02 ovpn-client2[23254]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Dec 6 00:02:02 ovpn-client2[23254]: Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Dec 6 00:02:02 ovpn-client2[23254]: Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Dec 6 00:02:02 ovpn-client2[23254]: TCP/UDP: Preserving recently used remote address: [AF_INET]89.157.17.191:1194
Dec 6 00:02:02 ovpn-client2[23254]: Socket Buffers: R=[524288->1048576] S=[524288->1048576]
Dec 6 00:02:02 ovpn-client2[23254]: UDP link local: (not bound)
Dec 6 00:02:02 ovpn-client2[23254]: UDP link remote: [AF_INET]89.157.17.191:1194
Dec 6 00:02:02 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:02:04 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:02:08 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:02:16 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:02:32 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:03:02 ovpn-client2[23254]: TLS Error: TLS key negotiation failed to occur within 60 seconds (check your network connectivity)
Dec 6 00:03:02 ovpn-client2[23254]: TLS Error: TLS handshake failed
Dec 6 00:03:02 ovpn-client2[23254]: SIGUSR1[soft,tls-error] received, process restarting
Dec 6 00:03:02 ovpn-client2[23254]: Restart pause, 5 second(s)
Dec 6 00:03:07 ovpn-client2[23254]: WARNING: --ping should normally be used with --ping-restart or --ping-exit
Dec 6 00:03:07 ovpn-client2[23254]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Dec 6 00:03:07 ovpn-client2[23254]: Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Dec 6 00:03:07 ovpn-client2[23254]: Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
Dec 6 00:03:07 ovpn-client2[23254]: TCP/UDP: Preserving recently used remote address: [AF_INET]89.157.17.191:1194
Dec 6 00:03:07 ovpn-client2[23254]: Socket Buffers: R=[524288->1048576] S=[524288->1048576]
Dec 6 00:03:07 ovpn-client2[23254]: UDP link local: (not bound)
Dec 6 00:03:07 ovpn-client2[23254]: UDP link remote: [AF_INET]89.157.17.191:1194
Dec 6 00:03:07 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:03:09 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:03:13 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:03:21 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
Dec 6 00:03:37 ovpn-client2[23254]: write UDP: Operation not permitted (code=1)
....
And it just keeps looping like this until I manually intervene.
This is the custom config I'm using:
remote-random
resolv-retry infinite
remote-cert-tls server
ping 15
ping-restart 0
ping-timer-rem
persist-key
persist-tun
reneg-sec 0
fast-io
disable-occ
mute-replay-warnings
auth-nocache
sndbuf 524288
rcvbuf 524288
push "sndbuf 524288"
push "rcvbuf 524288"
pull-filter ignore "auth-token"
pull-filter ignore "ifconfig-ipv6"
pull-filter ignore "route-ipv6"
explicit-exit-notify 3
tun-mtu 1500
tun-mtu-extra 32
mssfix 1450
As always, your help with this is very much appreciated!