DietPi-Globals | G_CHECK_URL fails as DNS resolving takes very long

shehzaman commented 5 years ago

Hi, Very strange issue on Orange Pi Zero board. I have tried this with multiple mirrors from different mirrors:

https://deb.debian.org/debian/ (and https://deb.debian.org/debian)
http://ftp.debian.org/debian/ (and http://ftp.debian.org/debian)

I looked at a similar issue #755 - where the last trailing slash / was a problem.

In my case, I get similar outputs when using wget --spider for all mirrors:

root@DietPi:~# wget --spider https://deb.debian.org/debian
Spider mode enabled. Check if remote file exists.
--2019-04-15 19:06:34--  https://deb.debian.org/debian
Resolving deb.debian.org (deb.debian.org)... 149.20.4.15, 5.153.231.4, 128.31.0.62, ...
Connecting to deb.debian.org (deb.debian.org)|149.20.4.15|:443... connected.
HTTP request sent, awaiting response... 302 Found
Location: https://cdn-aws.deb.debian.org/debian [following]
Spider mode enabled. Check if remote file exists.
--2019-04-15 19:06:40--  https://cdn-aws.deb.debian.org/debian
Resolving cdn-aws.deb.debian.org (cdn-aws.deb.debian.org)... 52.85.55.237, 52.85.55.249, 52.85.55.11, ...
Connecting to cdn-aws.deb.debian.org (cdn-aws.deb.debian.org)|52.85.55.237|:443... connected.
HTTP request sent, awaiting response... 302 Moved Temporarily
Location: http://cdn-fastly.deb.debian.org/debian [following]
Spider mode enabled. Check if remote file exists.
--2019-04-15 19:06:46--  http://cdn-fastly.deb.debian.org/debian
Resolving cdn-fastly.deb.debian.org (cdn-fastly.deb.debian.org)... 151.101.8.204, 2a04:4e42:2::204
Connecting to cdn-fastly.deb.debian.org (cdn-fastly.deb.debian.org)|151.101.8.204|:80... connected.
HTTP request sent, awaiting response... 302 Found
Location: http://ftp.debian.org/debian/ [following]
Spider mode enabled. Check if remote file exists.
--2019-04-15 19:06:52--  http://ftp.debian.org/debian/
Resolving ftp.debian.org (ftp.debian.org)... 130.89.148.12, 2001:67c:2564:a119::148:12
Connecting to ftp.debian.org (ftp.debian.org)|130.89.148.12|:80... connected.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [text/html]
Remote file exists and could contain further links,
but recursion is disabled -- not retrieving.

Apt update works:

root@DietPi:~# apt update
Hit:1 https://apt.armbian.com stretch InRelease
Ign:2 https://cdn-aws.deb.debian.org/debian stretch InRelease
Hit:3 https://cdn-aws.deb.debian.org/debian stretch-updates InRelease
Get:4 https://cdn-aws.deb.debian.org/debian-security stretch/updates InRelease [94.3 kB]
Hit:4 https://cdn-aws.deb.debian.org/debian-security stretch/updates InRelease
Get:5 https://cdn-aws.deb.debian.org/debian stretch-backports InRelease [91.8 kB]
Hit:5 https://cdn-aws.deb.debian.org/debian stretch-backports InRelease
Hit:6 https://cdn-aws.deb.debian.org/debian stretch Release
Reading package lists... Done
Building dependency tree       
Reading state information... Done
All packages are up to date.

dietpi-software fails:

root@DietPi:~# dietpi-software 
[  OK  ] DietPi-Software | Root access verified.
[  OK  ] DietPi-Software | RootFS R/W access verified.

[  OK  ] DietPi-Software | Initialized database
[  OK  ] DietPi-Software | Reading database
[ SUB1 ] DietPi-Set_software > passwords ()
[  OK  ] passwords  | Completed
[FAILED] DietPi-Software | Connection test: https://deb.debian.org/debian/

Details:

Date | Mon 15 Apr 19:01:16 BST 2019
Bug report | N/A
DietPi version | v6.22.3 (Fourdee/master)
Img creator | Twilight0
Pre-image | https://www.armbian.com/orange-pi-zero/
SBC device | OrangePi Zero (armv7l) (index=32)
Kernel version | #5.78 SMP Mon Apr 8 07:46:22 CEST 2019
Distro | stretch (index=4)
Command | Connection test: https://deb.debian.org/debian/
Exit code | 4
Software title | DietPi-Software

Steps to reproduce:

run dietpi-software as root
Use any mirror available

Expected behaviour:

Should be the same as wget --spider

Actual behaviour:

Fails to connect to debian mirror

Extra details:

apt update works
wget --spider works
With or without trailing slash / on mirror url gives the same behavior

Additional logs:

Log file contents:
Spider mode enabled. Check if remote file exists.
--2019-04-15 19:00:53--  https://deb.debian.org/debian/
Resolving deb.debian.org (deb.debian.org)... failed: Connection timed out.
wget: unable to resolve host address ‘deb.debian.org’

MichaIng commented 5 years ago

@shehzaman Many thanks for your report.

Indeed strange. How long does manual wget take?

time wget --spider https://deb.debian.org/debian

Because we have a maximum time hard coded into our connection test.

Actually I see already from your wget output. It takes 6 seconds for each redirect and there are several redirects included when accessing the APT mirror director.

So the question is if DNS resolving takes so long or the final connection.

Please compare the above time with:

time wget --spider https://130.89.148.12

shehzaman commented 5 years ago

Thank you for looking into this @MichaIng

Here is the output for all redirects:

root@DietPi: time wget --spider https://deb.debian.org/debian
Spider mode enabled. Check if remote file exists.
--2019-04-16 18:13:07--  https://deb.debian.org/debian
Resolving deb.debian.org (deb.debian.org)... 5.153.231.4, 128.31.0.62, 130.89.148.14, ...
Connecting to deb.debian.org (deb.debian.org)|5.153.231.4|:443... connected.
HTTP request sent, awaiting response... 302 Found
Location: https://cdn-aws.deb.debian.org/debian [following]
Spider mode enabled. Check if remote file exists.
--2019-04-16 18:13:13--  https://cdn-aws.deb.debian.org/debian
Resolving cdn-aws.deb.debian.org (cdn-aws.deb.debian.org)... 54.192.151.90, 54.192.151.2, 54.192.151.55, ...
Connecting to cdn-aws.deb.debian.org (cdn-aws.deb.debian.org)|54.192.151.90|:443... connected.
HTTP request sent, awaiting response... 302 Moved Temporarily
Location: http://cdn-fastly.deb.debian.org/debian [following]
Spider mode enabled. Check if remote file exists.
--2019-04-16 18:13:19--  http://cdn-fastly.deb.debian.org/debian
Resolving cdn-fastly.deb.debian.org (cdn-fastly.deb.debian.org)... 151.101.8.204, 2a04:4e42:2::204
Connecting to cdn-fastly.deb.debian.org (cdn-fastly.deb.debian.org)|151.101.8.204|:80... connected.
HTTP request sent, awaiting response... 302 Found
Location: http://ftp.debian.org/debian/ [following]
Spider mode enabled. Check if remote file exists.
--2019-04-16 18:13:25--  http://ftp.debian.org/debian/
Resolving ftp.debian.org (ftp.debian.org)... 130.89.148.12, 2001:67c:2564:a119::148:12
Connecting to ftp.debian.org (ftp.debian.org)|130.89.148.12|:80... connected.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [text/html]
Remote file exists and could contain further links,
but recursion is disabled -- not retrieving.

real    0m23.092s
user 0m0.210s
sys 0m0.084s

Using only IP address:

root@DietPi:~ time wget --spider https://130.89.148.12
Spider mode enabled. Check if remote file exists.
--2019-04-16 18:16:04--  https://130.89.148.12/
Connecting to 130.89.148.12:443... connected.
ERROR: The certificate of ‘130.89.148.12’ is not trusted.
ERROR: The certificate of ‘130.89.148.12’ hasn't got a known issuer.
The certificate's owner does not match hostname ‘130.89.148.12’

real    0m0.626s
user 0m0.121s
sys 0m0.051s

root@DietPi:~ time wget --spider http://130.89.148.12
Spider mode enabled. Check if remote file exists.
--2019-04-16 18:16:21--  http://130.89.148.12/
Connecting to 130.89.148.12:80... connected.
HTTP request sent, awaiting response... 302 Found
Location: http://130.89.148.12/debian/ [following]
Spider mode enabled. Check if remote file exists.
--2019-04-16 18:16:21--  http://130.89.148.12/debian/
Connecting to 130.89.148.12:80... connected.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [text/html]
Remote file exists and could contain further links,
but recursion is disabled -- not retrieving.

real    0m0.800s
user 0m0.009s
sys 0m0.037s

Do you hard code real time or user+sys time?

I tested my internet speed as well, latency and download speed are not too bad:

Screen Shot 2019-04-16 at 10 49 46 PM

MichaIng commented 5 years ago

@shehzaman So indeed it's the DNS resolving that takes very long. Which DNS server do you use? cat /etc/resolv.conf Do you use DHCP or static IP? In case of static IP, try to set DNS nameserver to your router, which should be usually fastest. Most likely your router is pre-configured to use a nearby DNS server provided by your ISP. In case of DHCP it should set this automatically. Otherwise try to set nameserver in /etc/resolv.conf to 8.8.8.8 (usually fast Google DNS) and recheck above time commands if this changes something.

Meanwhile to make DietPi scripts work, you can override the default timeout of our connection/URL check script: In /DietPi/dietpi/func/dietpi-globals look for local timeout=${timeout:-5} and replace with e.g. local timeout=${timeout:-30} So it allows connection to take up to 30 seconds.

Fourdee commented 5 years ago

@MichaIng

Tweaked the defaults to:

timeout = 10
retry = 2

Will also look at adding option to increase timeout when it fails on 1st attempt.

MichaIng commented 5 years ago

Similar issues:

@Fourdee

Will also look at adding option to increase timeout when it fails on 1st attempt.

That is what I had in mind as well. Does wget --spider have a special exit code when it times out (compared to 40X returns and such or related reply from DNS server (not found))? E.g. in this case we could allow to retry with unlimited time, with the hint to use ctrl+c to cancel (ah or would that always exit the whole script?).

In general I think the 5 seconds we had should be totally sufficient. Everything taking longer IMO is an issue. In those DNS cases (at least in one older case also 8.8.8.8 took the same long time) I just currently have no hint how this can be.

Fourdee commented 5 years ago

:u6307: Tested and working fine, new options:

MichaIng commented 5 years ago

Just ran some tests on my VMs and RPi and Windows and it takes max 0.5 seconds to resolve https://deb.debian.org/debian or any other domain I tried (dietpi.com, google.com). Actually I found curl -L to always be faster than wget --spider, ~0.3 vs. 0.5 seconds, but I could not find an equivalent to --spider so far so that curl will not download anything, just check existence.

Fourdee commented 5 years ago

@MichaIng

In general I think the 5 seconds we had should be totally sufficient.

Yep agree, and the 3 retry count should ignore DNS issues after its "hopefully" resolved in test 1.

Does wget --spider have a special exit code when it times out

https://gist.github.com/cosimo/5747881

MichaIng commented 5 years ago

Hah, curl equivalent to wget --spider: curl -LI https://deb.debian.org/debian - I to show document "info" only, -L as known to follow symlinks.

The printout is quite nice to follow the redirections and check which one took how much time:

2019-04-22 14:47:58 root@micha:/tmp# curl -LI https://deb.debian.org/debian
HTTP/1.1 302 Found
Date: Mon, 22 Apr 2019 12:48:18 GMT
Server: Apache
X-Content-Type-Options: nosniff
X-Frame-Options: sameorigin
Referrer-Policy: no-referrer
X-Xss-Protection: 1
Strict-Transport-Security: max-age=15552000
Location: https://cdn-aws.deb.debian.org/debian
Content-Type: text/html; charset=iso-8859-1

HTTP/1.1 302 Moved Temporarily
Content-Type: text/html; charset=iso-8859-1
Content-Length: 287
Connection: keep-alive
Date: Mon, 22 Apr 2019 12:09:42 GMT
Server: Apache
X-Content-Type-Options: nosniff
X-Frame-Options: sameorigin
Referrer-Policy: no-referrer
X-Xss-Protection: 1
Location: http://cdn-fastly.deb.debian.org/debian
Age: 2315
X-Cache: Hit from cloudfront
Via: 1.1 a1098f0eeab192209962e3a9d76d0339.cloudfront.net (CloudFront)
X-Amz-Cf-Id: SR4TPjz95cJmRt1BCrHuPBrjwPz1jeyjNOjxl1bY-eJfGA8xI2GDWw==

HTTP/1.1 302 Found
Server: Apache
X-Content-Type-Options: nosniff
X-Frame-Options: sameorigin
Referrer-Policy: no-referrer
X-Xss-Protection: 1
Location: http://ftp.debian.org/debian/
Content-Type: text/html; charset=iso-8859-1
Content-Length: 277
Accept-Ranges: bytes
Date: Mon, 22 Apr 2019 12:48:19 GMT
Via: 1.1 varnish
Age: 8
Connection: keep-alive
X-Served-By: cache-ams21049-AMS
X-Cache: HIT
X-Cache-Hits: 1
X-Timer: S1555937299.021094,VS0,VE0

HTTP/1.1 200 OK
Date: Mon, 22 Apr 2019 12:48:19 GMT
Server: Apache
X-Content-Type-Options: nosniff
X-Frame-Options: sameorigin
Referrer-Policy: no-referrer
X-Xss-Protection: 1
X-Clacks-Overhead: GNU Terry Pratchett
Content-Type: text/html;charset=UTF-8

Ah lol no forget about the time as these are reported from the servers and obviously one is totally out of sync: 12:09:42 GMT 😆

Disillusioning that our nice HTTPS request is forwarded to HTTP directly... cdn-fastly it not available in HTTPS at all, the in this case final ftp.debian.org is, but as it is not the official domain, the certificate does not match. Ah at least that was the case for some other mirror, but here even worse, self-singed?:
```
2019-04-22 14:54:01 root@micha:/tmp# curl -LI https://ftp.debian.org/debian/
curl: (60) SSL certificate problem: self signed certificate in certificate chain
More details here: https://curl.haxx.se/docs/sslcerts.html
```

curl failed to verify the legitimacy of the server and therefore could not establish a secure connection to it. To learn more about this situation and how to fix it, please visit the web page mentioned above.

... different topic but IMO it should be mandatory to use HTTPS for all official APT repositories. Unthinkable what is theoretically possible when some hacked DNS entry leads to you to a fake repo and APT/DPKG installs/updates some system core packages to whatever is desired to spy out data, passwords etc.? Nowadays HTTPS everywhere! 😃

@Fourdee 
Same for http://fuzon.co.uk/meveric/, perhaps you find some time to apply Let's Encrypt for it as well? Or add it to cloudflare, not sure if two domains are still for free?

> https://gist.github.com/cosimo/5747881

No explicit timeout exit code. Either 1 or 4 then:

2019-04-22 15:12:17 root@micha:/tmp# wget --spider -T 0.01 https://deb.debian.org; echo $? Spider mode enabled. Check if remote file exists. --2019-04-22 15:12:26-- https://deb.debian.org/ Resolving deb.debian.org (deb.debian.org)... failed: Connection timed out. wget: unable to resolve host address ‘deb.debian.org’ 4

- `4`

Also nice that one can define the individual timeouts, e.g. to test DNS resolving explicitly:

-T, --timeout=SECONDS set all timeout values to SECONDS --dns-timeout=SECS set the DNS lookup timeout to SECS --connect-timeout=SECS set the connect timeout to SECS --read-timeout=SECS set the read timeout to SECS

2019-04-22 15:15:50 root@micha:/tmp# time wget --spider -T 0.01 --dns-timeout=5 https://deb.debian.org; echo $? Spider mode enabled. Check if remote file exists. --2019-04-22 15:16:13-- https://deb.debian.org/ Resolving deb.debian.org (deb.debian.org)... 149.20.4.15, 130.89.148.14, 128.31.0.62, ... Connecting to deb.debian.org (deb.debian.org)|149.20.4.15|:443... failed: Connection timed out. Connecting to deb.debian.org (deb.debian.org)|130.89.148.14|:443... failed: Connection timed out. Connecting to deb.debian.org (deb.debian.org)|128.31.0.62|:443... failed: Connection timed out. Connecting to deb.debian.org (deb.debian.org)|5.153.231.4|:443... failed: Connection timed out. Connecting to deb.debian.org (deb.debian.org)|2001:41c8:1000:21::21:4|:443... failed: Address family not supported by protocol. Connecting to deb.debian.org (deb.debian.org)|2001:67c:2564:a119::148:14|:443... failed: Address family not supported by protocol. Connecting to deb.debian.org (deb.debian.org)|2001:4f8:1:c::15|:443... failed: Address family not supported by protocol.

real 0m0.228s user 0m0.082s sys 0m0.040s 4

- Given enough time to resolve the hostname and get 7 IPs. Then only 0.01 seconds to connect, which of course times out. All addresses are looped through. IPv6 fails since I completely disabled it on kernel level on my RPi.
- Sadly the output is always the same `Connection timed out`, no matter if it was DNS resolving or connection. Reading content timeout is different, but error code the same:

2019-04-22 15:23:06 root@micha:/tmp# time wget --spider --tries=1 --read-timeout=0.1 https://deb.debian.org; echo $? Spider mode enabled. Check if remote file exists. --2019-04-22 15:23:28-- https://deb.debian.org/ Resolving deb.debian.org (deb.debian.org)... 149.20.4.15, 128.31.0.62, 130.89.148.14, ... Connecting to deb.debian.org (deb.debian.org)|149.20.4.15|:443... connected. HTTP request sent, awaiting response... Read error (Success.) in headers. Giving up.

real 0m0.790s user 0m0.146s sys 0m0.029s 4

MichaIng commented 5 years ago

Btw:

What we define with -T/--timeout is applied to all three timeouts: DNS resolving, connecting and reading.
So theoretically the overall timeout is now up to 15 seconds, if everything succeeds just before 5s ends 😉.
Usually this does not apply since only a single step hangs or one step fails immediately and such, but actually it would be cool to have an overall timeout. wget does not have such option.

I will play around with curl as well. As said it executes faster and seems to have more options. curl -LI https://deb.debian.org/debian to follow redirects and get page info only, so to behave like wget --spider. But before applying, it needs to be tested at best on all URLs we check in our code. If we are lucky, it even successfully checks URLs successfully that wget cannot (there are some).

MichaIng commented 5 years ago

For now resolved with: https://github.com/MichaIng/DietPi/issues/2717#issuecomment-485405270

StephanStS commented 4 years ago

I had also this issue. The reason was a wrong entry in the /etc/resolv.conf which was caused by a wrong IPv6 nameserver entry in my Fritzbox.

How did it happen? I am running a pi-hole on my network and I changed the pi-hole hardware some weeks ago. The static IPv4 setting of the new pi-hole hardware I did correct via dietpi-config. But I did not change the IPv6 setting of the pi-hole. Then the Fritzbox had the IPv6 nameserver setting of the old pi-hole hardware and gave this via DHCP to all nodes.

Countermeasure: In the Fritzbox web interface I had to set the IPv6 nameserver setting to the correct value (menue entry in german language: "->Heimnetz->Netzwerk", tab "Netzwerkeinstellungen", sub-dialog "IPv6-Adressen", entry of "DNSv6-Server im Heimnetz".

Then, all worked fine.

lord-aceldama commented 1 year ago

i've managed to fix the issue by following the advice iven here: https://serverfault.com/a/858665

when you append the following line to the resolve.conf file the dns resolution becomes blindingly fast again as it was in the older distros. hope this helps.

options single-request-reopen

MichaIng commented 1 year ago

Interesting, seems to be a problem with certain hardware: https://manpages.debian.org/bullseye/resolv.conf#single

MichaIng / DietPi