Provider disconnects / VPN does not reconnect

[borussia]

Hello. I have a problem with my ISP being that the connection drops out pretty often. I have their router as modem and have my ASUS Merlin RT-AC68U behind it (exposed host) handling the VPN connection.

While the dropouts are a nuisance, they were not a problem for the ASUS so far as it reconnected the VPN connection whenever the ISP signal came back. As of two or three days though, the ASUS does not successfully reinitialize the VPN connection. All computer routed to use the VPN do not have a connection while the WAN-routed clients are back on track.

Is there something I can do to make the ASUS reinitialize the VPN connection after a disconnect from the ISP? I believe that first of all it must be able to recognize the dropped connection the other router is going through. Could be a challenge as the ASUS will always see the working connection in the LAN, but maybe not necessarily the missing WAN connection.

 

[M@rco]

Have you tried changing VPN > VPN Client > Connection Retry attempts to -1 (infinite retries)? It's set to 15 attempts by default, I think.

 

[borussia]

Thanks. My VPN provider stated in the setup tutorial for Merlin to set the TLS Renegotiation Time to 1800 and the Connection Retry attemps to 60. I have not yet tried your suggestion, but will do so now.

For me understand the situation better;

TLS Renegotiation Time of 1800 seconds means that for 30 minutes the client will attempt to connect 60 times? So if, in my case, the ISP disconnects and it takes 5 minutes for the WAN connection to reestablish and should the 60 attempts to reconnect be used up within these 5 minutes then my VPN connection will not be established?

Or will my router automatically spread out the reconnection attempts in the renegotiation timeframe, e.g. 1800 seconds / 60 attempts being one attempt every 30 seconds for half an hour?

 

[M@rco]

TLS Renegotiation Time is the time used to renegotiate a new data channel key. This setting can both be set by the client as well as on the server, whichever value is lower will initiate renegotiation. This applies to an active connection, so it's not relevant to your issue.

Connection Retry Attempts is the value used to determine how long ovpclient will retry connecting to your VPN Service provider. If the ISP disconnects usually take a longer time, setting it to 60 is probably too short. When setting it to -1 (infinite) ovpnclient will retry until it has established a new connection, regardless of the outage of your internet connection.

 

[borussia]

Hey, thanks a million, Marco!! That sounds like just what I need. Will let you know how it works out.

 

[borussia]

Ironically, there have been no ISP disconnects since sunday. So I will owe the feedback until a hopefully much later date...

UPDATE: ISP disconnected today - VPN connection was reestablished! Your advice must have made a difference. Thank you again.

UPDATE 2: Rejoiced too soon More disconnects and no successful VPN reconnect. Interestingly, the ASUS webinterface "OpenVPN Settings" shows "Connected" in Service State while no connection is there.

 

[borussia]

Thank you for your help so far, but unfortunately the problem remains. The only thing that helps is to switch the service state off and then back on. The refresh link on the service state line does nothing to help either. Is there something I could write in the custom configuration to check for a WAN signal and, if that is fruitless, to renogotiate the VPN connection?

 

[Martineau]

The refresh link on the service state line does nothing to help either.

The link just attempts to retrieve the VPN end-point public address which isn't available for some VPN providers such as vpnbook etc.

The only thing that helps is to switch the service state off and then back on.

Is there something I could write in the custom configuration to check for a WAN signal and, if that is fruitless, to renogotiate the VPN connection?

You will need to use scripting, something like ChkWAN.sh to create a cru (cron) schedule to regularly validate the WAN connection (with the 'noaction' directive) and if RC=99 then you could restart the VPN.

 

[borussia]

The link just attempts to retrieve the VPN end-point public address which isn't available for some VPN providers such as vpnbook etc.


You will need to use scripting, something like ChkWAN.sh to create a cru (cron) schedule to regularly validate the WAN connection (with the 'noaction' directive) and if RC=99 then you could restart the VPN.

Thanks @Martineau ! I will look into this, although I have no idea of scripting. But then again, I like a challenge!

 

[Olivier L]

Ironically, there have been no ISP disconnects since sunday. So I will owe the feedback until a hopefully much later date...

UPDATE: ISP disconnected today - VPN connection was reestablished! Your advice must have made a difference. Thank you again.

UPDATE 2: Rejoiced too soon More disconnects and no successful VPN reconnect. Interestingly, the ASUS webinterface "OpenVPN Settings" shows "Connected" in Service State while no connection is there.

Hello it seems I have the same issue there as your UPDATE2. Many times, when VPN falls over, it reconnects (-1 is set for reconnection tentatives) as per what we can see in the WEB UI, but in fact I have no web access. I have seen using "ip rules" that vpn connection is there but the ip rules are not set (Force Internet traffic through tunnel is set to Policy Rules Strict). Each time I deco/reco using the WEB UI, no pb ip rules are applied (as per rules of the WEB UI).

Do you know if there is a workaround or a fix to that bug ?

 

[Olivier L]

any idea ?

 

[Martineau]

any idea ?

Without seeing any VPN diagnostics or Syslog extracts showing the symptoms of the failure etc. it is very difficult to make an informed guess regarding the solution to your issue.

i.e. Perhaps Syslog may show the reason why the reconnect is failing such as an error reported by the '/usr/sbin/vpnrouting.sh' script which manages the Selective Routing table/RPDB rules/KILL-Switch etc.

Alternatively you could try the VPN Failover/Monitor script to see if it can force a successful recovery automatically.

 

[Olivier L]

No error in the syslog, it says it is reconnected. But Policy routing rules are not applied.
I have tried VPN-Failover but it is the same.

Here is the log when openvpn restart automatically.

#########
Dec 3 01:14:52 AX88U-olivier ovpn-client1[26046]: [lu-lux-001.mullvad.net] Inactivity timeout (--ping-restart), restarting
Dec 3 01:14:52 AX88U-olivier ovpn-client1[26046]: SIGUSR1[soft,ping-restart] received, process restarting
Dec 3 01:14:52 AX88U-olivier ovpn-client1[26046]: Restart pause, 5 second(s)
Dec 3 01:14:57 AX88U-olivier ovpn-client1[26046]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Dec 3 01:14:57 AX88U-olivier ovpn-client1[26046]: NOTE: --fast-io is disabled since we are not using UDP
Dec 3 01:14:57 AX88U-olivier ovpn-client1[26046]: TCP/UDP: Preserving recently used remote address: [AF_INET]92.223.89.160:443
Dec 3 01:14:57 AX88U-olivier ovpn-client1[26046]: Socket Buffers: R=[87380->1048576] S=[16384->1048576]
Dec 3 01:14:57 AX88U-olivier ovpn-client1[26046]: Attempting to establish TCP connection with [AF_INET]92.223.89.160:443 [nonblock]
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: TCP connection established with [AF_INET]92.223.89.160:443
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: TCP_CLIENT link local: (not bound)
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: TCP_CLIENT link remote: [AF_INET]92.223.89.160:443
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: TLS: Initial packet from [AF_INET]92.223.89.160:443, sid=868078e9 a51d5538
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: VERIFY OK: depth=2, C=SE, ST=Gotaland, L=Gothenburg, O=Amagicom AB, OU=Mullvad, CN=Mullvad Root CA v2, emailAddress=security@mullvad.net
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: VERIFY OK: depth=1, C=SE, ST=Gotaland, O=Amagicom AB, OU=Mullvad, CN=Mullvad Intermediate CA v2, emailAddress=security@mullvad.net
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: VERIFY KU OK
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: Validating certificate extended key usage
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: VERIFY EKU OK
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: VERIFY OK: depth=0, C=SE, ST=Gotaland, O=Amagicom AB, OU=Mullvad, CN=lu-lux-001.mullvad.net, emailAddress=security@mullvad.net
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 4096 bit RSA
Dec 3 01:14:58 AX88U-olivier ovpn-client1[26046]: [lu-lux-001.mullvad.net] Peer Connection Initiated with [AF_INET]92.223.89.160:443
Dec 3 01:15:00 AX88U-olivier ovpn-client1[26046]: SENT CONTROL [lu-lux-001.mullvad.net]: 'PUSH_REQUEST' (status=1)
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: SENT CONTROL [lu-lux-001.mullvad.net]: 'PUSH_REQUEST' (status=1)
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: PUSH: Received control message: 'PUSH_REPLY,dhcp-option DNS 10.5.0.1,redirect-gateway def1 bypass-dhcp,route-ipv6 0000::/2,route-ipv6 4000::/2,route-ipv6 8000::/2,route-ipv6 C000::/2,comp-lzo no,route-gateway 10.5.0.1,topology subnet,socket-flags TCP_NODELAY,ifconfig-ipv6 fdda:d0d0:cafe:443::1001/64 fdda:d0d0:cafe:443::,ifconfig 10.5.0.3 255.255.0.0,peer-id 0,cipher AES-256-GCM'
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: Pushed option removed by filter: 'route-ipv6 0000::/2'
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: Pushed option removed by filter: 'route-ipv6 4000::/2'
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: Pushed option removed by filter: 'route-ipv6 8000::/2'
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: Pushed option removed by filter: 'route-ipv6 C000::/2'
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: Pushed option removed by filter: 'ifconfig-ipv6 fdda:d0d0:cafe:443::1001/64 fdda:d0d0:cafe:443::'
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: OPTIONS IMPORT: compression on parms modified
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: OPTIONS IMPORT: --socket-flags option modified
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: OPTIONS IMPORT: --ifconfig/up options modified
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: OPTIONS IMPORT: route options modified
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: OPTIONS IMPORT: route-related options modified
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: OPTIONS IMPORT: peer-id set
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: OPTIONS IMPORT: adjusting link_mtu to 1627
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: OPTIONS IMPORT: data channel crypto options modified
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: Data Channel: using negotiated cipher 'AES-256-GCM'
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: Preserving previous TUN/TAP instance: tun11
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: Initialization Sequence Completed
Dec 3 01:20:00 AX88U-olivier (VPN_Failover.sh): 20764 v1.18 Started..... [1 ignore=2,3,4,5 once multiconfig force curlrate=500000]
Dec 3 01:20:00 AX88U-olivier (VPN_Failover.sh): 20764 once
Dec 3 01:20:00 AX88U-olivier (VPN_Failover.sh): 20764 VPN Client Monitor: Checking VPN Client 1 connection status....
Dec 3 01:20:01 AX88U-olivier (VPN_Failover.sh): 20764 Starting VPN Client 1 cURL 'big' data transfer.....(Expect 12MB approx @3.1MB/sec on 20Mbps download = 00:04 secs)
Dec 3 01:20:02 AX88U-olivier (VPN_Failover.sh): 20764 cURL 12MByte transfer took: 00:01.35 secs @9245562 B/sec
Dec 3 01:20:02 AX88U-olivier (VPN_Failover.sh): 20764 VPN Client Monitor: VPN Client 1 status OK using MINIMIUM acceptable cURL transfer rate (500000 Bytes/sec)
Dec 3 01:20:02 AX88U-olivier (VPN_Failover.sh): 20764 VPN Client Monitor: Monitoring VPN Client 1 terminated
########​

VPN connection is ok, but ip rule shows that my Policy routing is not set:
######

0: from all lookup local
9990: from all fwmark 0x8000/0x8000 lookup main
9991: from all fwmark 0x7000/0x7000 lookup ovpnc4
9992: from all fwmark 0x3000/0x3000 lookup ovpnc5
9993: from all fwmark 0x1000/0x1000 lookup ovpnc1
9994: from all fwmark 0x2000/0x2000 lookup ovpnc2
9995: from all fwmark 0x4000/0x4000 lookup ovpnc3
10201: from 192.168.1.1 lookup main
10301: from 192.168.1.22 lookup ovpnc2
32766: from all lookup main
32767: from all lookup default​

#######

​

 

[Olivier L]

When I manually restart the openvpn client (using web ui), I have this syslog :

#######
Dec 3 01:23:30 AX88U-olivier rc_service: httpd 1121:notify_rc stop_vpnclient1
Dec 3 01:23:30 AX88U-olivier custom_script: Running /jffs/scripts/service-event (args: stop vpnclient1)
Dec 3 01:23:30 AX88U-olivier ovpn-client1[26046]: event_wait : Interrupted system call (code=4)
Dec 3 01:23:30 AX88U-olivier ovpn-client1[26046]: vpnrouting.sh tun11 1500 1555 10.5.0.3 255.255.0.0 init
Dec 3 01:23:30 AX88U-olivier openvpn-routing: Configuring policy rules for client 1
Dec 3 01:23:30 AX88U-olivier custom_script: Running /jffs/scripts/openvpn-event (args: tun11 1500 1555 10.5.0.3 255.255.0.0 init)
Dec 3 01:23:30 AX88U-olivier openvpn-event[31031]: Running /jffs/scripts/vpnclient1-route-pre-down tun11 1500 1555 10.5.0.3 255.255.0.0 init
Dec 3 01:23:46 AX88U-olivier rc_service: httpd 1121:notify_rc start_vpnclient1
Dec 3 01:23:46 AX88U-olivier custom_script: Running /jffs/scripts/service-event (args: start vpnclient1)
Dec 3 01:23:46 AX88U-olivier ovpn-client1[31295]: OpenVPN 2.4.7 arm-buildroot-linux-gnueabi [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Jul 31 2019
Dec 3 01:23:46 AX88U-olivier ovpn-client1[31295]: library versions: OpenSSL 1.1.1c 28 May 2019, LZO 2.08
Dec 3 01:23:46 AX88U-olivier ovpn-client1[31296]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Dec 3 01:23:46 AX88U-olivier ovpn-client1[31296]: NOTE: --fast-io is disabled since we are not using UDP
Dec 3 01:23:46 AX88U-olivier ovpn-client1[31296]: TCP/UDP: Preserving recently used remote address: [AF_INET]92.223.89.160:443
Dec 3 01:23:46 AX88U-olivier ovpn-client1[31296]: Socket Buffers: R=[87380->1048576] S=[16384->1048576]
Dec 3 01:23:46 AX88U-olivier ovpn-client1[31296]: Attempting to establish TCP connection with [AF_INET]92.223.89.160:443 [nonblock]
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: TCP connection established with [AF_INET]92.223.89.160:443
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: TCP_CLIENT link local: (not bound)
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: TCP_CLIENT link remote: [AF_INET]92.223.89.160:443
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: TLS: Initial packet from [AF_INET]92.223.89.160:443, sid=2caf0b16 699d9d8a
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: VERIFY OK: depth=2, C=SE, ST=Gotaland, L=Gothenburg, O=Amagicom AB, OU=Mullvad, CN=Mullvad Root CA v2, emailAddress=security@mullvad.net
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: VERIFY OK: depth=1, C=SE, ST=Gotaland, O=Amagicom AB, OU=Mullvad, CN=Mullvad Intermediate CA v2, emailAddress=security@mullvad.net
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: VERIFY KU OK
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: Validating certificate extended key usage
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: VERIFY EKU OK
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: VERIFY OK: depth=0, C=SE, ST=Gotaland, O=Amagicom AB, OU=Mullvad, CN=lu-lux-001.mullvad.net, emailAddress=security@mullvad.net
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 4096 bit RSA
Dec 3 01:23:47 AX88U-olivier ovpn-client1[31296]: [lu-lux-001.mullvad.net] Peer Connection Initiated with [AF_INET]92.223.89.160:443
Dec 3 01:23:49 AX88U-olivier ovpn-client1[31296]: SENT CONTROL [lu-lux-001.mullvad.net]: 'PUSH_REQUEST' (status=1)
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: SENT CONTROL [lu-lux-001.mullvad.net]: 'PUSH_REQUEST' (status=1)
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: PUSH: Received control message: 'PUSH_REPLY,dhcp-option DNS 10.5.0.1,redirect-gateway def1 bypass-dhcp,route-ipv6 0000::/2,route-ipv6 4000::/2,route-ipv6 8000::/2,route-ipv6 C000::/2,comp-lzo no,route-gateway 10.5.0.1,topology subnet,socket-flags TCP_NODELAY,ifconfig-ipv6 fdda:d0d0:cafe:443::1001/64 fdda:d0d0:cafe:443::,ifconfig 10.5.0.3 255.255.0.0,peer-id 0,cipher AES-256-GCM'
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: Pushed option removed by filter: 'route-ipv6 0000::/2'
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: Pushed option removed by filter: 'route-ipv6 4000::/2'
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: Pushed option removed by filter: 'route-ipv6 8000::/2'
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: Pushed option removed by filter: 'route-ipv6 C000::/2'
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: Pushed option removed by filter: 'ifconfig-ipv6 fdda:d0d0:cafe:443::1001/64 fdda:d0d0:cafe:443::'
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: OPTIONS IMPORT: compression parms modified
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: OPTIONS IMPORT: --socket-flags option modified
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: OPTIONS IMPORT: --ifconfig/up options modified
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: OPTIONS IMPORT: route options modified
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: OPTIONS IMPORT: route-related options modified
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: OPTIONS IMPORT: peer-id set
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: OPTIONS IMPORT: adjusting link_mtu to 1627
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: OPTIONS IMPORT: data channel crypto options modified
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: Data Channel: using negotiated cipher 'AES-256-GCM'
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: TUN/TAP device tun11 opened
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: TUN/TAP TX queue length set to 1000
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: /bin/ip link set dev tun11 up mtu 1500
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: /bin/ip addr add dev tun11 10.5.0.3/16 broadcast 10.5.255.255
Dec 3 01:23:54 AX88U-olivier ovpn-client1[31296]: updown.sh tun11 1500 1555 10.5.0.3 255.255.0.0 init
Dec 3 01:23:54 AX88U-olivier rc_service: service 31371:notify_rc updateresolv
Dec 3 01:23:54 AX88U-olivier custom_script: Running /jffs/scripts/service-event (args: updateresolv)
Dec 3 01:23:54 AX88U-olivier custom_script: Running /jffs/scripts/openvpn-event (args: tun11 1500 1555 10.5.0.3 255.255.0.0 init)
Dec 3 01:23:54 AX88U-olivier openvpn-event[31391]: Running /jffs/scripts/vpnclient1-up tun11 1500 1555 10.5.0.3 255.255.0.0 init
Dec 3 01:23:54 AX88U-olivier custom_config: Appending content of /jffs/configs/dnsmasq.conf.add.
Dec 3 01:23:54 AX88U-olivier custom_script: Running /jffs/scripts/dnsmasq.postconf (args: /etc/dnsmasq.conf)
Dec 3 01:23:54 AX88U-olivier Diversion: restarted Dnsmasq to apply settings, from /jffs/scripts/dnsmasq.postconf
Dec 3 01:24:27 AX88U-olivier openvpn-routing: Configuring policy rules for client 1
Dec 3 01:24:27 AX88U-olivier ovpn-client2[15872]: write UDP: Network is unreachable (code=101)
Dec 3 01:24:27 AX88U-olivier ovpn-client2[15872]: write UDP: Network is unreachable (code=101)
Dec 3 01:24:27 AX88U-olivier ovpn-client2[15872]: write UDP: Network is unreachable (code=101)
Dec 3 01:24:27 AX88U-olivier custom_script: Running /jffs/scripts/openvpn-event (args: tun11 1500 1555 10.5.0.3 )
Dec 3 01:24:27 AX88U-olivier openvpn-event[32280]: Script not defined for event: vpnclient1-route-up
Dec 3 01:24:27 AX88U-olivier ovpn-client1[31296]: Initialization Sequence Completed
Dec 3 01:25:03 AX88U-olivier dropbear[32592]: Child connection from 192.168.1.31:49484
Dec 3 01:25:04 AX88U-olivier dropbear[32592]: Pubkey auth succeeded for 'olivier' with key sha1!! 32:69:fb:fa:6d:86:e3:82:28:48:d4:e0:70:0a:41:8a:a1:9c:86:b3 from 192.168.1.31:49484
Dec 3 01:30:00 AX88U-olivier (VPN_Failover.sh): 10028 v1.18 Started..... [1 ignore=2,3,4,5 once multiconfig force curlrate=500000]
Dec 3 01:30:00 AX88U-olivier (VPN_Failover.sh): 10028 once
Dec 3 01:30:00 AX88U-olivier (VPN_Failover.sh): 10028 VPN Client Monitor: Checking VPN Client 1 connection status....
Dec 3 01:30:01 AX88U-olivier (VPN_Failover.sh): 10028 Starting VPN Client 1 cURL 'big' data transfer.....(Expect 12MB approx @3.1MB/sec on 20Mbps download = 00:04 secs)
Dec 3 01:30:03 AX88U-olivier (VPN_Failover.sh): 10028 cURL 12MByte transfer took: 00:01.64 secs @7612667 B/sec
Dec 3 01:30:03 AX88U-olivier (VPN_Failover.sh): 10028 VPN Client Monitor: VPN Client 1 status OK using MINIMIUM acceptable cURL transfer rate (500000 Bytes/sec)
Dec 3 01:30:03 AX88U-olivier (VPN_Failover.sh): 10028 VPN Client Monitor: Monitoring VPN Client 1 terminated
#######​

​

 

[Olivier L]

And in that case my ip policy rules are ok :

#####
0: from all lookup local
9990: from all fwmark 0x8000/0x8000 lookup main
9991: from all fwmark 0x7000/0x7000 lookup ovpnc4
9992: from all fwmark 0x3000/0x3000 lookup ovpnc5
9993: from all fwmark 0x1000/0x1000 lookup ovpnc1
9994: from all fwmark 0x2000/0x2000 lookup ovpnc2
9995: from all fwmark 0x4000/0x4000 lookup ovpnc3
10001: from 192.168.1.1 lookup main
10002: from 192.168.1.192/28 to 192.168.0.254 lookup main
10003: from 192.168.1.192/28 to 185.246.211.0/24 lookup main
10004: from 192.168.1.192/28 to 193.200.164.0/24 lookup main
10005: from 192.168.1.192/28 to 212.8.242.0/23 lookup main
10006: from 192.168.1.192/28 to 185.59.222.0/24 lookup main
10007: from 192.168.1.192/28 to 84.17.60.0/23 lookup main
10008: from 192.168.1.192/28 to 185.132.176.0/22 lookup main
10009: from 192.168.1.192/28 to 51.77.0.0/16 lookup main
10010: from 192.168.1.192/28 to 145.239.0.0/16 lookup main
10011: from 192.168.1.192/28 to 54.38.0.0/16 lookup main
10012: from 192.168.1.192/28 to 185.172.88.0/22 lookup main
10101: from all to 74.125.0.0/16 lookup ovpnc1
10102: from all to 64.233.160.0/19 lookup ovpnc1
10103: from all to 66.102.0.0/20 lookup ovpnc1
10104: from all to 66.249.64.0/19 lookup ovpnc1
10105: from all to 72.14.192.0/18 lookup ovpnc1
10106: from all to 209.85.128.0/17 lookup ovpnc1
10107: from all to 216.239.32.0/19 lookup ovpnc1
10108: from 192.168.1.192/28 lookup ovpnc1
10201: from 192.168.1.1 lookup main
10301: from 192.168.1.22 lookup ovpnc2
32766: from all lookup main
32767: from all lookup default
#######​

 

[Olivier L]

You can see that when I manually restart vpn the script vpnrouting is called, but it is not the case when it is an autoreconnect...

 

[Martineau]

You can see that when I manually restart vpn the script vpnrouting is called, but it is not the case when it is an autoreconnect...

For the successful OpenVPN event

Dec 3 01:14:52 AX88U-olivier ovpn-client1[26046]: [lu-lux-001.mullvad.net] Inactivity timeout (--ping-restart), restarting
Dec 3 01:14:52 AX88U-olivier ovpn-client1[26046]: SIGUSR1[soft,ping-restart] received, process restarting
Dec 3 01:14:52 AX88U-olivier ovpn-client1[26046]: Restart pause, 5 second(s)
<snip>
Dec 3 01:15:05 AX88U-olivier ovpn-client1[26046]: Initialization Sequence Completed

logically there is no need to repopulate the RPDB rules since they should still exist, as clearly there is no 'detectable' DOWN/UP event (in the few seconds it took for the 'Inactivity timeout' to recover) to warrant the execution of 'vpnrouting.sh' etc.

A quick and dirty hack based on the successful VPN_Failover.sh throughput test

Dec 3 01:20:00 AX88U-olivier (VPN_Failover.sh): 20764 v1.18 Started..... [1 ignore=2,3,4,5 once multiconfig force curlrate=500000]
Dec 3 01:20:02 AX88U-olivier (VPN_Failover.sh): 20764 cURL 12MByte transfer took: 00:01.35 secs @9245562 B/sec

would be to set 'curlrate=25M'

However, whilst tedious, no doubt it would be useful to identify why/when the RDPB rules (specifically for VPN Client 1?) went AWOL.

e.g. crudely - geddit? Dump the RPDB rules every 5 mins to Syslog.

cru a ChkIPRule "*/5 * * * * " ip rule >>/tmp/syslog.log

NOTE: I vaguely recall from several years ago that nat-start is also usually helpful in identifying the time of the RPDB rules going AWOL due to the TrendMicro engine updating itself in the early hours of the morning.

grep -F "nat-start" /tmp/syslog.log

Q. Do you tinker with QoS in the GUI? etc. as this could reset the RPDB rules.

 

[Olivier L]

It is not specific to client1.
I have added the line into cron, we will see.
QOS is set on, but never modify it within the GUI, it has been set on once and that's it.

 

[Olivier L]

I do not catch what you mean by "A quick and dirty hack based on the successful VPN_Failover.sh throughput test would be to set 'curlrate=25M'"

 

[Martineau]

I do not catch what you mean by "A quick and dirty hack based on the successful VPN_Failover.sh throughput test would be to set 'curlrate=25M'"

VPN_Failover.sh can be configured to monitor for a drop in performance (aka degraded throughput) so in your use of VPN_Failover.sh the default 'curlrate=500000' was used and compared against the actual observed transfer rate

e.g.

Dec 3 01:20:02 AX88U-olivier (VPN_Failover.sh): 20764 cURL 12MByte transfer took: 00:01.35 secs @9245562 B/sec

meaning '9245562 Bytes/sec' is greater than the desired minimum allowed of '500000 Bytes/sec' so VPN_Failover.sh was satisfied with the current throughput as it was performing above the speed threshold.

So, by setting the desired minimum 'curlrate=' to be a figure that is physically unachievable i.e. 250000000 will force VPN_Failover.sh to restart the VPN Client, which should hopefully trigger 'vpnrouting.sh' etc. to reinstate the missing RPDB rules.