[bug] flexo serves 0 length files

[ivdimitro]

Hi, due to some unknown reason a package download can fail and flexo identifies the file as "0 length". The issue is that it keeps in the cache and continues to serve it.

Expected result: 0 length files are automatically deleted and re downloaded if necessary. Here is log of such occurrence:

Apr 13 11:59:27 arch-builder flexo[55449]: [2021-04-13T09:59:27.307Z INFO  flexo] Request served [CACHE HIT]: "extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst"
Apr 13 11:59:27 arch-builder flexo[55449]: [2021-04-13T09:59:27.307Z INFO  flexo::mirror_flexo] The file "/var/cache/flexo/pkg/extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst" used to lack the content-length attribute, this attribute has now been set to 0.
Apr 13 11:59:26 arch-builder flexo[55449]: [2021-04-13T09:59:26.384Z INFO  flexo] Error: JobTerminated { channel: DownloadChannel { handle: Easy { handle: 0x7f0d14002890, handler: DownloadState { job_state: JobState { order: DownloadOrder { filepath: StrPath { path_buf: "extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst", inner: "extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst" } }, job_resources: Some(DownloadJobResources { file_state: FileState { buf_writer: BufWriter { writer: File { fd: 12, path: "/var/cache/flexo/pkg/extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst", read: false, write: true }, buffer: 0/8192 }, size_written: 0 }, header_state: HeaderState { received_header: [], header_success: None }, last_chance: true }), tx: Sender { .. } }, properties: MirrorConfig { cache_directory: "/var/cache/flexo/pkg", mirrorlist_fallback_file: "/var/cache/flexo/state/mirrorlist", mirrorlist_latency_test_results_file: Some("/var/cache/flexo/state/latency_test_results.json"), refresh_latency_tests_after: None, port: 7878, listen_ip_address: None, mirror_selection_method: Auto, mirrors_predefined: [], custom_repo: Some([CustomRepo { name: "archzfs", url: "http://mirror.sum7.eu/archlinux/" }, CustomRepo { name: "aurto", url: "http://10.10.50.31:8080/aurto/" }]), low_speed_limit: None, low_speed_time_secs: Some(3), max_speed_limit: None, num_versions_retain: Some(3), mirrors_auto: Some(MirrorsAutoConfig { mirrors_status_json_endpoint: "https://archlinux.org/mirrors/status/json/", mirrors_blacklist: [], https_required: false, ipv4: true, ipv6: false, max_score: 1.0, num_mirrors: 3, mirrors_random_or_sort: Random, timeout: 300, allowed_countries: Some([]) }) } } } }, error: CurlError(Error { description: "Timeout was reached", code: 28, extra: Some("Resolving timed out after 3000 milliseconds") }) }, try again
Apr 13 11:59:26 arch-builder flexo[55449]: [2021-04-13T09:59:26.384Z WARN  flexo::mirror_flexo] Unable to download from "http://arch.jensgutermuth.de/extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst": Timeout reached. Try another remote mirror.
Apr 13 11:59:19 arch-builder flexo[55449]: [2021-04-13T09:59:19.803Z ERROR flexo] Unable to serve request "extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst": FileAttrError(TimeoutError)
Apr 13 11:59:19 arch-builder flexo[55449]: [2021-04-13T09:59:19.803Z INFO  flexo] Number of attempts exceeded: File "/var/cache/flexo/pkg/extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst" not found.
Apr 13 11:59:08 arch-builder flexo[55449]: [2021-04-13T09:59:08.632Z ERROR flexo] Unable to serve request "extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst": FileAttrError(TimeoutError)
Apr 13 11:59:08 arch-builder flexo[55449]: [2021-04-13T09:59:08.632Z INFO  flexo] Number of attempts exceeded: File "/var/cache/flexo/pkg/extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst" not found.
Apr 13 11:58:54 arch-builder flexo[55449]: [2021-04-13T09:58:54.777Z INFO  flexo] Request served [NO PAYLOAD]: "extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst"
Apr 13 11:58:52 arch-builder flexo[55449]: [2021-04-13T09:58:52.182Z INFO  flexo] Error: JobTerminated { channel: DownloadChannel { handle: Easy { handle: 0x7f0d14002890, handler: DownloadState { job_state: JobState { order: DownloadOrder { filepath: StrPath { path_buf: "extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst", inner: "extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst" } }, job_resources: Some(DownloadJobResources { file_state: FileState { buf_writer: BufWriter { writer: File { fd: 12, path: "/var/cache/flexo/pkg/extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst", read: false, write: true }, buffer: 0/8192 }, size_written: 0 }, header_state: HeaderState { received_header: [], header_success: None }, last_chance: false }), tx: Sender { .. } }, properties: MirrorConfig { cache_directory: "/var/cache/flexo/pkg", mirrorlist_fallback_file: "/var/cache/flexo/state/mirrorlist", mirrorlist_latency_test_results_file: Some("/var/cache/flexo/state/latency_test_results.json"), refresh_latency_tests_after: None, port: 7878, listen_ip_address: None, mirror_selection_method: Auto, mirrors_predefined: [], custom_repo: Some([CustomRepo { name: "archzfs", url: "http://mirror.sum7.eu/archlinux/" }, CustomRepo { name: "aurto", url: "http://10.10.50.31:8080/aurto/" }]), low_speed_limit: None, low_speed_time_secs: Some(3), max_speed_limit: None, num_versions_retain: Some(3), mirrors_auto: Some(MirrorsAutoConfig { mirrors_status_json_endpoint: "https://archlinux.org/mirrors/status/json/", mirrors_blacklist: [], https_required: false, ipv4: true, ipv6: false, max_score: 1.0, num_mirrors: 3, mirrors_random_or_sort: Random, timeout: 300, allowed_countries: Some([]) }) } } } }, error: CurlError(Error { description: "Timeout was reached", code: 28, extra: Some("Failed to connect to mirror.f4st.host port 443: Connection timed out") }) }, try again
Apr 13 11:58:52 arch-builder flexo[55449]: [2021-04-13T09:58:52.182Z WARN  flexo::mirror_flexo] Unable to download from "https://mirror.f4st.host/archlinux/extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst": Timeout reached. Try another remote mirror.
Apr 13 11:58:50 arch-builder flexo[55449]: [2021-04-13T09:58:50.479Z INFO  flexo] Error: JobTerminated { channel: DownloadChannel { handle: Easy { handle: 0x7f0d140048a0, handler: DownloadState { job_state: JobState { order: DownloadOrder { filepath: StrPath { path_buf: "extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst", inner: "extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst" } }, job_resources: Some(DownloadJobResources { file_state: FileState { buf_writer: BufWriter { writer: File { fd: 12, path: "/var/cache/flexo/pkg/extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst", read: false, write: true }, buffer: 0/8192 }, size_written: 0 }, header_state: HeaderState { received_header: [], header_success: None }, last_chance: false }), tx: Sender { .. } }, properties: MirrorConfig { cache_directory: "/var/cache/flexo/pkg", mirrorlist_fallback_file: "/var/cache/flexo/state/mirrorlist", mirrorlist_latency_test_results_file: Some("/var/cache/flexo/state/latency_test_results.json"), refresh_latency_tests_after: None, port: 7878, listen_ip_address: None, mirror_selection_method: Auto, mirrors_predefined: [], custom_repo: Some([CustomRepo { name: "archzfs", url: "http://mirror.sum7.eu/archlinux/" }, CustomRepo { name: "aurto", url: "http://10.10.50.31:8080/aurto/" }]), low_speed_limit: None, low_speed_time_secs: Some(3), max_speed_limit: None, num_versions_retain: Some(3), mirrors_auto: Some(MirrorsAutoConfig { mirrors_status_json_endpoint: "https://archlinux.org/mirrors/status/json/", mirrors_blacklist: [], https_required: false, ipv4: true, ipv6: false, max_score: 1.0, num_mirrors: 3, mirrors_random_or_sort: Random, timeout: 300, allowed_countries: Some([]) }) } } } }, error: CurlError(Error { description: "Timeout was reached", code: 28, extra: Some("Failed to connect to mirror.f4st.host port 80: Connection timed out") }) }, try again
Apr 13 11:58:50 arch-builder flexo[55449]: [2021-04-13T09:58:50.479Z WARN  flexo::mirror_flexo] Unable to download from "http://mirror.f4st.host/archlinux/extra/os/x86_64/qt5-tools-5.15.2+kde+r17-1-x86_64.pkg.tar.zst": Timeout reached. Try another remote mirror.

Any idea how to increase the downlaod time out as workaround?

[nroi]

Flexo obviously shouldn't create empty files and then assume that 0 is the correct content length, so this is a bug.

Another problem is that, for some reason, the selected mirrors are causing timeouts for you. Could you please tell me if:

• You are located at or near central Europe? Because if you're located at another continent, then there seems to be a problem with the mirror selection process, because the selected mirrors are in Germany.
• Do you generally have a bad or high latency internet connection? Are you using a VPN, or a wireless 3G connection or anything out of the ordinary that could introduce latencies?

As a workaround:

1. Remove all empty files (something like find /var/cache/flexo/pkg -size 0 -print -delete should do the trick.
2. It looks like you currently have the setting mirrors_random_or_sort = "random", try to change this to mirrors_random_or_sort = "sort", because the random setting has not been tested as well as sort.
3. Remove the latency test results and restart Flexo so that the latency test is started again:

   rm /var/cache/flexo/state/latency_test_results.json
   systemctl restart flexo
   

Any idea how to increase the downlaod time out as workaround?

Flexo is currently using the default timeouts from CURL, and so far, I think they have worked well for all users. So I hope we find a solution where fast mirrors are selected so that no timeouts occur.

[ivdimitro]

Thanks for the reply. About the repo, yes I am in Central Europe. My internet is OK but I seems to have some issues with some of the German servers. I have to blacklist the ones that are causing me problem. The issues with those servers was happening even when I was using nginx caching server.