NordVPN client does not connect automatically after reboot on ASUS RT-AC68U

[dest8]

I have an ASUS RT-AC68U running ASUSWRT-Merlin firmware version 386.5.2.

The ASUS router is running under double NAT behind a service provider's router/fiber ONU, since internet subscribers here are not allowed to bridge the router.

I have a NordVPN client enabled in the RT-AC68U. It's running without problems.

The ASUS router is set to reboot via cron job (set up through amtm script) every 3:00 AM. The "Automatic start at boot time" setting in the GUI is set to "Yes."

After reboot, the "Service State" is always switched back to "OFF." I have to manually switch it to "ON" to start the NordVPN client every morning.

I have checked the settings, and all seem to be good (see attachments of the GUI settings and the VPN client custom configuration).

Please help resolve this problem. My networking knowledge is self-taught, do be patient if at times I'm slow in the uptake of technical info.

Thank you!

 

[GSpock]

first check the syslog.log file in /tmp to look for potentiel error messages ...

 

[dest8]

first check the syslog.log file in /tmp to look for potentiel error messages ...

Thank you for the hint.

I tried to check the syslog.txt saved from the router's GUI after a boot which I did a few minutes ago.

I cleared the log from the GUI a few times before booting the router. The saved contents after the boot were a mix of entries for May 3, May 4 (today's date) and May 5 (tomorrow's date!).

I tried to just look at the lines which have a datestamp/timestamp around the time I did the reboot. I'm not sure what to look for. Is there an NVRAM parameter setting that I should also check?

 

[GSpock]

It would be better if you could post the syslog file ; I suspect something is wrong with the date/time of your router (it would not sync with your ISP modem) and therefore your openvpn client cannot start

PS: you gui image is too small to be read ...

and also , May 5 is not the date of tomorrow, it is the intial internal date of the router when it boots .... it then needs to sync to get the correct date/time

Example of a boot log :

May  5 07:05:02 kernel: Linux version 4.1.52 (merlin@ubuntu-dev) (gcc version 5.5.0 (Buildroot 2017.11.1) ) #1 SMP PREEMPT Fri Mar 25 10:30:42 EDT 2022
May  5 07:05:02 kernel: CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d
May  5 07:05:02 kernel: CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
May  5 07:05:02 kernel: Machine model: Broadcom BCM947622
May  5 07:05:02 kernel: bootconsole [earlycon0] enabled
May  5 07:05:02 kernel: Memory policy: Data cache writealloc
May  5 07:05:02 kernel: PERCPU: Embedded 10 pages/cpu @dfbc9000 s11852 r8192 d20916 u40960
May  5 07:05:02 kernel: Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 130048
May  5 07:05:02 kernel: Kernel command line: isolcpus=3 root=ubi:rootfs_ubifs ubi.mtd=0 rootfstype=ubifs console=ttyAMA0 earlyprintk debug irqaffinity=0 pci=pcie_bus_safe
May  5 07:05:02 kernel: PID hash table entries: 2048 (order: 1, 8192 bytes)
May  5 07:05:02 kernel: Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
May  5 07:05:02 kernel: Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
May  5 07:05:02 kernel: Memory: 510132K/524288K available (4728K kernel code, 1726K rwdata, 1288K rodata, 212K init, 414K bss, 14156K reserved, 0K cma-reserved, 0K highmem)
May  5 07:05:02 kernel: Virtual kernel memory layout:
May  5 07:05:02 kernel:     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
May  5 07:05:02 kernel:     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
May  5 07:05:02 kernel: Architected cp15 timer(s) running at 50.00MHz (phys).
May  5 07:05:02 kernel: clocksource arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xb8812736b, max_idle_ns: 440795202655 ns
May  5 07:05:02 kernel: sched_clock: 56 bits at 50MHz, resolution 20ns, wraps every 4398046511100ns
May  5 07:05:02 kernel: Switching to timer-based delay loop, resolution 20ns
May  5 07:05:02 kernel: BRCM Legacy Drivers' Helper, all legacy drivers' IO memories/interrupts should be remapped here
May  5 07:05:02 kernel:      Remapping interrupts...
May  5 07:05:02 kernel:              hwirq      virq
May  5 07:05:34 rc_service: udhcpc_lan 2354:notify_rc stop_ntpd
May  5 07:05:34 rc_service: udhcpc_lan 2354:notify_rc start_ntpd
May  5 07:05:34 rc_service: waitting "stop_ntpd" via udhcpc_lan ...
May  5 07:05:35 ntpd: Started ntpd
May  5 07:05:35 rc_service: udhcpc_lan 2354:notify_rc restart_dms
May  5 07:05:35 rc_service: udhcpc_lan 2354:notify_rc restart_samba
May  5 07:05:35 rc_service: waitting "restart_dms" via udhcpc_lan ...
May  5 07:05:36 wsdd2[2334]: Terminated received.
May  5 07:05:36 wsdd2[2334]: terminating.
May  5 07:05:37 Samba_Server: smb daemon is stopped
May  5 07:05:37 Samba_Server: daemon is started
May  5 07:05:37 wsdd2[2416]: starting.
May  2 14:36:50 ntpd: Initial clock set
May  2 14:36:50 rc_service: ntpd_synced 2418:notify_rc restart_diskmon
May  2 14:36:50 disk_monitor: Finish
May  2 14:36:50 disk_monitor: be idle
May  2 14:36:57 wifi_scheduler: Turn radio [band_index=0] on.
May  2 14:36:57 wifi_scheduler: Turn radio [band_index=1] on.
May  2 14:36:59 kernel: CSIMON:  CSIMON[1.1.0] Initialization
May  2 14:36:59 kernel: CSIMON: M2M usr already registered ...
May  2 14:36:59 kernel: CSIMON:  CSIMON[1.1.0] Initialization
May  2 14:36:59 kernel: CSIMON: M2M usr already registered ...
May  2 14:37:05 rc_service: amas_lanctrl 2054:notify_rc stop_acsd
May  2 14:37:14 crond[2031]: time disparity of 2099972 minutes detected

 

[Jaime Alvarez]

The ASUS router is set to reboot via cron job (set up through amtm script) every 3:00 AM. The "Automatic start at boot time" setting in the GUI is set to "Yes."

After reboot, the "Service State" is always switched back to "OFF." I have to manually switch it to "ON" to start the NordVPN client every morning.

Just in case... did you clicked on the "Apply" button after setting the "Automatic start at boot time" to "Yes."?
It has happened to me before ;-)

 

[dest8]

Just in case... did you clicked on the "Apply" button after setting the "Automatic start at boot time" to "Yes."?
It has happened to me before ;-)

Yes, I did.

I also tried to power down/power up the router to reboot, instead of using the GUI's reboot button, but the problem persisted.

 

[octopus]

VPN wont start if time is not set before VPN trying to start.

 

[dest8]

It would be better if you could post the syslog file ; I suspect something is wrong with the date/time of your router (it would not sync with your ISP modem) and therefore your openvpn client cannot start

PS: you gui image is too small to be read ...

and also , May 5 is not the date of tomorrow, it is the intial internal date of the router when it boots .... it then needs to sync to get the correct date/time

Example of a boot log :

May  5 07:05:02 kernel: Linux version 4.1.52 (merlin@ubuntu-dev) (gcc version 5.5.0 (Buildroot 2017.11.1) ) #1 SMP PREEMPT Fri Mar 25 10:30:42 EDT 2022
May  5 07:05:02 kernel: CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d
May  5 07:05:02 kernel: CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
May  5 07:05:02 kernel: Machine model: Broadcom BCM947622
May  5 07:05:02 kernel: bootconsole [earlycon0] enabled
May  5 07:05:02 kernel: Memory policy: Data cache writealloc
May  5 07:05:02 kernel: PERCPU: Embedded 10 pages/cpu @dfbc9000 s11852 r8192 d20916 u40960
May  5 07:05:02 kernel: Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 130048
May  5 07:05:02 kernel: Kernel command line: isolcpus=3 root=ubi:rootfs_ubifs ubi.mtd=0 rootfstype=ubifs console=ttyAMA0 earlyprintk debug irqaffinity=0 pci=pcie_bus_safe
May  5 07:05:02 kernel: PID hash table entries: 2048 (order: 1, 8192 bytes)
May  5 07:05:02 kernel: Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
May  5 07:05:02 kernel: Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
May  5 07:05:02 kernel: Memory: 510132K/524288K available (4728K kernel code, 1726K rwdata, 1288K rodata, 212K init, 414K bss, 14156K reserved, 0K cma-reserved, 0K highmem)
May  5 07:05:02 kernel: Virtual kernel memory layout:
May  5 07:05:02 kernel:     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
May  5 07:05:02 kernel:     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
May  5 07:05:02 kernel: Architected cp15 timer(s) running at 50.00MHz (phys).
May  5 07:05:02 kernel: clocksource arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xb8812736b, max_idle_ns: 440795202655 ns
May  5 07:05:02 kernel: sched_clock: 56 bits at 50MHz, resolution 20ns, wraps every 4398046511100ns
May  5 07:05:02 kernel: Switching to timer-based delay loop, resolution 20ns
May  5 07:05:02 kernel: BRCM Legacy Drivers' Helper, all legacy drivers' IO memories/interrupts should be remapped here
May  5 07:05:02 kernel:      Remapping interrupts...
May  5 07:05:02 kernel:              hwirq      virq
May  5 07:05:34 rc_service: udhcpc_lan 2354:notify_rc stop_ntpd
May  5 07:05:34 rc_service: udhcpc_lan 2354:notify_rc start_ntpd
May  5 07:05:34 rc_service: waitting "stop_ntpd" via udhcpc_lan ...
May  5 07:05:35 ntpd: Started ntpd
May  5 07:05:35 rc_service: udhcpc_lan 2354:notify_rc restart_dms
May  5 07:05:35 rc_service: udhcpc_lan 2354:notify_rc restart_samba
May  5 07:05:35 rc_service: waitting "restart_dms" via udhcpc_lan ...
May  5 07:05:36 wsdd2[2334]: Terminated received.
May  5 07:05:36 wsdd2[2334]: terminating.
May  5 07:05:37 Samba_Server: smb daemon is stopped
May  5 07:05:37 Samba_Server: daemon is started
May  5 07:05:37 wsdd2[2416]: starting.
May  2 14:36:50 ntpd: Initial clock set
May  2 14:36:50 rc_service: ntpd_synced 2418:notify_rc restart_diskmon
May  2 14:36:50 disk_monitor: Finish
May  2 14:36:50 disk_monitor: be idle
May  2 14:36:57 wifi_scheduler: Turn radio [band_index=0] on.
May  2 14:36:57 wifi_scheduler: Turn radio [band_index=1] on.
May  2 14:36:59 kernel: CSIMON:  CSIMON[1.1.0] Initialization
May  2 14:36:59 kernel: CSIMON: M2M usr already registered ...
May  2 14:36:59 kernel: CSIMON:  CSIMON[1.1.0] Initialization
May  2 14:36:59 kernel: CSIMON: M2M usr already registered ...
May  2 14:37:05 rc_service: amas_lanctrl 2054:notify_rc stop_acsd
May  2 14:37:14 crond[2031]: time disparity of 2099972 minutes detected

Thanks for explaining the different timestamps on the syslog. It's a coincidence that today's date is May 4th (local), so the May 5th date made me confused. I will post the syslog.

Attached is the VPN Client settings in the GUI for your review, in PDF format. I apologize as it seems I can't attach/insert a high resolution image.

 

[dest8]

VPN wont start if time is not set before VPN trying to start.

How would one ensure that the time is set before restarting VPN?

 

[octopus]

How would one ensure that the time is set before restarting VPN?

Make sure your router can see internet when after rebooting.

 

[dest8]

Make sure your router can see internet when after rebooting.

Internet is automatically reconnected after booting.

 

[dest8]

Make sure your router can see internet when after rebooting.

Internet is automatically reconnected after booting.

 

[octopus]

Internet is automatically reconnected after booting.

Yes. If its takes time to get ntp to start and vpn trying to start before. Thats the problems.

 

[dest8]

It would be better if you could post the syslog file ; I suspect something is wrong with the date/time of your router (it would not sync with your ISP modem) and therefore your openvpn client cannot start

PS: you gui image is too small to be read ...

and also , May 5 is not the date of tomorrow, it is the intial internal date of the router when it boots .... it then needs to sync to get the correct date/time

I have the syslog.txt file - it's 273 KB in size. I'm failing in attaching it as a file, or posting it as a code here. Any suggestion on how to get the syslog to you?

 

[dest8]

Yes. If its takes time to get ntp to start and vpn trying to start before. Thats the problems.

How to make sure that NTP process is completed before starting the VPN process? Is there a way to add a delay or is there a setting that needs to be changed?

 

[L&LD]

Use Pastebin.com - #1 paste tool since 2002! to attach files here.

 

[eibgrad]

First thing I would do is remove ALL of those directives from the custom config field. NONE of them are actually necessary. The router takes care of 99% of these for you, and whatever else remains usually ends up being irrelevant. In fact, sometimes things in that field do more harm than good. For example, reneg-sec 0 disables session key updates (which means no more perfect forward secrecy). disable-occ disables error messages (that's the last thing you want if you're trying to debug something). Etc.

The only things worth keeping imo are the pull-filter and remote-cert-tls server directives. But even so, when debugging in particular, the less you modify the GUI using the custom config field, the better. I've yet to see a circumstance where anything in that field was required to get the basic thing working. But I've seen plenty of examples where it broke stuff. If later, after resolving all other issues, you decide to investigate using those directives, that's up to you. But it should always be the LAST thing you do.

Also, the fact the OpenVPN client is set to OFF is unlikely to be due to that setting NOT being preserved across a reboot, but more likely due to the router trying multiple times to get the OpenVPN client started after a reboot and failing, eventually exceeding the retry limit. At that point, the OpenVPN client shuts down completely and shows OFF.

And another thing. You provided no information regarding DNS settings other than those configured on the OpenVPN client itself. Seems likely to me this is a DNS issue. As if the server's domain name can't be resolved on a reboot for some reason. You might try using an explicit server IP instead to see if it now works reliably. At least that would strongly suggest it is a DNS issue and narrow down the problem.

 

[dest8]

It would be better if you could post the syslog file ; I suspect something is wrong with the date/time of your router (it would not sync with your ISP modem) and therefore your openvpn client cannot start

PS: you gui image is too small to be read ...

and also , May 5 is not the date of tomorrow, it is the intial internal date of the router when it boots .... it then needs to sync to get the correct date/time

Example of a boot log :

Here's the syslog.txt file after reboot:

syslog.txt [Boot 04-May-2020 1930H]

 

[dest8]

First thing I would do is remove ALL of those directives from the custom config field. NONE of them are actually necessary. The router takes care of 99% of these for you, and whatever else remains usually ends up being irrelevant. In fact, sometimes things in that field do more harm than good. For example, reneg-sec 0 disables session key updates (which means no more perfect forward secrecy). disable-occ disables error messages (that's the last thing you want if you're trying to debug something). Etc.

The only things worth keeping imo are the pull-filter and remote-cert-tls server directives. But even so, when debugging in particular, the less you modify the GUI using the custom config field, the better. I've yet to see a circumstance where anything in that field was required to get the basic thing working. But I've seen plenty of examples where it broke stuff. If later, after resolving all other issues, you decide to investigate using those directives, that's up to you. But it should always be the LAST thing you do.

Also, the fact the OpenVPN client is set to OFF is unlikely to be due to that setting NOT being preserved across a reboot, but more likely due to the router trying multiple times to get the OpenVPN client started after a reboot and failing, eventually exceeding the retry limit. At that point, the OpenVPN client shuts down completely and shows OFF.

And another thing. You provided no information regarding DNS settings other than those configured on the OpenVPN client itself. Seems likely to me this is a DNS issue. As if the server's domain name can't be resolved on a reboot for some reason. You might try using an explicit server IP instead to see if it now works reliably. At least that would strongly suggest it is a DNS issue and narrow down the problem.

Thank you for the hints. I will try all your suggestions and will post an update.

Appreciate all of your patience.

 

[ColinTaylor]

I see this message in your log file:

May  5 13:05:09 wanduck: WARNING - router is in manufacturing mode, and can behave unexpectedly (did you mess with your bootloader?)

So the obvious question is have you modified the bootloader? Is the router a genuine RT-AC68U or a modified TMobile device?