What's new

Asus RT-AC86U OpenVPN server doesn't start up on router reboot

  • 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!

treetrunk

Occasional Visitor
I recently purchased an AC86U (running Merlin's firmware 384.4_2) for its upgraded RAM and CPU, an upgrade from my AC68P. Anyway, I run an OpenVPN server on the router and noticed that the OpenVPN server doesn't start up automatically when the router reboots.

Any ideas how to fix this issue?
 
Have to enable "Start with WAN".
 
Have to enable "Start with WAN".

I don't see that anywhere in the server settings. Note the server status and it shows that the server is being initialized indefinitely. See screenshots. Once I hit the "apply" button, the server starts up
 

Attachments

  • Screen Shot 2018-04-15 at 9.29.47 PM.png
    Screen Shot 2018-04-15 at 9.29.47 PM.png
    112.7 KB · Views: 1,273
  • Screen Shot 2018-04-15 at 9.30.00 PM.png
    Screen Shot 2018-04-15 at 9.30.00 PM.png
    388.5 KB · Views: 1,132
Last edited:
I had ab-solution and Skynet running, so I uninstalled those, re-initialized my AC86U (cleared nvram and jffs) and set it up manually as before. It may or may not be relevant, but I still have Asus's Download Master running. The VPN server still doesn't come up automatically.
I looked in the system log and see the following two lines:
"Apr 16 06:32:15 rc_service: udhcpc 910:notify_rc start_vpnserver1"
"Apr 16 06:32:30 rc_service: skip the event: start_vpnserver1."
 
Sorry, I missed the bit mentioning this was on a server.

The start event gets skipped because probably a previous event is getting stuck. What are the previous rc_service entries saying?
 
Sorry, I missed the bit mentioning this was on a server.

The start event gets skipped because probably a previous event is getting stuck. What are the previous rc_service entries saying?

here's a snippet of what I think are relevant entries (others removed).
Also. I powered cycled the router and the VPN server came up. Then I rebooted it from the webui about 5 times and on the 5th the server wouldn't come back up

Apr 16 07:17:01 ovpn-server1[3151]: event_wait : Interrupted system call (code=4)

Apr 16 07:17:01 ovpn-server1[3151]: Closing TUN/TAP interface

Apr 16 07:17:01 ovpn-server1[3151]: /bin/ip addr del dev tun21 10.8.0.1/24

Apr 16 07:17:01 lldpd[878]: removal request for address of 10.8.0.1%23, but no knowledge of it

Apr 16 07:17:01 ovpn-server1[3151]: PLUGIN_CLOSE: /usr/lib/openvpn-plugin-auth-pam.so



Apr 16 07:18:04 rc_service: udhcpc 911:notify_rc start_firewall

Apr 16 07:18:04 rc_service: udhcpc 911:notify_rc start_vpnserver1

Apr 16 07:18:04 rc_service: waitting "start_firewall" via udhcpc ...

Apr 16 07:18:04 nat: apply nat rules (/tmp/nat_rules_eth0_eth0)

Apr 16 07:18:05 Username: sh /opt/S50asuslighttpd.1 firewall-start

Apr 16 07:18:05 Username: sh /opt/S50downloadmaster.1 firewall-start

Apr 16 07:18:06 Username: sh /opt/S50downloadmaster.1 start



Apr 16 07:18:08 rc_service: ntp 942:notify_rc restart_upnp

Apr 16 07:18:08 rc_service: waitting "start_firewall" via udhcpc ...

Apr 16 07:18:16 kernel: ubi1: attaching mtd9

Apr 16 07:18:16 kernel: ubi1: scanning is finished

Apr 16 07:18:16 kernel: ubi1: attached mtd9 (name "misc1", size 8 MiB)

Apr 16 07:18:16 kernel: ubi1: PEB size: 131072 bytes (128 KiB), LEB size: 126976 bytes

Apr 16 07:18:16 kernel: ubi1: min./max. I/O unit sizes: 2048/2048, sub-page size 2048

Apr 16 07:18:16 kernel: ubi1: VID header offset: 2048 (aligned 2048), data offset: 4096

Apr 16 07:18:16 kernel: ubi1: good PEBs: 64, bad PEBs: 0, corrupted PEBs: 0

Apr 16 07:18:16 kernel: ubi1: user volume: 1, internal volumes: 1, max. volumes count: 128

Apr 16 07:18:16 kernel: ubi1: max/mean erase counter: 3/2, WL threshold: 4096, image sequence number: 1960956644

Apr 16 07:18:16 kernel: ubi1: available PEBs: 0, total reserved PEBs: 64, PEBs reserved for bad PEB handling: 4

Apr 16 07:18:16 kernel: ubi1: background thread "ubi_bgt1d" started, PID 2460

Apr 16 07:18:17 kernel: UBIFS (ubi1:0): UBIFS: mounted UBI device 1, volume 0, name "nvram", R/O mode

Apr 16 07:18:17 kernel: UBIFS (ubi1:0): LEB size: 126976 bytes (124 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes

Apr 16 07:18:17 kernel: UBIFS (ubi1:0): FS size: 5840896 bytes (5 MiB, 46 LEBs), journal size 1015809 bytes (0 MiB, 6 LEBs)

Apr 16 07:18:17 kernel: UBIFS (ubi1:0): reserved for root: 275879 bytes (269 KiB)

Apr 16 07:18:17 kernel: UBIFS (ubi1:0): media format: w4/r0 (latest is w4/r0), UUID 700E756D-208E-4C91-B256-B51AA3EDE77F, small LPT model

Apr 16 07:18:17 kernel: UBIFS (ubi1:0): un-mount UBI device 1

Apr 16 07:18:17 kernel: ubi1: detaching mtd9

Apr 16 07:18:17 kernel: ubi1: mtd9 is detached

Apr 16 07:18:18 watchdog: start ddns.

Apr 16 07:18:18 rc_service: watchdog 828:notify_rc restart_ddns

Apr 16 07:18:18 rc_service: waitting "start_firewall" via udhcpc ...

Apr 16 07:18:20 rc_service: skip the event: start_vpnserver1.



Apr 16 07:18:20 start_ddns: update WWW.ASUS.COM dyndns, wan_unit 0

Apr 16 07:18:20 ddns_update: ez-ipupdate: starting...

Apr 16 07:18:20 ddns_update: connected to nwsrv-ns1.asus.com (103.10.4.108) on port 80.

Apr 16 07:18:20 transmission-daemon[3011]: Transmission 2.92 (14714) started (session.c:768)

Apr 16 07:18:20 transmission-daemon[3011]: RPC Server Adding address to whitelist: 127.0.0.1 (rpc-server.c:1124)

Apr 16 07:18:20 transmission-daemon[3011]: RPC Server Adding address to whitelist: *.*.*.* (rpc-server.c:1124)

Apr 16 07:18:20 transmission-daemon[3011]: RPC Server Serving RPC and Web requests on port 127.0.0.1:9091/transmission/ (rpc-server.c:1334)

Apr 16 07:18:20 transmission-daemon[3011]: RPC Server Whitelist enabled (rpc-server.c:1338)

Apr 16 07:18:20 transmission-daemon[3011]: RPC Server Password required (rpc-server.c:1341)

Apr 16 07:18:20 transmission-daemon[3011]: UDP Failed to set receive buffer: requested 4194304, got 1048576 (tr-udp.c:84)

Apr 16 07:18:20 transmission-daemon[3011]: UDP Please add the line "net.core.rmem_max = 4194304" to /etc/sysctl.conf (tr-udp.c:89)

Apr 16 07:18:20 transmission-daemon[3011]: DHT Generating new id (tr-dht.c:311)

Apr 16 07:18:20 transmission-daemon[3011]: Using settings from "/tmp/mnt/storage/Download2/config" (daemon.c:578)

Apr 16 07:18:20 transmission-daemon[3011]: Saved "/tmp/mnt/storage/Download2/config/settings.json" (variant.c:1269)

Apr 16 07:18:20 transmission-daemon[3011]: transmission-daemon requiring authentication (daemon.c:604)

Apr 16 07:18:20 transmission-daemon[3011]: Port Forwarding (NAT-PMP) initnatpmp succeeded (0) (natpmp.c:70)

Apr 16 07:18:20 transmission-daemon[3011]: Port Forwarding (NAT-PMP) sendpublicaddressrequest succeeded (2) (natpmp.c:70)

Apr 16 07:18:20 ddns_update: Asus update entry:: return: HTTP/1.1 200 OK^M Date: Mon, 16 Apr 2018 14:18:19 GMT^M Server: Apache^M X-Powered-By: PHP/5.6.30^M Content-Length: 0^M Connection: close^M Content-Type: text/html; charset=UTF-8^M ^M

Apr 16 07:18:20 ddns_update: retval= 0, ddns_return_code (,200)

Apr 16 07:18:20 ddns_update: asusddns_update: 0

Apr 16 07:18:20 ddns: ddns update ok



Apr 16 07:18:27 crond[803]: time disparity of 614298 minutes detected

Apr 16 07:18:28 transmission-daemon[3011]: Port Forwarding State changed from "Not forwarded" to "Starting" (port-forwarding.c:92)

Apr 16 07:18:29 rc_service: hotplug 1193:notify_rc restart_nasapps

Apr 16 07:18:29 iTunes: daemon is stopped

Apr 16 07:18:29 FTP_Server: daemon is stopped

Apr 16 07:18:29 Samba_Server: smb daemon is stopped

Apr 16 07:18:29 Timemachine: daemon is stopped

Apr 16 07:18:29 Samba_Server: daemon is started
 
add user or change Username / Password Auth. Only to No.
I changed it to "no" which means that it uses certificates in addition to username/password, correct?
I'm also having a difficult time seeing how that would be related to an intermittent startup failure of the server. Could you explain that one? Reading the log carefully, it seems like the vpnserver is waiting on the firewall to startup.

EDIT: There is a user, it's the same account that I use to login to the router, I just hid it in the screenshot.

EDIT2: Set it to "no" and several reboots later, vpnserver fails to startup again
 
Last edited:
There is no graphical way to make the OpenVPN server use both password AND cert.

It can be done you just need to do it through scripts. Did it myself. Rather easy.
 
There is no graphical way to make the OpenVPN server use both password AND cert.

Setting "Username / Password Auth. Only" to No should do that. Note however that this setting does not exist in the stock firmware, only on mine.

The OP is experiencing a different issue, seems that something in his boot process is taking too long to proceed, causing the start_vpnserver1 event to time out and be dropped. (and since Asus closed the rc_service source code about two years ago, I can no longer extend that timeout value like I used to do).

We'd need the complete syslog starting at boot to determine which process is blocking the rest.
 
Setting "Username / Password Auth. Only" to No should do that. Note however that this setting does not exist in the stock firmware, only on mine.

The OP is experiencing a different issue, seems that something in his boot process is taking too long to proceed, causing the start_vpnserver1 event to time out and be dropped. (and since Asus closed the rc_service source code about two years ago, I can no longer extend that timeout value like I used to do).

We'd need the complete syslog starting at boot to determine which process is blocking the rest.

I added a line to firewall-start:
service start_vpnserver1

This seems to force the vpnserver to start and mimic the behavior of me pressing the apply button in the vpn server settings. I rebooted the router close to 15 times now and no issues yet.
I can post a full syslog if you'd like to potentially track down any bugs in your code, or for any other debugging issues.
 
I added a line to firewall-start:
service start_vpnserver1

This seems to force the vpnserver to start and mimic the behavior of me pressing the apply button in the vpn server settings. I rebooted the router close to 15 times now and no issues yet.
I can post a full syslog if you'd like to potentially track down any bugs in your code, or for any other debugging issues.
I think it is better to set it at init-start script and what I did was a sleep 100 before the vpnserver start. This will ensure all stuff required by the vpnserver is started properly. In my case it was due to ddns wasn't ready before the initial start of my vpnserver.

Reason why I suggest to put in init-start is because the problem is due to router reboot and init-start script only used once there. Whereas I think the firewall-start script may be used during operation at some time. Like skynet using it.
 
I think it is better to set it at init-start script and what I did was a sleep 100 before the vpnserver start. This will ensure all stuff required by the vpnserver is started properly. In my case it was due to ddns wasn't ready before the initial start of my vpnserver.
Reason why I suggest to put in init-start is because the problem is due to router reboot and init-start script only used once there. Whereas I think the firewall-start script may be used during operation at some time. Like skynet using it.

I found a similar problem when I reinstalled skynet, because the call to start it in firewall-start was after my call to start the vpnserver, my vpnserver would hang just as before. So, I moved my call to the end and put a sleep timer just before for 2min and that seemed to fix the issue once and for all. Fingers crossed.

How did you determine it was due to ddns not starting up?
 
I found a similar problem when I reinstalled skynet, because the call to start it in firewall-start was after my call to start the vpnserver, my vpnserver would hang just as before. So, I moved my call to the end and put a sleep timer just before for 2min and that seemed to fix the issue once and for all. Fingers crossed.

How did you determine it was due to ddns not starting up?
I read the syslog and it just happened to be this way..

This is my post just last week.
https://www.snbforums.com/threads/question-failed-to-start-openvpn-server-at-bootup.45998/
 

Sign Up For SNBForums Daily Digest

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