Huge delay during boot (that I didn't have *I think* before 6.11)


NLS

Recommended Posts

I am talking maybe even 5 minutes waiting.

Even though I know that it takes time, it is so much, that I start thinking every time that something is wrong this time. :D And then it proceeds.

Here is where the long pause takes place:

 

20221008_235147.thumb.jpg.84b59ee88f3ab4e25e046a0cd60a1b35.jpg

 

Also, I am not sure why it looks for nct6775 (don't know if it is related to the long pause), as I don't have that plugin in UNRAID (it was in my previous motherboard, but I removed it and I have ITE driver now).

But I don't know if it comes from that removed plugin either.

 

So:

- Any idea how to find what makes the huge pause?

- Any idea how to remove this modprobe for nct6775? (or is it part of the boot process anyway?)

 

 

Link to comment
12 minutes ago, NLS said:

 

As I said, I removed that addin driver when I changed motherboard.

 

Anyway, here are my diags...

 

quasar-ultima-diagnostics-20221010-0101.zip 201.28 kB · 0 downloads

Looks like myservers plugin is.creating the delay. Checking dns or maybe a network

Oct  8 23:49:35 quasar-ultima root: Installing dynamix.unraid.net.plg 2022.09.28.1258 with Unraid API 2.52.1

Oct  8 23:49:35 quasar-ultima root: plugin: running: anonymous

Oct  8 23:49:35 quasar-ultima root: Checking DNS...

Oct  8 23:52:07 quasar-ultima root: Validating /boot/config/plugins/dynamix.my.servers/dynamix.unraid.net.txz...  ok.

Oct  8 23:52:07 quasar-ultima root: Validating

Edited by SimonF
Link to comment
10 minutes ago, SimonF said:

Looks like myservers plugin is.creating the delay. Checking dns or maybe a network

Oct  8 23:49:35 quasar-ultima root: Installing dynamix.unraid.net.plg 2022.09.28.1258 with Unraid API 2.52.1

Oct  8 23:49:35 quasar-ultima root: plugin: running: anonymous

Oct  8 23:49:35 quasar-ultima root: Checking DNS...

Oct  8 23:52:07 quasar-ultima root: Validating /boot/config/plugins/dynamix.my.servers/dynamix.unraid.net.txz...  ok.

Oct  8 23:52:07 quasar-ultima root: Validating

 

Well DNS is on a VM inside UNRAID, so it is not there while booting.
The secondary one (in UNRAID settings) is my router, so that should work.
So... if that is the issue probably it should skip to secondary DNS much faster OR use maybe a hardcoded "boot time" DNS or (third possible solution) revert to a (list of?) hard-coded name resolution entries (which is the best option probably).

It was working faster somehow before a few weeks probably (not sure, I rarely reboot).

 

Link to comment
2 minutes ago, NLS said:

 

Well DNS is on a VM inside UNRAID, so it is not there while booting.
The secondary one (in UNRAID settings) is my router, so that should work.
So... if that is the issue probably it should skip to secondary DNS much faster OR use maybe a hardcoded "boot time" DNS or (third possible solution) revert to a (list of?) hard-coded name resolution entries (which is the best option probably).

It was working faster somehow before a few weeks probably (not sure, I rarely reboot).

 

Any ideas @ljm42?

Link to comment

Many problems people have with My Servers are the result of faulty DNS servers that do not resolve DNS properly, so the installation routine checks some hostnames to ensure they resolve:

host unraid-dl.sfo2.cdn.digitaloceanspaces.com
host registration.unraid.net
host mothership.unraid.net
host wanip4.unraid.net
host backup.unraid.net

 

If your system is pointed to a DNS server that does not exist at boot, it makes sense that this would cause a delay. I'm not sure of the best way to reduce the delay for you as I do want to warn users when there are problems.

 

What is confusing is that your system did not report any problems. I would have expected the logs to show errors for each one that did not return results.

Link to comment
3 hours ago, ljm42 said:

Many problems people have with My Servers are the result of faulty DNS servers that do not resolve DNS properly, so the installation routine checks some hostnames to ensure they resolve:

host unraid-dl.sfo2.cdn.digitaloceanspaces.com
host registration.unraid.net
host mothership.unraid.net
host wanip4.unraid.net
host backup.unraid.net
 

 

If your system is pointed to a DNS server that does not exist at boot, it makes sense that this would cause a delay. I'm not sure of the best way to reduce the delay for you as I do want to warn users when there are problems.

 

What is confusing is that your system did not report any problems. I would have expected the logs to show errors for each one that did not return results.

 

It is possible that after some time-out the system checks the secondary DNS, that works.
I am not sure how Linux does switch to secondary DNS for resolution and if it is configurable.

Since people hosting DNS in the server itself is not uncommon (I mean... it is the server), you should probably consider alternative solutions.
Can you still make the checks and log issues, but not freeze the system? (make it a background task with some time out)

 

Now, if those FQDN are NEEDED during boot (and is not just a check), you should also have them as static entries and/or temporarily use an extrernal DNS (like 8.8.8.8), that will also check connectivity to Internet. Maybe both (try defined DNS in background, but test with alternative DNS and on time-out use static entries).
 

Of course it can also revert to the check later after server boots and anything auto-start is working. (so maybe raise a warning flag and then clear it?)

 

Link to comment
  • 1 month later...

I agree. Ive noticed this check adds at least 3 mins to the boot time if internet is down because it's being run from a VM from the same server. @ljm42 Is there another method, which is possible, without these long delays?

 

Also, it seems that I'm getting a 5min jump between these 2 steps: emhttpd: shcmd (21): /etc/rc.d/rc.nginx start and Starting Nginx server daemon... So does this also mean nginx is timing out too?

 

Any help/insight would be appreciated as I'd love to get my boot times to something reasonable if possible. Thanks!

Edited by AKC Server
Link to comment

It is an issue for sure.

The delay I get is not just 3 min, it is maybe 10 (or more!), which means that other things that depend on DNS (?) time-out AND THEY DID NOT (I want to point out the difference) before 6.11 (I think).
During boot the system should have some backup solution that kicks in early (after testing for DNS maybe). Either use direct IP connections, or have some static hosts or even use 8.8.8.8 (or similar) in case there is no DNS access early in boot.

This will probably solve it if DNS is the issue, but will not solve it if gateway is also within the same machine (so be inaccessible during boot) or there is a real Internet issue, or of course someone wants to setup a machine that will be off-internet on purpose (which is something many people don't think much nowadays, but is certainly an option).


Whatever the case, the time-outs are HUGE. Even if there is no other solution, if the time outs just become WAY shorter (like 1/3 of what they are), will be a "passable" solution.

 

Edited by NLS
Link to comment

@NLS I think it was an oversight about people not having internet during boot. There's probably a decent amount between the people (like myself) who use a VM to run router software, people who have an offline box, or other networking or other small blockages until boot. 

 

For the VM group, I'm sure it wouldn't be too tough to add a setting to delay these checks until system boots, or some other possible workarounds.  Guess it depends on if they see this as something worth solving or not. In their defense, this is only an issue during testing times or a power blip because I leave my box on 24/7 (as do the majority I think).

 

Good to hear I'm not the only one having these issues though. Cheers!

  • Like 1
Link to comment

Hi folks,

 

Regarding the original topic of this thread, the five DNS lookups originally had a one minute timeout, in the latest My Servers plugin release they each have a 10 second timeout, meaning this particular issue would add a max of 50 seconds to your boot time instead of 5 minutes (assuming your plugins are up to date). I am still thinking through my options for reducing that further for people who have setup their network such that DNS and/or Internet are not available at boot.

 

In general though, Unraid is not optimized for this configuration. For the most trouble-free operation, if you run a PiHole I recommend having Unraid use a public DNS like 8.8.8.8 so there is no chance of the PiHole blocking it and DNS will be available even when the array is stopped.

 

And for the most trouble-free operation I would recommend against running your router in a VM. It can work, but it makes your life very difficult if something goes wrong with your hardware and the array can't start, then Internet for your whole network is offline while you troubleshoot it. Not to mention regular reboots take longer while network requests timeout. 

 


I do not think there are changes in 6.11 that would affect boot times. But if you want to dig into this further, go to Tools -> System Log and look at the timestamps. If you find a large gap in the timestamps while booting then there might be something to investigate, in which case please post your current diagnostics.zip (from Tools -> Diagnostics) and a snippet showing where you think there might be something that could be optimized. Also describe your network situation.

 

For troubleshooting DNS specifically, you should also boot using 8.8.8.8 as your only DNS provider, then you can find the same area in the syslog and compare the gaps. Post these diagnostics too.

Link to comment

Hey @ljm42,

 

Thanks for all the work you do on your plugin! 10 seconds per and 50s overall is not a big delay, so thanks for fixing. Only thing is, I'm still seeing 30s in the logs on version 2022.11.02.0859. Do you know why that would be?

 

### [PREVIOUS LINE REPEATED 1 TIMES] ###
Nov 17 22:29:00 Westcotts root: Executing hook script: post_plugin_checks
Nov 17 22:29:00 Westcotts root: plugin: installing: dynamix.unraid.net.plg
Nov 17 22:29:00 Westcotts root: Executing hook script: pre_plugin_checks
Nov 17 22:29:00 Westcotts root: plugin: running: anonymous
Nov 17 22:29:00 Westcotts root: Installing dynamix.unraid.net.plg 2022.11.02.0859 with Unraid API 2.53.0
Nov 17 22:29:00 Westcotts root: plugin: running: anonymous
Nov 17 22:29:00 Westcotts root: Checking DNS...
Nov 17 22:29:03 Westcotts kernel: igc 0000:01:00.0 eth0: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX/TX
Nov 17 22:29:03 Westcotts kernel: br0: port 1(eth0) entered blocking state
Nov 17 22:29:03 Westcotts kernel: br0: port 1(eth0) entered forwarding state
Nov 17 22:29:05 Westcotts  ntpd[990]: Listen normally on 2 br0 192.168.10.222:123
Nov 17 22:29:05 Westcotts  ntpd[990]: new interface(s) found: waking up resolver
Nov 17 22:29:30 Westcotts root: ⚠️ Warning: Your DNS server (1.1.1.1) is unable to resolve 'unraid-dl.sfo2.cdn.digitaloceanspaces.com'
Nov 17 22:30:00 Westcotts root: ⚠️ Warning: Your DNS server (1.1.1.1) is unable to resolve 'registration.unraid.net'
Nov 17 22:30:30 Westcotts root: ⚠️ Warning: Your DNS server (1.1.1.1) is unable to resolve 'mothership.unraid.net'
Nov 17 22:31:00 Westcotts root: ⚠️ Warning: Your DNS server (1.1.1.1) is unable to resolve 'wanip4.unraid.net'
Nov 17 22:31:30 Westcotts root: ⚠️ Warning: Your DNS server (1.1.1.1) is unable to resolve 'backup.unraid.net'
Nov 17 22:31:30 Westcotts root:   Recommend navigating to Settings -> Network Settings and changing your DNS server to 8.8.8.8
Nov 17 22:31:30 Westcotts root: Validating /boot/config/plugins/dynamix.my.servers/dynamix.unraid.net.txz...  ok.
Nov 17 22:31:33 Westcotts root: Validating /boot/config/plugins/dynamix.my.servers/unraid-api.tgz...  ok.
Nov 17 22:31:33 Westcotts root: plugin: checking: /boot/config/plugins/dynamix.my.servers/dynamix.unraid.net.txz - SHA256
Nov 17 22:31:33 Westcotts root: plugin: skipping: /boot/config/plugins/dynamix.my.servers/dynamix.unraid.net.txz already exists
Nov 17 22:31:33 Westcotts root: plugin: checking: /boot/config/plugins/dynamix.my.servers/unraid-api.tgz - SHA256
Nov 17 22:31:33 Westcotts root: plugin: skipping: /boot/config/plugins/dynamix.my.servers/unraid-api.tgz already exists
Nov 17 22:31:33 Westcotts root: plugin: running: anonymous
### [PREVIOUS LINE REPEATED 1 TIMES] ###
Nov 17 22:31:33 Westcotts root: 🕹️ Installing JavaScript web components
Nov 17 22:31:42 Westcotts root:  Finished installing web components
Nov 17 22:31:42 Westcotts root: plugin: running: anonymous
### [PREVIOUS LINE REPEATED 1 TIMES] ###
Nov 17 22:31:42 Westcotts root: 
Nov 17 22:31:42 Westcotts root: +==============================================================================
Nov 17 22:31:42 Westcotts root: | Installing new package /boot/config/plugins/dynamix.my.servers/dynamix.unraid.net.txz
Nov 17 22:31:42 Westcotts root: +==============================================================================
Nov 17 22:31:42 Westcotts root: 
Nov 17 22:31:42 Westcotts root: Verifying package dynamix.unraid.net.txz.
Nov 17 22:31:42 Westcotts root: Installing package dynamix.unraid.net.txz:
Nov 17 22:31:42 Westcotts root: PACKAGE DESCRIPTION:
Nov 17 22:31:43 Westcotts root: Package dynamix.unraid.net.txz installed.
Nov 17 22:31:43 Westcotts root: 
Nov 17 22:31:43 Westcotts root:  Installation is complete
Nov 17 22:31:43 Westcotts root: 
Nov 17 22:31:43 Westcotts root: plugin: dynamix.unraid.net.plg installed
### [PREVIOUS LINE REPEATED 1 TIMES] ###

 

westcotts-diagnostics-20221117-2254.zip

Link to comment
17 hours ago, AKC Server said:

Thanks for all the work you do on your plugin! 10 seconds per and 50s overall is not a big delay, so thanks for fixing. Only thing is, I'm still seeing 30s in the logs on version 2022.11.02.0859. Do you know why that would be?

 

Hmm, here is an example command we are running:
  /usr/bin/host -W 10 unraid-dl.sfo2.cdn.digitaloceanspaces.com

 

The "-W 10" means "wait up to 10 seconds", so I'm not sure why it is actually waiting 30 seconds.

 

I see you have two DNS servers defined, but even if it were waiting 10 seconds per DNS server that would only be 20 seconds. So... yeah :)


I will spend some time rethinking this (maybe it can quit after a single failure instead of trying them all), but probably not in time for our next release, hopefully the one after that.

Link to comment
On 11/22/2022 at 5:32 AM, NLS said:

I need to wake this up and ask. Did anybody make ANY change regarding this?

Because I think no change happened. MyServers did not get updated, nor do I see any relevant change in 6.11.4 and 6.11.5 changelogs.

Will anything be actually done?

 

 

Have you had a chance to read my last post?

 

You can watch this thread for updates to My Servers

https://forums.unraid.net/topic/112073-my-servers-releases-and-announcements/

 

Link to comment
4 hours ago, NLS said:

 

I did, yet I still get an around 5 minute delay in the same place (as shown in my opening post).

 

 

There was already an update to My Servers that would have reduced the time, but for further reductions:

Quote

I will spend some time rethinking this (maybe it can quit after a single failure instead of trying them all), but probably not in time for our next release, hopefully the one after that.

 

Link to comment

Join the conversation

You can post now and register later. If you have an account, sign in now to post with your account.
Note: Your post will require moderator approval before it will be visible.

Guest
Reply to this topic...

×   Pasted as rich text.   Restore formatting

  Only 75 emoji are allowed.

×   Your link has been automatically embedded.   Display as a link instead

×   Your previous content has been restored.   Clear editor

×   You cannot paste images directly. Upload or insert images from URL.