What's new

Merlin 386.5.2 bug: OpenVPN Server does not start after router restart (scheduled restart, explicit restart, or power reset)

  • SNBForums Code of Conduct

    SNBForums is a community for everyone, no matter what their level of experience.

    Please be tolerant and patient of others, especially newcomers. We are all here to share and learn!

    The rules are simple: Be patient, be nice, be helpful or be gone!

Well I'll take a look and see if I can reproduce the problem now that I have a better understanding. But again, if it's a very rare occurrence, that could still be difficult.

In the meantime, it might be prudent to create a simple script that runs on bootup and waits for the OpenVPN server to come online, then force a restart. Presumably that will workaround the issue, if NOT necessarily fix it.
 
Last edited:
I created a simple script to automatically restart the OpenVPN servers once they become established.


It's only intended as a workaround until the underlying problem can be reproduced and corrected.

Directions for installation are provided in the script.
 
I updated the script to v1.1.0. I decided to also check the OpenVPN server "state", just to be sure the server wasn't in some quasi up state, but clearly established.

I still can't reproduce the problem. I've tried pulling the power cord on the router, blocking NTP, rebooting every 5 mins, etc., and it works just fine. I can only assume the problem is most likely caused by a power surge, which makes it effectively unrepeatable for diagnostic purposes.

As mentioned previously, if remote access is critical to your setup, consider using a UPS, esp. if you're using USB drives. Unexpected power loss can corrupt partitions and partition tables too.
 
I can reproduce this quite frequently now, just by rebooting the router (by clicking the Reboot button in the UI). It also happens during a power cycle sometimes. I'm on the latest firmware 386.7_2
 
Sounds like your router is damaged from the power outages.

Or, a full reset to factory defaults is required.

The issues you're stating are not an issue for every other user (at least, not on these forums).

You can try a new power supply to see if it fixes anything.

But a full reset to factory defaults (multiple times and with multiple methods, including reflashing the same firmware you're using now) will be (also) needed to rule out a hardware issue.
 
I can reproduce this quite frequently now, just by rebooting the router (by clicking the Reboot button in the UI). It also happens during a power cycle sometimes. I'm on the latest firmware 386.7_2
Provide logs from the router and the client showing the failing connection attempt. That will help to pinpoint the problem.
 
As mentioned previously, if remote access is critical to your setup, consider using a UPS, esp. if you're using USB drives. Unexpected power loss can corrupt partitions and partition tables too.
You are correct about a UPS.

IMHO, a UPS should be considered mandatory on all networking equipment. I have UPS units on all my electronics with the exceptions of some IoT devices.
 
How do I obtain server logs? I can ssh in and get them from a system file, or I can get them from the UI, thanks for any advice.
The OpenVPN server logs to the general system log which you can view and save from System Log - General Log. Or you can copy them directly from the files at /tmp/syslog.log and /tmp/syslog.log-1. The client's log should be available within whatever application you're using.
 
It keeps happening. Due to many power outages in my area, I'm always forced to log in after every power outage, turn off the VPN, and turn on the VPN again. I wonder if the stock firmware (non-Merlin) has this bug too? I'd gladly switch just to avoid this bug.

This is what the client side log says (Viscosity) while it fails to connect to the VPN server:

Code:
2022-10-20 18:57:11: SIGUSR1[connection failed(soft), init_instance] received, process restarting
2022-10-20 18:57:11: Valid endpoint found: X.X.X.X:1194: tcp-client
2022-10-20 18:57:11: TCP/UP: Preserving recently used remote address: [AF_INET]X.X.X.X:1194
2022-10-20 18:57:11: Attempting to establish TCP connection with [AF_INET]X.X.X.X:1194 [nonblock]
2022-10-20 18:58:33: TCP: connect to [AF_INET]X.X.X.X:1194 failed: Operation timed out
2022-10-20 18:58:33: SIGUSR1[connection failed(soft), init_instance] received, process restarting
2022-10-20 18:58:33: Valid endpoint found: X.X.X.X:1194:tcp-client
2022-10-20 18:58:33: TCP/UP: Preserving recently used remote address: [AF_INET]X.X.X.X:1194
2022-10-20 18:58:33: Attempting to establish TCP connection with [AF_INET]X.X.X.X:1194 [nonblock]
 
Last edited:
I realize I should have sent this, but by the time I checked the log was wiped.
It shouldn't be wiped unless you manually did it through the GUI or did a hard factory reset. The system log files are periodically copied to jffs so that they are preserved and restored over a reboot.

I assume /tmp/syslog.log is the log on the router.
Correct. The previous log (if it's rolled over) is /tmp/syslog.log-1.
 
It shouldn't be wiped unless you manually did it through the GUI or did a hard factory reset. The system log files are periodically copied to jffs so that they are preserved and restored over a reboot.


Correct. The previous log (if it's rolled over) is /tmp/syslog.log-1.
There's nothing of interest in the /tmp/syslog.log other than these lines:

May 5 01:02:31 dnsmasq-dhcp[412]: DHCPOFFER(br0) 192.168.2.77 00:5d:59:b3:74:75
May 5 01:02:32 dnsmasq-dhcp[412]: DHCPDISCOVER(br0) 00:5d:59:b3:74:75
May 5 01:10:49 miniupnpd[1726]: SoapMethod: Unknown: GetPortMappingNumberOfEntries urn:schemas-upnp-org:service:WANIPConnection:1
May 5 01:38:32 syslog: wlceventd_proc_event(491): eth1: Deauth_ind 3C:1D:66:DA:BC:7C, status: 0, reason: Disassociated due to inactivity (4), rssi:0
May 5 01:38:32 syslog: wlceventd_proc_event(508): eth1: Disassoc 3C:1D:66:DA:BC:7C, status: 0, reason: Disassociated because sending station is leaving (or has left) BSS (8), rssi:0
May 5 02:01:40 syslog: wlceventd_proc_event(527): eth1: Auth 4C:1D:36:DA:BC:7C, status: Successful (0), rssi:0
May 5 02:01:40 syslog: wlceventd_proc_event(556): eth1: Assoc 4C:1D:36:DA:BC:7C, status: Successful (0), rssi:0

The VPN client cannot connect until the VPN is manually turned off on the router and then turned on again. Note how when the router reboots it thinks the date today is May 5, 2018.
 
When I turned off the VPN and on again, it worked. Here's what happened in the log:

May 5 07:26:06 rc_service: httpds 421:notify_rc stop_vpnserver1
...
May 5 07:26:48 rc_service: httpds 421:notify_rc restart_chpass;restart_vpnserver1
...
May 5 07:26:51 ovpn-server1[6635]: ovpn-up 1 server tun21 1500 1624 10.8.0.1 255.255.255.0 init
 
Note how when the router reboots it thinks the date today is May 5, 2018.
That's normal initially. After the router connects to the internet it should update the time via NTP. If it doesn't correct the time this will cause problems, especially for things that rely on having the correct time like VPNs.

Upload the complete unedited syslog to pastebin.com and provide a link to it for us to looks at. Seeing all the messages in context is important. Knowing what messages are not there is as important as those that are.
 
I'm curious about this one, because I recently experienced 2 power outages in a row where I lost openvpn access. One of the times I was away from home, had my daughter power off/on the router with the switch, and the server started working again. Not sure if it has to do with my ISP's gateway device... I have fiber in home, and the fiber gateway powered down in both instances. I'm also using ntpmerlin and unbound for dns.

This was with a ups, with a 24hr and a 72hr outage.
 
Last edited:
That's normal initially. After the router connects to the internet it should update the time via NTP. If it doesn't correct the time this will cause problems, especially for things that rely on having the correct time like VPNs.

Upload the complete unedited syslog to pastebin.com and provide a link to it for us to looks at. Seeing all the messages in context is important. Knowing what messages are not there is as important as those that are.

It happened again. Power outage and router restart with VPN disalbed (even though it says OpenVPN Server ON in the Merlin GUI). The only fix is to turn it OFF and ON again. This time I have all the logs, /tmp/syslog.log and /tmp/syslog.log-1. Can I private message them to you? Not sure if logs expose anything sensitive.
 
It happened again. Power outage and router restart with VPN disalbed (even though it says OpenVPN Server ON in the Merlin GUI). The only fix is to turn it OFF and ON again. This time I have all the logs, /tmp/syslog.log and /tmp/syslog.log-1. Can I private message them to you? Not sure if logs expose anything sensitive.
Yes, send them via a private message or a password protected pastebin.com link.
 

Latest threads

Support SNBForums w/ Amazon

If you'd like to support SNBForums, just use this link and buy anything on Amazon. Thanks!

Sign Up For SNBForums Daily Digest

Get an update of what's new every day delivered to your mailbox. Sign up here!
Top