Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)

Started by Maarten, October 01, 2021, 01:06:48 PM

Previous topic - Next topic
I would be looking for errors and timeouts in the OpenVPN logs at VPN: OpenVPN: Log File...

There should be some insightful mentions there upon reboot.

If not, increase the verbosity level to 5 for each client configuration at VPN: OpenVPN: Clients and try again.

Looks like the problem is not related to OpenVPN connectivity, but related to the presence of multiple ovpncX interfaces.
For me delay is started after "Reconfiguring IPv4 on ovpnc2..." line in the boot screen log.

So there are no associated errors or delays in the OpenVPN log...?

I'm not seeing the issue despite having multiple OpenVPN Client (ovpnc) interfaces.

Also, because you are not seeing the issue on all such interfaces, it suggests the problem lies in just those with a delay.

Quote from: karlson2k on October 29, 2021, 03:33:42 PM
Do you have in "timeouts" in general log without OpenVPN interfaces? Like this one:
Quoteconfigctl[11670]   error in configd communication Traceback (most recent call last): File "/usr/local/opnsense/service/configd_ctl.py", line 68, in exec_config_cmd line = sock.recv(65536).decode() socket.timeout: timed out

No

Quote from: benyamin on October 29, 2021, 04:22:42 PM
So there are no associated errors or delays in the OpenVPN log...?

I'm not seeing the issue despite having multiple OpenVPN Client (ovpnc) interfaces.

Also, because you are not seeing the issue on all such interfaces, it suggests the problem lies in just those with a delay.

There are no errors in my opnvpn log, the openvpn daemons start without issues. It's just the script "configctl interface newip ovpns..." which causes the delay if you attach an interface to the openvpn instance.

I've commented out that line in the script "10-newwanip", and it was fast right away. Of course this script does not run for nothing, so I restored the setting after testing.

Ok...

I've just realised that @Maarten is referring to OpenVPN servers (ovpnsX) and @karlson2k is talking about OpenVPN clients (ovpncX)... 8^d

I do have that right, yes...?!?

@karlson2k: Maybe check those logs I mentioned.

@Maarten: I noticed you no longer have a contiguous namespace for the interfaces your OpenVPN servers are using, namely ovpnsX where X is 5,3,8,9 and 10. I'm guessing it's been a lot of configuration changes over a period of time. Have you considered recreating the OpenVPN server config...? I imagine it's a not insignificant amount of work, likely with a range of firewall rules to recreate too. As the issue has been in effect for years, it's likely an ancient configuration change that caused the problem. Time for a fresh build maybe...?

yeah, I named it x, because I have about 10 vpn server instances. So x stands indeed for 1,2, 3 etc.

Like I mentioned above, I've tested a "vanilla" installation, latest version of opnsense, so clean sheet, no config import whatsoever. Just added a few openvpn servers and created an interface for it. That results in the delay right away for me.

Quote from: Maarten on November 01, 2021, 01:06:48 PM
Like I mentioned above, I've tested a "vanilla" installation, latest version of opnsense, so clean sheet, no config import whatsoever. Just added a few openvpn servers and created an interface for it. That results in the delay right away for me.
Did it take a certain number of VPN servers to produce the delay?

EDIT: Just saw your other post (again):
Quote from: Maarten on October 29, 2021, 02:31:52 PM
I did some testing with a vanilla configuration, and measured the time it took opnsense to reconfigure all connections:

1 vpn server configured = 30sec total
2 vpn servers configured = 100sec total
3 vpn servers configured = 25sec total !?!?!?!?

Then I deleted the 3rd and it took 20 seconds, but the boot after that it was 40. Seems like the delay is a bit random.....

Perhaps you can share more of the config? e.g. Server mode, Device mode and listening interface for each server.

Quote from: Maarten on October 29, 2021, 02:31:52 PM
I did some testing with a vanilla configuration, and measured the time it took opnsense to reconfigure all connections:

1 vpn server configured = 30sec total
2 vpn servers configured = 100sec total
3 vpn servers configured = 25sec total !?!?!?!?

Then I deleted the 3rd and it took 20 seconds, but the boot after that it was 40. Seems like the delay is a bit random.....

This was my "vanilla" test. One instance already gave delays.

Settings: (nothing special)

Server Mode: P2P
Device Mode: Tun
Protocol: Udp
Interface: LocalHost (but tried other options as well)
IPv4 Tunnel Network: 10.0.10.4/30


Anyone got an idea how Maarten could get more verbose logging to identify the delays?

Anyone know if this is expected behaviour - and why?

A client I could understand, but why would there be a delay for a server...?

@Maarten: You may also want to post this question to the VPN Board.

Given it's been a long standing issue, it might be better suited to that board.

Methinks it more likely to be seen by a VPN gun there as well.

So far it looks like more related to the OPNsense core than to the "VPN" topic.

Quote from: karlson2k on November 02, 2021, 12:41:08 PM
So far it looks like more related to the OPNsense core than to the "VPN" topic.

Respectfully, IMHO, I disagree.

I'm having no problem with my boot times whatsoever while running multiple OpenVPN clients.

I think you are running clients too @karlson2k, yes...? @Maarten is running servers.

I think it worthwhile sharing your VPN logs, redacted if /as necessary so we can eliminate this as the cause.

No one else has offered any advice as to how to log boot with more verbosity. So this might be where we need to start. I know mine is working so I can compare time stamps, etc. to see what might be happening.

If there's nothing to be seen in the VPN logs, I might be prepared to spend a little time getting some logging runing for the 10-newwanip script and the configctl interface newip commands.