nroi / flexo

a central pacman cache
MIT License
180 stars 10 forks source link

Verbose mode? #22

Closed Kernald closed 4 years ago

Kernald commented 4 years ago

I've been using Flexo for a while using Docker, and had to restart it today. It's not starting anymore:

[2020-10-27T04:47:21Z INFO  flexo] Will switch mirror if download speed falls below 125.00 KiB/s
[2020-10-27T04:47:25Z ERROR flexo] Unable to find remote mirrors that match the selected criteria.

I've got those two lines, and the container stops.

I tried specifying a few things through the configuration file, which didn't make any difference. Is there any way to enable a more verbose output?

nroi commented 4 years ago

The RUST_LOG environment variable is used to determine the logging verbosity. For example:

docker run -it --rm -e RUST_LOG=debug nroi/flexo:1.0.7

Could you try it with RUST_LOG=debug and the most recent version (1.0.7) and post relevant output?

Kernald commented 4 years ago

Thanks! RUST_LOG is indeed helpful. With the Docker image I was using yesterday (I believe 1.0.5):

[2020-10-27T22:22:45Z INFO  flexo] Will switch mirror if download speed falls below 125.00 KiB/s
[2020-10-27T22:22:45Z DEBUG flexo::mirror_fetch] Fetch json from "https://www.archlinux.org/mirrors/status/json/"
[2020-10-27T22:22:48Z DEBUG flexo] mirrors: []
[2020-10-27T22:22:48Z ERROR flexo] Unable to find remote mirrors that match the selected criteria.

With 1.0.7 (not changing anything else):

[2020-10-27T22:25:15.504Z INFO  flexo] Will switch mirror if download speed falls below 125.00 KiB/s
[2020-10-27T22:25:15.504Z DEBUG flexo::mirror_fetch] Fetch json from "https://www.archlinux.org/mirrors/status/json/"
[2020-10-27T22:25:17.982Z DEBUG flexo::mirror_flexo] Mirrors will be filtered according to the following criteria: MirrorsAutoConfig { mirrors_status_json_endpoint: "https://www.archlinux.org/mirrors/status/json/", mirrors_blacklist: [], https_required: true, ipv4: true, ipv6: true, max_score: 2.5, num_mirrors: 8, mirrors_random_or_sort: Sort, timeout: 350 }
[2020-10-27T22:25:17.982Z DEBUG flexo::mirror_flexo] Running latency tests on the following mirrors: [MirrorUrl { url: "https://mirror.f4st.host/archlinux/", protocol: Https, last_sync: "2020-10-27T22:09:01Z", completion_pct: 1.0, delay: 29, duration_avg: 0.013406656682491302, duration_stddev: 0.004428161437478982, score: 25890373675525, country: "Germany", ipv4: true, ipv6: true }, MirrorUrl { url: "https://mirror.chaoticum.net/arch/", protocol: Https, last_sync: "2020-10-27T22:09:01Z", completion_pct: 1.0, delay: 58, duration_avg: 0.01405341923236847, duration_stddev: 0.0024185974053630445, score: 32583127748842, country: "Germany", ipv4: true, ipv6: true }, MirrorUrl { url: "https://mirror.pkgbuild.com/", protocol: Https, last_sync: "2020-10-27T22:09:26Z", completion_pct: 1.0, delay: 65, duration_avg: 0.0335591658949852, duration_stddev: 0.00473084011079554, score: 56345561561336, country: "Germany", ipv4: true, ipv6: true }, MirrorUrl { url: "https://archlinux.mailtunnel.eu/", protocol: Https, last_sync: "2020-10-27T22:10:01Z", completion_pct: 1.0, delay: 61, duration_avg: 0.05357261747121811, duration_stddev: 0.004728345597899904, score: 75245407513562, country: "France", ipv4: true, ipv6: true }, MirrorUrl { url: "https://arch.jensgutermuth.de/", protocol: Https, last_sync: "2020-10-27T22:09:26Z", completion_pct: 1.0, delay: 93, duration_avg: 0.03979584574699402, duration_stddev: 0.017233587657026844, score: 82862766737354, country: "Germany", ipv4: true, ipv6: true }, MirrorUrl { url: "https://archlinux.uk.mirror.allworldit.com/archlinux/", protocol: Https, last_sync: "2020-10-27T22:10:01Z", completion_pct: 1.0, delay: 45, duration_avg: 0.07831766456365585, duration_stddev: 0.0037652256244895977, score: 94582890188145, country: "United Kingdom", ipv4: true, ipv6: true }, MirrorUrl { url: "https://phinau.de/arch/", protocol: Https, last_sync: "2020-10-27T22:09:26Z", completion_pct: 1.0, delay: 81, duration_avg: 0.07069239020347595, duration_stddev: 0.00670561477385768, score: 99898004977333, country: "Germany", ipv4: true, ipv6: true }, MirrorUrl { url: "https://ftp.sh.cvut.cz/arch/", protocol: Https, last_sync: "2020-10-27T22:09:01Z", completion_pct: 1.0, delay: 33, duration_avg: 0.08090854436159134, duration_stddev: 0.015045049646530096, score: 105120260674788, country: "Czechia", ipv4: true, ipv6: true }]
[2020-10-27T22:25:19.614Z DEBUG flexo] Mirror latency test results: []
[2020-10-27T22:25:19.614Z ERROR flexo] Unable to find remote mirrors that match the selected criteria.

Given that I live in Australia, I think the initial selection is somehow wrong. If I open https://www.archlinux.org/mirrors/status/json/ on my laptop (from the same LAN, no proxy, VPN or anything), I get Australian servers listed first. I don't know how Archlinux's geolocation works, but that might be the issue?

nroi commented 4 years ago

The problem seems to be that the mirror selection process and the default settings are not ideal. I suggest you try to change the FLEXO_MIRRORS_AUTO_TIMEOUT (milliseconds) as well as the FLEXO_MIRRORS_AUTO_NUM_MIRRORS environment variable. For example, try it with FLEXO_MIRRORS_AUTO_TIMEOUT=800 and FLEXO_MIRRORS_AUTO_NUM_MIRRORS=60 and see if that helps.

Given that I live in Australia, I think the initial selection is somehow wrong. If I open https://www.archlinux.org/mirrors/status/json/ on my laptop (from the same LAN, no proxy, VPN or anything), I get Australian servers listed first. I don't know how Archlinux's geolocation works, but that might be the issue?

I'm located in Germany, and I also see Australian servers at the first two positions, so I don't think that they use anything like Geolocation.

The problem seems to be that Flexo is doing an initial selection of only 8 mirrors without considering your location. Those 8 mirrors happen to be located in Europe, so if you're located in Australia, you have a relatively high latency to those mirrors. Now the next problem is that Flexo uses a default timeout of 350 ms, so if the latency exceeds this threshold, the mirror will not be considered. In your case, it seems that all mirrors exceed the threshold so there aren't any mirrors left, hence the error message. I've created a new issue (#23) to improve this. I just never had this issue because I'm located in Germany and lots of mirrors are located in Germany or at least in Europe, so thank you for reporting this!

Kernald commented 4 years ago

This makes a lot of sense, thanks! Increasing the number of mirrors to consider did the trick. I'll close this issue in favour of #23 and #24 - please feel free to ping me to test things from Australia, I'd be happy to help!