OPNsense Forum

Archive => 21.7 Legacy Series => Topic started by: Maarten on October 01, 2021, 01:06:48 pm

Title: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: Maarten on October 01, 2021, 01:06:48 pm
Hi, it takes about 13 minutes for my router to boot up. This is the case for years now. I'm trying to find out how I can solve this, but I'm not sure where to start.

I've attached a screenshot of the part where it becomes really slow. (Red Arrows) Every line of "Reconfiguring IPv4 on ovpns" takes minutes to complete.

I've tried to boot with all openvpn server connections disabled. As expected the boot was fast. I've re-enabled the connections and the boot is slow again.

Is this a known issue?

[You need to be logged in to see the attached picture...]


[Edit 2021-10-28]
Apparently executing this command is taking a long time:

configctl interface newip ovpns5  (this is executed for every vpn server you've configured)

This command is fired from this script:
/usr/local/etc/rc.syshook.d/start/10-newwanip

I noticed the delay is there when you assign an interface to the vpn instance. If you remove the interface assignment there is no delay anymore. (but then your setup doesn't work of course)
[/Edit]
Title: Re: Boot delay after "Invoking start script newwanip"
Post by: karlson2k on October 01, 2021, 02:10:37 pm
I have a similar problem: https://forum.opnsense.org/index.php?topic=23607.msg112323#msg112323

No solution so far.
Title: Re: Boot delay after "Invoking start script newwanip"
Post by: yodaphone on October 02, 2021, 02:04:48 am
I too have this issue..
Title: Re: Boot delay after "Invoking start script newwanip"
Post by: karlson2k on October 02, 2021, 09:32:04 am
I too have this issue..
Do you have any OpenVPN connections?

Hi, it takes a long time for my router to boot up. This is the case for years now. I'm trying to find out how I can solve this, but I'm not sure where to start.

I've attached a screenshot of the part where it becomes really slow. (Red Arrows) Every line of "Reconfiguring IPv4 on ovpns" takes minutes to complete.
Do you have any "time outs" in the general log, like in my case?


Title: Re: Boot delay after "Invoking start script newwanip"
Post by: Maarten on October 03, 2021, 01:12:44 pm
Yes, I have the same timeout entries in the log.
Title: Re: Boot delay after "Invoking start script newwanip"
Post by: patrickstar on October 04, 2021, 09:39:58 am
i have the same problem but its only using PPPOE connection...
i am not using openvpn/...
also i have this annoying ipv6 gw problem on pppoe connection

using cable modem via dhcp , no problem at all...
Title: Re: Boot delay after "Invoking start script newwanip"
Post by: karlson2k on October 04, 2021, 09:59:04 am
i have the same problem but its only using PPPOE connection...
i am not using openvpn/...
also i have this annoying ipv6 gw problem on pppoe connection

using cable modem via dhcp , no problem at all...
Do you have timeout entries in "general log"?
Can you post relevant log excerpts?
Title: Re: Boot delay after "Invoking start script newwanip"
Post by: Maarten on October 04, 2021, 12:59:57 pm
I've added a temporary local dns server that is accessible on boot, and now the bootup seems to speed up quite a bit.

So it looks like for me, if there is no dns server available on boot, it will slow the boot process quite a bit.
Title: Re: Boot delay after "Invoking start script newwanip"
Post by: karlson2k on October 04, 2021, 04:12:55 pm
For me the boot process finished quick if no WAN network is connected or DHCP server is NOT present in the WAN network.
For WAN connection I have dynamic IPv4.
Title: Re: Boot delay after "Invoking start script newwanip"
Post by: karlson2k on October 07, 2021, 01:51:22 pm
Yes, I have the same timeout entries in the log.
How many timeouts do you have in the each boot log?

My guess that it could be related to the number of OpenVPN connections.
Title: Re: Boot delay after "Invoking start script newwanip"
Post by: Maarten on October 26, 2021, 10:27:48 am
I've now tried to boot with all openvpn server connections disabled. As expected the boot was fast. I've re-enabled the connections and the boot is slow again.

But, now, for some reason, I don't see any timeouts anymore. So I don't think the timeouts are related to the boot delay I have.
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: Maarten on October 28, 2021, 10:54:28 am
Apparently executing this command is taking a long time:

configctl interface newip ovpns5  (this is executed for every vpn server you've configured)

This command is fired from this script:
/usr/local/etc/rc.syshook.d/start/10-newwanip

I noticed the delay is there as when you assign an interface to the vpn instance. If you remove the interface assignment there is no delay anymore. (but your setup doesn't work of course)
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: karlson2k on October 29, 2021, 01:22:59 pm
I have two OpenVPN connection (with OPNsense as a client) and configctl halted for two minutes (the timeout period set in the /usr/local/opnsense/service/configd_ctl.py file).

Looks like the bug is triggered by more than one OpenVPN connection configured.
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: 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.....

Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: karlson2k on October 29, 2021, 03:33:42 pm
Do you have in "timeouts" in general log without OpenVPN interfaces? Like this one:
Quote
configctl[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
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: benyamin on October 29, 2021, 03:48:50 pm
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.
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: karlson2k on October 29, 2021, 04:12:45 pm
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.
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: 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.
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: Maarten on November 01, 2021, 09:06:56 am
Do you have in "timeouts" in general log without OpenVPN interfaces? Like this one:
Quote
configctl[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
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: Maarten on November 01, 2021, 09:36:20 am
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.
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: benyamin on November 01, 2021, 12:24:40 pm
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...?
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: Maarten on November 01, 2021, 01:06:48 pm
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.
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: benyamin on November 01, 2021, 01:38:57 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):
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.
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: Maarten on November 01, 2021, 01:44:24 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

Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: benyamin on November 01, 2021, 02:10:21 pm
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...?
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: benyamin on November 02, 2021, 12:03:24 pm
@Maarten: You may also want to post this question to the VPN Board (https://forum.opnsense.org/index.php?board=36.0).

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.
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: 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.
Title: Re: Boot delay after "Invoking start script newwanip" (boot takes about 13 minutes)
Post by: benyamin on November 02, 2021, 01:30:06 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.