What's new

Solved OpenVPN problem on RT-AC86U after upgrade to 386.4 - server daemon fails to start with DNS resolution error

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

bjark

New Around Here
Short summary:
After upgrading to firmware version 386.4 OpenVPN server daemon fails to start. In the log is reported an error attempting DNS resolution of my public hostname. Advice appreciated.


Background:
I've used Merlin on my RT-AC86U router since a long time, keeping the firmware regularly updated without problems. I haven't had any troubles just upgrading and running with the already present configuration.
I use two instances (for two separate listening ports) of OpenVPN server, and it has also run without trouble for a long time. I am using the VPN(s) every day from several devices. However, it is long since I set up the server, and I am not very familiar with the settings and inner workings of OpenVPN.
My router is on a dynamic public IP address and I have a (static) public hostname which resolves to the dynamic IP address. Connecting to the public hostname works (/has been working?) well both from inside my LAN and everywhere else with NAT loopback.

Current Problem:
Yesterday I upgraded the router firmware from 386.3_2 to 386.4, and after the upgrade everything works well except the OpenVPN servers. I immediately noticed that they didn't respond to connection attempts.

What I've found out:
On the Advanced Settings -> VPN -> VPN Server - OpenVPN -> Basic Config -> Server 1/Server 2 pages in the "Export OpenVPN configuration file" is an error message saying "OpenVPN server daemon failed to start. Please check your device environment or contents on the Advanced Setting page.".
In the router logs I see repeated (every 2 minutes) attempts to initialize the VPN servers which all seem to end with a DNS resolution problem, see log excerpts below. After a while the logs are different (also included below) - perhaps this change in behavior could be obstructing my troubleshooting attempts..?

What I've tried:
  • Rebooting the router (of course), but I have not (yet) tried a factory reset and re-importing or manually re-entering all settings again.
  • Checked that my public hostname seems to resolve well both inside my LAN and from everywhere else.
  • Exporting and re-importing OpenVPN server certifications.
  • Disabling and re-enabling the VPN servers.
  • Clearing the Custom Configuration settings - still the same problem.

I'm most thankful for any help to understand or solve this problem.

Further details - log excerpt and VPN configuration:
Default message log level: notice
Log only messages more urgent than: info
Code:
rc_service: service 7987:notify_rc restart_vpnserver1
rc_service: service 7988:notify_rc restart_vpnserver2
rc_service: waitting "restart_vpnserver1" via service ...
ovpn-server1[8054]: OpenVPN 2.5.5 arm-buildroot-linux-gnueabi [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Jan  1 2022
ovpn-server1[8054]: library versions: OpenSSL 1.1.1m  14 Dec 2021, LZO 2.08
ovpn-server1[8055]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
ovpn-server1[8055]: PLUGIN AUTH-PAM: initialization succeeded (fg)
ovpn-server1[8055]: PLUGIN_INIT: POST /usr/lib/openvpn-plugin-auth-pam.so '[/usr/lib/openvpn-plugin-auth-pam.so] [openvpn]' intercepted=PLUGIN_AUTH_USER_PASS_VERIFY
ovpn-server1[8055]: Diffie-Hellman initialized with 2048 bit key
ovpn-server1[8055]: Outgoing Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key
ovpn-server1[8055]: Outgoing Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication
ovpn-server1[8055]: Incoming Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key
ovpn-server1[8055]: Incoming Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication
vpnserver1[8057]: PLUGIN AUTH-PAM: BACKGROUND: initialization succeeded
ovpn-server1[8055]: RESOLVE: Cannot resolve host address: [MY PUBLIC HOSTNAME]:[PORT NUMBER A] (Name or service not known)
ovpn-server1[8055]: Exiting due to fatal error
ovpn-server2[8137]: OpenVPN 2.5.5 arm-buildroot-linux-gnueabi [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Jan  1 2022
ovpn-server2[8137]: library versions: OpenSSL 1.1.1m  14 Dec 2021, LZO 2.08
ovpn-server2[8138]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
ovpn-server2[8138]: PLUGIN AUTH-PAM: initialization succeeded (fg)
ovpn-server2[8138]: PLUGIN_INIT: POST /usr/lib/openvpn-plugin-auth-pam.so '[/usr/lib/openvpn-plugin-auth-pam.so] [openvpn]' intercepted=PLUGIN_AUTH_USER_PASS_VERIFY
ovpn-server2[8138]: Diffie-Hellman initialized with 2048 bit key
ovpn-server2[8138]: Outgoing Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key
ovpn-server2[8138]: Outgoing Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication
ovpn-server2[8138]: Incoming Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key
ovpn-server2[8138]: Incoming Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication
vpnserver2[8139]: PLUGIN AUTH-PAM: BACKGROUND: initialization succeeded
ovpn-server2[8138]: RESOLVE: Cannot resolve host address: [MY PUBLIC HOSTNAME]:[PORT NUMBER A] (Name or service not known)
ovpn-server2[8138]: Exiting due to fatal error
After a while the logs look like this instead:
Code:
rc_service: service [SERVICE NUMBER]:notify_rc restart_vpnserver2
rc_service: waitting "restart_vpnserver1" via  ...
rc_service: skip the event: restart_vpnserver2.
Server instance: Server 1 / Server 2
Enable OpenVPN Server: ON

General Settings
RSA Encryption: 2048 bit
Client will use VPN to access: Both

Advanced Settings
Interface Type: TUN
Protocol: UDP
Server Port: [MY RESPECTIVE PORT NUMBERS FOR THE SERVERS]
Authorization Mode: TLS
Keys and Certificates: [Static Key (V1), Certificate Authority, Server Certificate, Server Key and Diffie Hellman parameters are defined; Certificate Revocation List and Extra Chain Certificates are empty]
Username/Password Authentication: Yes
Username / Password Auth. Only: No
TLS control channel security: Encrypt channel
HMAC Authentication: Default
VPN Subnet / Netmask: 10.8.0.0 255.255.255.0
VPN IPv6 prefix/length: fd00:ac68:1:: 64
Advertise DNS to clients: Yes
Data ciphers: AES-256-GCM:AES-128-GCM:AES-256-CBC:AES-128-CBC
Compression: Disable
Log verbosity: 3
Manage Client-Specific Options: No

Custom configuration
local [MY PUBLIC HOSTNAME]
dhcp-option DNS 8.8.8.8
dhcp-option DNS 1.1.1.1
push "dhcp-option DNS 8.8.8.8"
push "dhcp-option DNS 1.1.1.1"
 
Remove that "local" parameter.
 
Remove that "local" parameter.
Yes, that (and a reboot) solved it. Thanks a lot for your help!

I actually tried this before (as well as clearing the whole Custom Configuration settings), and it didn't seem to help then. Probably that was due to not doing a real reboot of the router between the changes (I thought the "apply changes" was doing what I needed, shouldn't have assumed I guess)?

Just out of curiosity - was this problem really related to some change to the firmware and/or OpenVPN?
I can't really understand why it should suddenly be a problem binding OpenVPN to the static public hostname - but on the other hand I can't remember why I needed to do this back when I set it up, so it'll have to be fine until I (maybe) run into a problem.
 
I can`t tell what was going on because the info is obfuscated. Could be the info wasn't correctly entered, could be because you specified a port when it should only be a hostname, could be openvpn starting before your DNS is running, could be a misconfiguration on your DNS' could be... lots of things.

Bottom line, that parameter makes no real sense in the context, since the server is already bound to your WAN interface.
 
I guess it could be your suggestion that OpenVPN was trying to resolve the (external) hostname before the DNS was available. A race condition like that could explain why it suddenly wasn't working. (There was no port specified, and there were no problems resolving the hostname before upgrading from 386.3_2.)

Thanks again for your help and for all your work!
 
Thank you for posting this!

I had exactly the same error in 386.7...

@bjark Did you ever find out why you needed that line? (I can't remember either...)
 

Similar threads

Sign Up For SNBForums Daily Digest

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