VPNMON VPNMON-R2 v2.52 -Mar 27, 2023- Monitor your VPN connection's Health (Thread locked/closed)

[Viktor Jaep]

Haha, that's funny--true, at least the internet complaints have stopped.

So here's the deal, it looks like the script is unable to recover from WAN downtime. It started today at 1930 AST and hasn't yet stopped at 2200 AST:

Spoiler: Script Log

Thu Sep 22 19:31:19 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED
Thu Sep 22 19:31:24 AST 2022 - VPNMON-R2 - WAN Link Detected -- Trying to reconnect/Reset VPN
Thu Sep 22 19:32:28 AST 2022 - VPNMON-R2 - Executing VPN Reset
Thu Sep 22 19:32:32 AST 2022 - VPNMON-R2 - Killed all VPN Client Connections
Thu Sep 22 19:33:32 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED
Thu Sep 22 19:33:32 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED. VPN RESET TERMINATED.
<SNIP>
Thu Sep 22 21:59:08 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED
Thu Sep 22 21:59:08 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED. VPN RESET TERMINATED.
Thu Sep 22 21:59:14 AST 2022 - VPNMON-R2 - WAN Link Detected -- Trying to reconnect/Reset VPN
Thu Sep 22 22:00:18 AST 2022 - VPNMON-R2 - Executing VPN Reset
Thu Sep 22 22:00:22 AST 2022 - VPNMON-R2 - Killed all VPN Client Connections
Thu Sep 22 22:01:22 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED
Thu Sep 22 22:01:22 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED. VPN RESET TERMINATED.
Thu Sep 22 22:01:28 AST 2022 - VPNMON-R2 - WAN Link Detected -- Trying to reconnect/Reset VPN
Thu Sep 22 22:02:33 AST 2022 - VPNMON-R2 - Executing VPN Reset
Thu Sep 22 22:02:37 AST 2022 - VPNMON-R2 - Killed all VPN Client Connections
Thu Sep 22 22:03:37 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED
Thu Sep 22 22:03:37 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED. VPN RESET TERMINATED.
Thu Sep 22 22:03:43 AST 2022 - VPNMON-R2 - WAN Link Detected -- Trying to reconnect/Reset VPN
Thu Sep 22 22:04:47 AST 2022 - VPNMON-R2 - Executing VPN Reset
Thu Sep 22 22:04:51 AST 2022 - VPNMON-R2 - Killed all VPN Client Connections
<SNIP>
Thu Sep 22 22:08:42 AST 2022 - VPNMON-R2 - Executing VPN Reset
Thu Sep 22 22:08:46 AST 2022 - VPNMON-R2 - Killed all VPN Client Connections
Thu Sep 22 22:09:17 AST 2022 - VPNMON-R2 - Updated Skynet Whitelist
Thu Sep 22 22:09:25 AST 2022 - VPNMON-R2 - Refreshed VPN Slots 1 - 5 from 2244 SuperRandom NordVPN Server Locations
Thu Sep 22 22:09:26 AST 2022 - VPNMON-R2 - Randomly selected VPN3 Client ON
Thu Sep 22 22:09:31 AST 2022 - VPNMON-R2 - VPN Reset Finished
Thu Sep 22 22:09:34 AST 2022 - VPNMON-R2 - Resuming normal operations
Thu Sep 22 22:10:03 AST 2022 - VPNMON-R2 - API call made to update WAN0 city to New York
Thu Sep 22 22:10:25 AST 2022 - VPNMON-R2 - API call made to update VPN city to New York

I got busy and wasn't paying attention until just before bedtime :/ Fixed it by killing the screen session and restarting the script through amtm. If it were a ping-related issue it wouldn't work now either after two and half hours. It's something else, the script is somehow unable to detect when the WAN comes back up when it goes down in the same session. Kill the session and restart the script and all goes well. For the heck of it, I'll change the ping to 1000 and see what happens next.

Can't say I've run across this kind of behavior before. Anything look weird on screen by chance? Any errors or whatnot? I'm going to have you try something. Gimme a few.

 

[monakh]

Can't say I've run across this kind of behavior before. Anything look weird on screen by chance? Any errors or whatnot? I'm going to have you try something. Gimme a few.

Nope, nothing weird at all. Everything looks peachy. It's just odd!

 

[Viktor Jaep]

Nope, nothing weird at all. Everything looks peachy. It's just odd!

Could you please run these commands for me, and send me the output?

nvram get wan0_ifname
nvram get wan1_ifname

nvram get wan0_state_t
nvram get wan1_state_t

nc

openssl version

Ideally, I would love to see these NVRAM values when VPNMON-R2 is behaving, and then once again when it's stuck in this loop. It might be an AXE16000 thing? It's just weird that by exiting the script and starting it back up would fix it... because even during a normal loop, it's executing the same exact code. Hum!

 

[monakh]

Here you go, sir:

Spoiler: NVRAM

admin@VPN-Router:/tmp/home/root# nvram get wan0_ifname
eth0
admin@VPN-Router:/tmp/home/root# nvram get wan1_ifname

admin@VPN-Router:/tmp/home/root# nvram get wan0_state_t
2
admin@VPN-Router:/tmp/home/root# nvram get wan1_state_t
4
admin@VPN-Router:/tmp/home/root# nc
BusyBox v1.25.1 (2022-08-13 16:53:39 EDT) multi-call binary.

Usage: nc [-iN] [-wN] [-f FILE|IPADDR PORT] [-e PROG]

Open a pipe to IP: PORT or FILE

-w SEC Connect timeout
-i SEC Delay interval for lines sent
-f FILE Use file (ala /dev/ttyS0) instead of network
-e PROG Run PROG after connect
admin@VPN-Router:/tmp/home/root# openssl version
OpenSSL 1.1.1q 5 Jul 2022

I think you are right, likely an AXE16000 quirk, it's probably something simple like not calling the expected WAN interface with the correct name or some such thing.

 

[Viktor Jaep]

Here you go, sir:

Spoiler: NVRAM

admin@VPN-Router:/tmp/home/root# nvram get wan0_ifname
eth0
admin@VPN-Router:/tmp/home/root# nvram get wan1_ifname

admin@VPN-Router:/tmp/home/root# nvram get wan0_state_t
2
admin@VPN-Router:/tmp/home/root# nvram get wan1_state_t
4
admin@VPN-Router:/tmp/home/root# nc
BusyBox v1.25.1 (2022-08-13 16:53:39 EDT) multi-call binary.

Usage: nc [-iN] [-wN] [-f FILE|IPADDR PORT] [-e PROG]

Open a pipe to IPORT or FILE

-w SEC Connect timeout
-i SEC Delay interval for lines sent
-f FILE Use file (ala /dev/ttyS0) instead of network
-e PROG Run PROG after connect
admin@VPN-Router:/tmp/home/root#
admin@VPN-Router:/tmp/home/root# openssl version
OpenSSL 1.1.1q 5 Jul 2022

I think you are right, likely an AXE16000 quirk, it's probably something simple like not calling the expected WAN interface with the correct name or some such thing.

Thank you!! OK so that's a functional baseline... could you please do the same thing when it's stuck in that whacky loop? IE - open up a secondary SSH window and run these commands, while VPNMON-R2 is plugging away in the other window? Sorry to make you go through all this.

 

[Viktor Jaep]

Here you go, sir:

I think you are right, likely an AXE16000 quirk, it's probably something simple like not calling the expected WAN interface with the correct name or some such thing.

Also, if you wouldn't mind running this command now, and then when it's gone whacky, please?

nc -w1 8.8.8.8 443 && echo | openssl s_client -connect 8.8.8.8:443 | awk 'handshake && $1 == "Verification" { if ($2=="OK") exit; exit 1 } $1 $2 == "SSLhandshake" { handshake = 1 }'

 

[monakh]

Please don't be sorry, you're the one helping me out so thank you! Don't mind running the commands at all. I tried to replicate the scenario by rebooting my fiber modem and it's almost behaving the same way with one exception: The VPN connection came back up once but was killed again by the script for some odd reason and now we are back in the loop. Here's the output while in the loop (no changes as far as I can tell):

Spoiler: While in the loop

admin@VPN-Router:/tmp/home/root# nvram get wan0_ifname
eth0
admin@VPN-Router:/tmp/home/root# nvram get wan1_ifname

admin@VPN-Router:/tmp/home/root# nvram get wan0_state_t
2
admin@VPN-Router:/tmp/home/root# nvram get wan1_state_t
4
admin@VPN-Router:/tmp/home/root# nc
BusyBox v1.25.1 (2022-08-13 16:53:39 EDT) multi-call binary.

Usage: nc [-iN] [-wN] [-f FILE|IPADDR PORT] [-e PROG]

Open a pipe to IPORT or FILE

-w SEC Connect timeout
-i SEC Delay interval for lines sent
-f FILE Use file (ala /dev/ttyS0) instead of network
-e PROG Run PROG after connect
admin@VPN-Router:/tmp/home/root# openssl version
OpenSSL 1.1.1q 5 Jul 2022

admin@VPN-Router:/tmp/home/root# nc -w1 8.8.8.8 443 && echo | openssl s_cli
ent -connect 8.8.8.8:443 | awk 'handshake && $1 == "Verification" { if ($2=="OK"
) exit; exit 1 } $1 $2 == "SSLhandshake" { handshake = 1 }'
Can't use SSL_get_servername
depth=2 C = US, O = Google Trust Services LLC, CN = GTS Root R1
verify return:1
depth=1 C = US, O = Google Trust Services LLC, CN = GTS CA 1C3
verify return:1
depth=0 CN = dns.google
verify return:1
DONE

Edit: Here's the last command while out of the loop (but VPNMON isn't running yet). Let me know if you want me to run it while the script is active.

admin@VPN-Router:/tmp/home/root# nc -w1 8.8.8.8 443 && echo | openssl s_cli
ent -connect 8.8.8.8:443 | awk 'handshake && $1 == "Verification" { if ($2=="OK"
) exit; exit 1 } $1 $2 == "SSLhandshake" { handshake = 1 }'
Can't use SSL_get_servername
depth=2 C = US, O = Google Trust Services LLC, CN = GTS Root R1
verify return:1
depth=1 C = US, O = Google Trust Services LLC, CN = GTS CA 1C3
verify return:1
depth=0 CN = dns.google
verify return:1
DONE

 

[Viktor Jaep]

Please don't be sorry, you're the one helping me out so thank you! Don't mind running the commands at all. I tried to replicate the scenario by rebooting my fiber modem and it's almost behaving the same way with one exception: The VPN connection came back up once but was killed again by the script for some odd reason and now we are back in the loop. Here's the output while in the loop (no changes as far as I can tell):

Spoiler: While in the loop

admin@VPN-Router:/tmp/home/root# nvram get wan0_ifname
eth0
admin@VPN-Router:/tmp/home/root# nvram get wan1_ifname

admin@VPN-Router:/tmp/home/root# nvram get wan0_state_t
2
admin@VPN-Router:/tmp/home/root# nvram get wan1_state_t
4
admin@VPN-Router:/tmp/home/root# nc
BusyBox v1.25.1 (2022-08-13 16:53:39 EDT) multi-call binary.

Usage: nc [-iN] [-wN] [-f FILE|IPADDR PORT] [-e PROG]

Open a pipe to IPORT or FILE

-w SEC Connect timeout
-i SEC Delay interval for lines sent
-f FILE Use file (ala /dev/ttyS0) instead of network
-e PROG Run PROG after connect
admin@VPN-Router:/tmp/home/root# openssl version
OpenSSL 1.1.1q 5 Jul 2022

Just making sure you're not running any "vpnmon-r2 -reset" commands anywhere at this point in time yet, right?

 

[monakh]

Just making sure you're not running any "vpnmon-r2 -reset" commands anywhere at this point in time yet, right?

Nope!

Here's the last command output while the script is active with a tunnel:

admin@8118-VPN-Router:/tmp/home/root# nc -w1 8.8.8.8 443 && echo | openssl s_cli
ent -connect 8.8.8.8:443 | awk 'handshake && $1 == "Verification" { if ($2=="OK"
) exit; exit 1 } $1 $2 == "SSLhandshake" { handshake = 1 }'
Can't use SSL_get_servername
depth=2 C = US, O = Google Trust Services LLC, CN = GTS Root R1
verify return:1
depth=1 C = US, O = Google Trust Services LLC, CN = GTS CA 1C3
verify return:1
depth=0 CN = dns.google
verify return:1
DONE

New problem: Ever since I rebooted the ISP modem, and after I killed the session, when the script runs again, it connects once, then for some weird reason kills the connection and back to the loop we go

Here's the last few lines of the log from the time it connected and then killed thinking WAN is down (it's not since now I also have connmon running):

Spoiler: Script Log

Fri Sep 23 00:16:51 AST 2022 - VPNMON-R2 ----------> ERROR: Connection failed - Executing VPN Reset
Fri Sep 23 00:16:51 AST 2022 - VPNMON-R2 - Executing VPN Reset
Fri Sep 23 00:16:55 AST 2022 - VPNMON-R2 - Killed all VPN Client Connections
Fri Sep 23 00:17:27 AST 2022 - VPNMON-R2 - Updated Skynet Whitelist
Fri Sep 23 00:17:35 AST 2022 - VPNMON-R2 - Refreshed VPN Slots 1 - 5 from 2244 SuperRandom NordVPN Server Locations
Fri Sep 23 00:17:36 AST 2022 - VPNMON-R2 - Randomly selected VPN3 Client ON
Fri Sep 23 00:17:40 AST 2022 - VPNMON-R2 - VPN Reset Finished
Fri Sep 23 00:17:43 AST 2022 - VPNMON-R2 - Resuming normal operations
Fri Sep 23 00:18:12 AST 2022 - VPNMON-R2 - API call made to update WAN0 city to Los Angeles
Fri Sep 23 00:18:34 AST 2022 - VPNMON-R2 - API call made to update VPN city to Los Angeles
Fri Sep 23 00:19:54 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED
Fri Sep 23 00:20:00 AST 2022 - VPNMON-R2 - WAN Link Detected -- Trying to reconnect/Reset VPN
Fri Sep 23 00:21:04 AST 2022 - VPNMON-R2 - Executing VPN Reset
Fri Sep 23 00:21:08 AST 2022 - VPNMON-R2 - Killed all VPN Client Connections
Fri Sep 23 00:22:08 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED
Fri Sep 23 00:22:08 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED. VPN RESET TERMINATED.
Fri Sep 23 00:22:14 AST 2022 - VPNMON-R2 - WAN Link Detected -- Trying to reconnect/Reset VPN
Fri Sep 23 00:23:18 AST 2022 - VPNMON-R2 - Executing VPN Reset
Fri Sep 23 00:23:22 AST 2022 - VPNMON-R2 - Killed all VPN Client Connections

 

[Viktor Jaep]

Nope!

Hum. Well, just for grins, I killed my cable modem... let it sit in an off state for a few minutes, turned it back on, and watched VPNMON-R2 identify a WAN down scenario, wait until the WAN came back up, reconnect the VPN, and enter back into the normal operations mode. So I'm a bit baffled.

The state of your normal baseline, and when it's stuck in the loop is exactly the same. And with your WAN 0 state being 2 (normal connection), it shouldn't even be jumping to the conclusion thinking the WAN is down, because it's up. If this works for me, this should be working for you as well. The only other thing I can think of is that's one of these newer AXE16000... and so maybe we're looking at a bug of some sort??

Man... now I'm going to have to get myself an AXE16000 so I can TEST this out. Lol

 

[monakh]

Hum. Well, just for grins, I killed my cable modem... let it sit in an off state for a few minutes, turned it back on, and watched VPNMON-R2 identify a WAN down scenario, wait until the WAN came back up, reconnect the VPN, and enter back into the normal operations mode. So I'm a bit baffled.

The state of your normal baseline, and when it's stuck in the loop is exactly the same. And with your WAN 0 state being 2 (normal connection), it shouldn't even be jumping to the conclusion thinking the WAN is down, because it's up. If this works for me, this should be working for you as well. The only other thing I can think of is that's one of these newer AXE16000... and so maybe we're looking at a bug of some sort??

Man... now I'm going to have to get myself an AXE16000 so I can TEST this out. Lol

Hah, it's an expensive toy for sure and the only advantage, so far, over my trusty old AX88, is the faster VPN speed (not by much--certainly not by $700 much!)

I had to reboot my router and keep my fingers crossed and hope the script sticks (see my edit above to post #189). My intuition is telling me this is something super simple but I am no programmer so what do I know!?

 

[Viktor Jaep]

New problem: Ever since I rebooted the ISP modem, and after I killed the session, when the script runs again, it connects once, then for some weird reason kills the connection and back to the loop we go

OK... so this is pretty interesting.

Fri Sep 23 00:18:12 AST 2022 - VPNMON-R2 - API call made to update WAN0 city to Los Angeles
Fri Sep 23 00:18:34 AST 2022 - VPNMON-R2 - API call made to update VPN city to Los Angeles
Fri Sep 23 00:19:54 AST 2022 - VPNMON-R2 ----------> ERROR: WAN CONNECTIVITY ISSUE DETECTED
Fri Sep 23 00:20:00 AST 2022 - VPNMON-R2 - WAN Link Detected -- Trying to reconnect/Reset VPN

So the only way you would get this WAN CONNECTIVITY ISSUE DETECTED message is if the "nvram get wan0_state_t" or "nvram get wan1_state_t" does not equal 2... or if it fails that NC/Openssl connectivity test to 8.8.8.8.

Is there any possibility that your fiber modem is giving a false report? How about save this code into an .sh file (in your /jffs/scripts folder), and run this for a little while and see what kinds of results you get? It's an endless loop, so it should be interesting to see? (Or let me know if you want me to make a file out of this that you can download)

#!/bin/sh

while true; do

  wan0if=$(nvram get wan0_ifname)
  wan1if=$(nvram get wan1_ifname)
  wan0=$(nvram get wan0_state_t)
  wan1=$(nvram get wan1_state_t)

  echo "WAN0 IF:$wan0if State:$wan0 -- WAN1 IF:$wan1if State:$wan1"
  sleep 1

done

 

[monakh]

Naah, I can manage, I still remember some Linux from my wee days (am an IT guy). So I saved the code and left it running in another screen session. How long do you think I should let it run?

I guess it's possible the modem is giving a false reading with regard to the WAN session. It's Huawei after all!

Edit: Alrighty, am off to sleep it's about 1.30 am here. I'll catch you tomorrow. Thanks again for all your help.

 

[Viktor Jaep]

Naah, I can manage, I still remember some Linux from my wee days (am an IT guy). So I saved the code and left it running in another screen session. How long do you think I should let it run?

I guess it's possible the modem is giving a false reading with regard to the WAN session. It's Huawei after all!

Edit: Alrighty, am off to sleep it's about 1.30 am here. I'll catch you tomorrow. Thanks again for all your help.

Yeah, just long enough to see if it does anything funky off and on, like when you see vpnmon act up.

Thanks for your assistance today!

 

[monakh]

No issues for over 12 hours. Keeping my fingers crossed!

 

[Viktor Jaep]

No issues for over 12 hours. Keeping my fingers crossed!

How's things going @monakh! Has VPNMON fallen into any other crazy loops? Any leads on the output of the script you were running to see if the modem is causing invalid connection indications?

 

[monakh]

Hellos--OK--so I saw one issue (not sure if it's VPNMON related) which was exactly like before I installed the script. There was no internet. I didn't see any changes in the WAN0 state as per your script above--it has been 2 throughout (though maybe a timestamp would things more certain in terms of output?) The no internet issue was smack in the middle of the night after 2am so all I did was turn the VPN tunnel off in the router GUI. Woke up in the morning and the tunnel is back up which is good.

I'm gonna keep watching the WAN, looks like the resets are fewer than before so it's getting tougher to stay on top of it That's a good thing. Hope it stays that way. These Middle Easter ISPs are like the old AT&T before the Baby Bells--pretty much a monopoly that doesn't care about its customers. So it's hard to get their attention with cases like this.

 

[Viktor Jaep]

Hellos--OK--so I saw one issue (not sure if it's VPNMON related) which was exactly like before I installed the script. There was no internet. I didn't see any changes in the WAN0 state as per your script above--it has been 2 throughout (though maybe a timestamp would things more certain in terms of output?) The no internet issue was smack in the middle of the night after 2am so all I did was turn the VPN tunnel off in the router GUI. Woke up in the morning and the tunnel is back up which is good.

I'm gonna keep watching the WAN, looks like the resets are fewer than before so it's getting tougher to stay on top of it That's a good thing. Hope it stays that way. These Middle Easter ISPs are like the old AT&T before the Baby Bells--pretty much a monopoly that doesn't care about its customers. So it's hard to get their attention with cases like this.

That is strange. If the internet was down, the wan0 state should have changed to 0... it's like the router isn't recognizing it. Glad to hear that vpnmon reconnected for you, but wish it was more automated for you. Yeah that must be frustrating dealing with an ISP who isn't willing to help! Well, reach out if you see anything else, and will be happy to help troubleshoot!

 

[monakh]

Quick question for you, VJ?

Is it possible to use the Nord API to pull the recommended server only and create a list accordingly? I find that the recommended servers are suitable for watching US-based streaming. Most everything else (even if it's out of thousands of IPs) is blocked, so I would rather have a limited list--say dozens--as long as it works. The recommended server changes based on location, I think, not sure what the logic behind the change is but it changes for me frequently, almost on a daily basis. The server is here:

Server recommended by NordVPN

Getting annoyed by geographical restrictions? With NordVPN's American servers you can enjoy your favorite content in every part of USA.

nordvpn.com

Any idea?

 

[Viktor Jaep]

Quick question for you, VJ?

Is it possible to use the Nord API to pull the recommended server only and create a list accordingly? I find that the recommended servers are suitable for watching US-based streaming. Most everything else (even if it's out of thousands of IPs) is blocked, so I would rather have a limited list--say dozens--as long as it works. The recommended server changes based on location, I think, not sure what the logic behind the change is but it changes for me frequently, almost on a daily basis. The server is here:

Server recommended by NordVPN

Getting annoyed by geographical restrictions? With NordVPN's American servers you can enjoy your favorite content in every part of USA.

nordvpn.com

Any idea?

Yes, it's actually my intention to build that functionality in as well, and will start working on this option next. Thanks! In the interim, you could configure a few of your VPN slots with recommended servers and turn off the superrandom functionality, so that it will just pick from these preconfigured ones?