flexo: signature from is invalid

Hey,

Sometimes when using flexo, I’ve noticed errors when my machine is validating packages in the form of:

error: <package>: signature from "<person>" is invalid
:: File /var/cache/pacman/pkg/<package>.pkg.tar.zst is corrupted (invalid or corrupted package (PGP signature)).
Do you want to delete it? [Y/n] 

Neither Y nor n fixes the problem. Clearing out the flexo cache does. Re-downloading the archlinux-keyring also does not fix this issue.

Could this be a stale package cached in flexo somehow? Is there any mitigation for this instead of clearing out the flexo cache?

About this issue

  • Original URL
  • State: open
  • Created 2 years ago
  • Comments: 23 (11 by maintainers)

Commits related to this issue

Most upvoted comments

Thanks for providing the logs, @exalented!

HTTP response code is 206. AKA the remote isn’t ready with the file yet.

actually, 206 is the expected response when the client requests just part of the file. For example, when pacman initiates a download from flexo, then aborts it, and later on downloads the same file again, the expected behavior is that flexo resumes the download, so it sends a range request to the remote mirror and the remote mirror responds with 206. 416 is the response when the client for some reason sends a wrong range request that cannot be fulfilled by the server.

I wasn’t able to completely figure out what exactly is happening for what reasons from the logs, but something that definitely looks wrong is this:

pacman_cache  | [2023-09-15T20:19:23.596Z INFO  flexo] Error: JobTerminated { channel: DownloadChannel { handle: Easy { handle: 0x7fb510018e70, handler: DownloadState { job_state: JobState { order: DownloadOrder { requested_path: StrPath { path_buf: "extra/os/x86_64/unibilium-2.1.1-1-x86_64.pkg.tar.zst.sig", inner: "extra/os/x86_64/unibilium-2.1.1-1-x86_64.pkg.tar.zst.sig" }, cacheability: Cacheable }, job_resources: Some(DownloadJobResources { file_state: FileState { buf_writer: BufWriter { writer: File { fd: 9, path: "/var/cache/flexo/pkg/extra/os/x86_64/unibilium-2.1.1-1-x86_64.pkg.tar.zst.sig", read: false, write: true }, buffer: 0/8192 }, size_written: 0, filename: "unibilium-2.1.1-1-x86_64.pkg.tar.zst.sig" }, header_state: HeaderState { received_header: [72, 84, 84, 80, 47, 49, 46, 49, 32, 52, 49, 54, 32, 82, 101, 113, 117, 101, 115, 116, 101, 100, 32, 82, 97, 110, 103, 101, 32, 78, 111, 116, 32, 83, 97, 116, 105, 115, 102, 105, 97, 98, 108, 101, 13, 10, 83, 101, 114, 118, 101, 114, 58, 32, 110, 103, 105, 110, 120, 13, 10, 68, 97, 116, 101, 58, 32, 70, 114, 105, 44, 32, 49, 53, 32, 83, 101, 112, 32, 50, 48, 50, 51, 32, 50, 48, 58, 49, 57, 58, 50, 51, 32, 71, 77, 84, 13, 10, 67, 111, 110, 116, 101, 110, 116, 45, 84, 121, 112, 101, 58, 32, 116, 101, 120, 116, 47, 104, 116, 109, 108, 13, 10, 67, 111, 110, 116, 101, 110, 116, 45, 76, 101, 110, 103, 116, 104, 58, 32, 49, 57, 48, 13, 10, 67, 111, 110, 110, 101, 99, 116, 105, 111, 110, 58, 32, 107, 101, 101, 112, 45, 97, 108, 105, 118, 101, 13, 10, 75, 101, 101, 112, 45, 65, 108, 105, 118, 101, 58, 32, 116, 105, 109, 101, 111, 117, 116, 61, 53, 13, 10, 67, 111, 110, 116, 101, 110, 116, 45, 82, 97, 110, 103, 101, 58, 32, 98, 121, 116, 101, 115, 32, 42, 47, 53, 54, 54, 13, 10, 13, 10], header_success: Some(Unavailable) }, 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: Some("0.0.0.0"), mirror_selection_method: Auto, mirrors_predefined: [], custom_repo: None, low_speed_limit: Some(128000), low_speed_limit_formatted: None, low_speed_time_secs: Some(3), connect_timeout: None, max_speed_limit: None, num_versions_retain: Some(3), mirrors_auto: Some(MirrorsAutoConfig { mirrors_status_json_endpoint: "https://archlinux.org/mirrors/status/json/", mirrors_status_json_endpoint_fallbacks: [], mirrors_blacklist: [], https_required: true, ipv4: true, ipv6: false, max_score: 2.5, num_mirrors: 8, mirrors_random_or_sort: Sort, timeout: 350, allowed_countries: [] }) } } } }, error: HttpFailureStatus(416) }, try again
pacman_cache  | [2023-09-15T20:19:23.596Z INFO  flexo] Request served [CACHE HIT]: "extra/os/x86_64/unibilium-2.1.1-1-x86_64.pkg.tar.zst.sig"

The header we have received (1st line in the logs) is this one:

HTTP/1.1 416 Requested Range Not Satisfiable
Server: nginx
Date: Fri, 15 Sep 2023 20:19:23 GMT
Content-Type: text/html
Content-Length: 190
Connection: keep-alive
Keep-Alive: timeout=5
Content-Range: bytes */566

Notice it actually says “try again” in the log, so the re-try logic is already in place. And yet, in almost the exact same time, we have this in the logs:

pacman_cache  | [2023-09-15T20:19:23.596Z INFO  flexo] Request served [CACHE HIT]: "extra/os/x86_64/unibilium-2.1.1-1-x86_64.pkg.tar.zst.sig"

So, even though we haven’t received the required payload from the server, we just serve whatever trash to the client (probably an empty file or an HTML file saying “Not found”), and only after we served this trash to the client, flexo fetches the actual content from the remote mirror.

This does not explain everything, but it’s a start.

Thanks again for providing the logs, I will look into it.

This showed up again for me. I still haven’t figured out how to reliably reproduce it, but it does seem to be failing with an HTTP 416. Thanks for looking into this!

flexo-verify-package output

Mismatches were detected for the following files:

Filename:               wine-7.17-1-x86_64.pkg.tar.zst
File path:              ./var/cache/flexo/pkg/multilib/os/x86_64/wine-7.17-1-x86_64.pkg.tar.zst
Expected sha256sum:     07d43a80980cc53447ab54dcd69b62910b7c4b586d9821d3c95ae69e6016a17e
actual sha256sum:       b1526d5da749b0b01a81b99ec8fb708249b1ee9e1c2b250de0707334cf951293
Expected filesize:      61735728
Actual filesize:        69665584
CFS filesize:           61735728
Modification time:      2022-09-10 18:01:47

Note: the modification time here is correct. I dumped the logs a while back and forgot about them until now…

docker logs output

[2022-09-10T22:01:07.633Z INFO  flexo] Received request for path "kde-unstable/os/x86_64/kde-unstable.db". Range start: 0
[2022-09-10T22:01:07.633Z INFO  flexo] Received request for path "core/os/x86_64/core.db". Range start: 0
[2022-09-10T22:01:07.633Z INFO  flexo] Received request for path "extra/os/x86_64/extra.db". Range start: 0
[2022-09-10T22:01:07.634Z INFO  flexo] Received request for path "community/os/x86_64/community.db". Range start: 0
[2022-09-10T22:01:08.083Z INFO  flexo] Content length of path "core/os/x86_64/core.db" is 160268
[2022-09-10T22:01:08.092Z INFO  flexo] Content length of path "extra/os/x86_64/extra.db" is 1789135
[2022-09-10T22:01:08.107Z INFO  flexo] Content length of path "community/os/x86_64/community.db" is 7257893
[2022-09-10T22:01:08.108Z INFO  flexo] Content length of path "kde-unstable/os/x86_64/kde-unstable.db" is 21326
[2022-09-10T22:01:08.156Z INFO  flexo] Received request for path "multilib/os/x86_64/multilib.db". Range start: 0
[2022-09-10T22:01:08.180Z INFO  flexo] Request served [CACHE MISS]: "kde-unstable/os/x86_64/kde-unstable.db"
[2022-09-10T22:01:08.182Z INFO  flexo] Received request for path "kde-unstable/os/x86_64/kde-unstable.db.sig". Range start: 0
[2022-09-10T22:01:08.268Z INFO  flexo] kde-unstable/os/x86_64/kde-unstable.db.sig is not available at https://mirrors.lug.mtu.edu/archlinux/
[2022-09-10T22:01:08.268Z INFO  flexo] kde-unstable/os/x86_64/kde-unstable.db.sig was unavailable at all remote mirrors.
[2022-09-10T22:01:08.268Z INFO  flexo] Request served [NO PAYLOAD]: "kde-unstable/os/x86_64/kde-unstable.db.sig"
[2022-09-10T22:01:08.340Z INFO  flexo] Request served [CACHE MISS]: "core/os/x86_64/core.db"
[2022-09-10T22:01:08.341Z INFO  flexo] Received request for path "core/os/x86_64/core.db.sig". Range start: 0
[2022-09-10T22:01:08.444Z INFO  flexo] core/os/x86_64/core.db.sig is not available at https://mirrors.lug.mtu.edu/archlinux/
[2022-09-10T22:01:08.445Z INFO  flexo] core/os/x86_64/core.db.sig was unavailable at all remote mirrors.
[2022-09-10T22:01:08.445Z INFO  flexo] Request served [NO PAYLOAD]: "core/os/x86_64/core.db.sig"
[2022-09-10T22:01:08.483Z INFO  flexo] Content length of path "multilib/os/x86_64/multilib.db" is 180441
[2022-09-10T22:01:08.949Z INFO  flexo] Request served [CACHE MISS]: "multilib/os/x86_64/multilib.db"
[2022-09-10T22:01:08.957Z INFO  flexo] Received request for path "multilib/os/x86_64/multilib.db.sig". Range start: 0
[2022-09-10T22:01:09.132Z INFO  flexo] Request served [CACHE MISS]: "extra/os/x86_64/extra.db"
[2022-09-10T22:01:09.134Z INFO  flexo] Received request for path "extra/os/x86_64/extra.db.sig". Range start: 0
[2022-09-10T22:01:09.172Z INFO  flexo] multilib/os/x86_64/multilib.db.sig is not available at https://mirrors.lug.mtu.edu/archlinux/
[2022-09-10T22:01:09.172Z INFO  flexo] multilib/os/x86_64/multilib.db.sig was unavailable at all remote mirrors.
[2022-09-10T22:01:09.172Z INFO  flexo] Request served [NO PAYLOAD]: "multilib/os/x86_64/multilib.db.sig"
[2022-09-10T22:01:09.292Z INFO  flexo] extra/os/x86_64/extra.db.sig is not available at https://mirrors.lug.mtu.edu/archlinux/
[2022-09-10T22:01:09.292Z INFO  flexo] extra/os/x86_64/extra.db.sig was unavailable at all remote mirrors.
[2022-09-10T22:01:09.292Z INFO  flexo] Request served [NO PAYLOAD]: "extra/os/x86_64/extra.db.sig"
[2022-09-10T22:01:10.036Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/community.db"
[2022-09-10T22:01:10.039Z INFO  flexo] Received request for path "community/os/x86_64/community.db.sig". Range start: 0
[2022-09-10T22:01:10.108Z INFO  flexo] community/os/x86_64/community.db.sig is not available at https://mirrors.lug.mtu.edu/archlinux/
[2022-09-10T22:01:10.108Z INFO  flexo] community/os/x86_64/community.db.sig was unavailable at all remote mirrors.
[2022-09-10T22:01:10.108Z INFO  flexo] Request served [NO PAYLOAD]: "community/os/x86_64/community.db.sig"
[2022-09-10T22:01:11.336Z INFO  flexo] Received request for path "community/os/x86_64/blender-17:3.3.0-2-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:11.336Z INFO  flexo] Received request for path "community/os/x86_64/erlang-nox-25.0.4-1-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:11.336Z INFO  flexo] Received request for path "multilib/os/x86_64/wine-7.17-1-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:11.337Z INFO  flexo] Received request for path "community/os/x86_64/docker-1:20.10.18-1-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:11.337Z INFO  flexo] Received request for path "community/os/x86_64/go-2:1.19.1-1-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:11.652Z INFO  flexo] Content length of path "community/os/x86_64/blender-17:3.3.0-2-x86_64.pkg.tar.zst" is 73103523
[2022-09-10T22:01:11.669Z INFO  flexo] Content length of path "community/os/x86_64/go-2:1.19.1-1-x86_64.pkg.tar.zst" is 80458359
[2022-09-10T22:01:11.670Z INFO  flexo] Content length of path "community/os/x86_64/erlang-nox-25.0.4-1-x86_64.pkg.tar.zst" is 41575331
[2022-09-10T22:01:11.693Z INFO  flexo] Content length of path "multilib/os/x86_64/wine-7.17-1-x86_64.pkg.tar.zst" is 61735728
[2022-09-10T22:01:11.693Z INFO  flexo] Content length of path "community/os/x86_64/docker-1:20.10.18-1-x86_64.pkg.tar.zst" is 28908403
[2022-09-10T22:01:38.084Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/docker-1:20.10.18-1-x86_64.pkg.tar.zst"
[2022-09-10T22:01:38.085Z INFO  flexo] Received request for path "community/os/x86_64/docker-1:20.10.18-1-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:38.181Z INFO  flexo] Content length of path "community/os/x86_64/docker-1:20.10.18-1-x86_64.pkg.tar.zst.sig" is 590
[2022-09-10T22:01:38.182Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/docker-1:20.10.18-1-x86_64.pkg.tar.zst.sig"
[2022-09-10T22:01:38.198Z INFO  flexo] Received request for path "community/os/x86_64/nushell-0.68.1-1-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:38.344Z INFO  flexo] Content length of path "community/os/x86_64/nushell-0.68.1-1-x86_64.pkg.tar.zst" is 12066760
[2022-09-10T22:01:47.210Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/nushell-0.68.1-1-x86_64.pkg.tar.zst"
[2022-09-10T22:01:47.211Z INFO  flexo] Received request for path "community/os/x86_64/nushell-0.68.1-1-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:47.284Z INFO  flexo] Content length of path "community/os/x86_64/nushell-0.68.1-1-x86_64.pkg.tar.zst.sig" is 566
[2022-09-10T22:01:47.285Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/nushell-0.68.1-1-x86_64.pkg.tar.zst.sig"
[2022-09-10T22:01:47.293Z INFO  flexo] Received request for path "extra/os/x86_64/python-numpy-1.23.3-1-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:47.328Z INFO  flexo] Request served [CACHE MISS]: "multilib/os/x86_64/wine-7.17-1-x86_64.pkg.tar.zst"
[2022-09-10T22:01:47.351Z INFO  flexo] Received request for path "multilib/os/x86_64/wine-7.17-1-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:47.358Z INFO  flexo] Content length of path "extra/os/x86_64/python-numpy-1.23.3-1-x86_64.pkg.tar.zst" is 5948879
[2022-09-10T22:01:47.401Z INFO  flexo] Error: JobTerminated { channel: DownloadChannel { handle: Easy { handle: 0x7f00b801bc30, handler: DownloadState { job_state: JobState { order: DownloadOrder { requested_path: StrPath { path_buf: "multilib/os/x86_64/wine-7.17-1-x86_64.pkg.tar.zst.sig", inner: "multilib/os/x86_64/wine-7.17-1-x86_64.pkg.tar.zst.sig" }, cacheability: Cacheable }, job_resources: Some(DownloadJobResources { file_state: FileState { buf_writer: BufWriter { writer: File { fd: 10, path: "/var/cache/flexo/pkg/multilib/os/x86_64/wine-7.17-1-x86_64.pkg.tar.zst.sig", read: false, write: true }, buffer: 0/8192 }, size_written: 0 }, header_state: HeaderState { received_header: [72, 84, 84, 80, 47, 49, 46, 49, 32, 52, 49, 54, 32, 82, 101, 113, 117, 101, 115, 116, 101, 100, 32, 82, 97, 110, 103, 101, 32, 78, 111, 116, 32, 83, 97, 116, 105, 115, 102, 105, 97, 98, 108, 101, 13, 10, 83, 101, 114, 118, 101, 114, 58, 32, 110, 103, 105, 110, 120, 13, 10, 68, 97, 116, 101, 58, 32, 83, 97, 116, 44, 32, 49, 48, 32, 83, 101, 112, 32, 50, 48, 50, 50, 32, 50, 50, 58, 48, 49, 58, 52, 55, 32, 71, 77, 84, 13, 10, 67, 111, 110, 116, 101, 110, 116, 45, 84, 121, 112, 101, 58, 32, 116, 101, 120, 116, 47, 104, 116, 109, 108, 59, 32, 99, 104, 97, 114, 115, 101, 116, 61, 117, 116, 102, 45, 56, 13, 10, 67, 111, 110, 116, 101, 110, 116, 45, 76, 101, 110, 103, 116, 104, 58, 32, 49, 57, 48, 13, 10, 67, 111, 110, 110, 101, 99, 116, 105, 111, 110, 58, 32, 107, 101, 101, 112, 45, 97, 108, 105, 118, 101, 13, 10, 69, 120, 112, 105, 114, 101, 115, 58, 32, 83, 117, 110, 44, 32, 49, 49, 32, 83, 101, 112, 32, 50, 48, 50, 50, 32, 50, 50, 58, 48, 49, 58, 52, 55, 32, 71, 77, 84, 13, 10, 67, 97, 99, 104, 101, 45, 67, 111, 110, 116, 114, 111, 108, 58, 32, 109, 97, 120, 45, 97, 103, 101, 61, 56, 54, 52, 48, 48, 13, 10, 88, 45, 70, 114, 97, 109, 101, 45, 79, 112, 116, 105, 111, 110, 115, 58, 32, 68, 69, 78, 89, 13, 10, 88, 45, 67, 111, 110, 116, 101, 110, 116, 45, 84, 121, 112, 101, 45, 79, 112, 116, 105, 111, 110, 115, 58, 32, 110, 111, 115, 110, 105, 102, 102, 13, 10, 67, 111, 110, 116, 101, 110, 116, 45, 82, 97, 110, 103, 101, 58, 32, 98, 121, 116, 101, 115, 32, 42, 47, 53, 54, 54, 13, 10, 88, 45, 70, 114, 97, 109, 101, 45, 79, 112, 116, 105, 111, 110, 115, 58, 32, 68, 69, 78, 89, 13, 10, 88, 45, 67, 111, 110, 116, 101, 110, 116, 45, 84, 121, 112, 101, 45, 79, 112, 116, 105, 111, 110, 115, 58, 32, 110, 111, 115, 110, 105, 102, 102, 13, 10, 13, 10], header_success: Some(Unavailable) }, 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: Some("0.0.0.0"), mirror_selection_method: Auto, mirrors_predefined: [], custom_repo: None, low_speed_limit: Some(128000), low_speed_limit_formatted: None, low_speed_time_secs: Some(3), connect_timeout: None, max_speed_limit: None, num_versions_retain: Some(3), mirrors_auto: Some(MirrorsAutoConfig { mirrors_status_json_endpoint: "https://archlinux.org/mirrors/status/json/", mirrors_status_json_endpoint_fallbacks: [], mirrors_blacklist: [], https_required: true, ipv4: true, ipv6: false, max_score: 2.5, num_mirrors: 8, mirrors_random_or_sort: Sort, timeout: 350, allowed_countries: [] }) } } } }, error: HttpFailureStatus(416) }, try again
[2022-09-10T22:01:47.402Z INFO  flexo] Request served [CACHE HIT]: "multilib/os/x86_64/wine-7.17-1-x86_64.pkg.tar.zst.sig"
[2022-09-10T22:01:47.402Z INFO  flexo] Received request for path "extra/os/x86_64/python-virtualenv-20.13.2-1-any.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:47.724Z INFO  flexo] Content length of path "extra/os/x86_64/python-virtualenv-20.13.2-1-any.pkg.tar.zst" is 5468709
[2022-09-10T22:01:48.430Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/erlang-nox-25.0.4-1-x86_64.pkg.tar.zst"
[2022-09-10T22:01:48.432Z INFO  flexo] Received request for path "community/os/x86_64/erlang-nox-25.0.4-1-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:48.598Z INFO  flexo] Content length of path "community/os/x86_64/erlang-nox-25.0.4-1-x86_64.pkg.tar.zst.sig" is 566
[2022-09-10T22:01:48.599Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/erlang-nox-25.0.4-1-x86_64.pkg.tar.zst.sig"
[2022-09-10T22:01:48.600Z INFO  flexo] Received request for path "community/os/x86_64/zellij-0.31.4-1-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:48.745Z INFO  flexo] Content length of path "community/os/x86_64/zellij-0.31.4-1-x86_64.pkg.tar.zst" is 4180267
[2022-09-10T22:01:49.103Z INFO  flexo] Request served [CACHE MISS]: "extra/os/x86_64/python-virtualenv-20.13.2-1-any.pkg.tar.zst"
[2022-09-10T22:01:49.104Z INFO  flexo] Received request for path "extra/os/x86_64/python-virtualenv-20.13.2-1-any.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:49.177Z INFO  flexo] Content length of path "extra/os/x86_64/python-virtualenv-20.13.2-1-any.pkg.tar.zst.sig" is 566
[2022-09-10T22:01:49.178Z INFO  flexo] Request served [CACHE MISS]: "extra/os/x86_64/python-virtualenv-20.13.2-1-any.pkg.tar.zst.sig"
[2022-09-10T22:01:49.184Z INFO  flexo] Received request for path "core/os/x86_64/gawk-5.2.0-3-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:49.261Z INFO  flexo] Content length of path "core/os/x86_64/gawk-5.2.0-3-x86_64.pkg.tar.zst" is 1272255
[2022-09-10T22:01:49.402Z INFO  flexo] Request served [CACHE MISS]: "core/os/x86_64/gawk-5.2.0-3-x86_64.pkg.tar.zst"
[2022-09-10T22:01:49.410Z INFO  flexo] Received request for path "core/os/x86_64/gawk-5.2.0-3-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:49.515Z INFO  flexo] Content length of path "core/os/x86_64/gawk-5.2.0-3-x86_64.pkg.tar.zst.sig" is 141
[2022-09-10T22:01:49.516Z INFO  flexo] Request served [CACHE MISS]: "core/os/x86_64/gawk-5.2.0-3-x86_64.pkg.tar.zst.sig"
[2022-09-10T22:01:49.517Z INFO  flexo] Received request for path "community/os/x86_64/python-prompt_toolkit-3.0.31-1-any.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:49.633Z INFO  flexo] Content length of path "community/os/x86_64/python-prompt_toolkit-3.0.31-1-any.pkg.tar.zst" is 572140
[2022-09-10T22:01:49.673Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/python-prompt_toolkit-3.0.31-1-any.pkg.tar.zst"
[2022-09-10T22:01:49.675Z INFO  flexo] Received request for path "community/os/x86_64/python-prompt_toolkit-3.0.31-1-any.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:49.703Z INFO  flexo] Request served [CACHE MISS]: "extra/os/x86_64/python-numpy-1.23.3-1-x86_64.pkg.tar.zst"
[2022-09-10T22:01:49.703Z INFO  flexo] Received request for path "extra/os/x86_64/python-numpy-1.23.3-1-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:49.765Z INFO  flexo] Content length of path "community/os/x86_64/python-prompt_toolkit-3.0.31-1-any.pkg.tar.zst.sig" is 590
[2022-09-10T22:01:49.766Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/python-prompt_toolkit-3.0.31-1-any.pkg.tar.zst.sig"
[2022-09-10T22:01:49.804Z INFO  flexo] Received request for path "extra/os/x86_64/rsync-3.2.6-1-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:49.929Z INFO  flexo] Content length of path "extra/os/x86_64/rsync-3.2.6-1-x86_64.pkg.tar.zst" is 337369
[2022-09-10T22:01:50.006Z INFO  flexo] Request served [CACHE MISS]: "extra/os/x86_64/rsync-3.2.6-1-x86_64.pkg.tar.zst"
[2022-09-10T22:01:50.007Z INFO  flexo] Received request for path "extra/os/x86_64/rsync-3.2.6-1-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:50.095Z INFO  flexo] Content length of path "extra/os/x86_64/rsync-3.2.6-1-x86_64.pkg.tar.zst.sig" is 119
[2022-09-10T22:01:50.096Z INFO  flexo] Request served [CACHE MISS]: "extra/os/x86_64/rsync-3.2.6-1-x86_64.pkg.tar.zst.sig"
[2022-09-10T22:01:50.097Z INFO  flexo] Received request for path "core/os/x86_64/grep-3.8-2-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:50.154Z INFO  flexo] Content length of path "extra/os/x86_64/python-numpy-1.23.3-1-x86_64.pkg.tar.zst.sig" is 566
[2022-09-10T22:01:50.155Z INFO  flexo] Request served [CACHE MISS]: "extra/os/x86_64/python-numpy-1.23.3-1-x86_64.pkg.tar.zst.sig"
[2022-09-10T22:01:50.172Z INFO  flexo] Received request for path "community/os/x86_64/python-docker-6.0.0-1-any.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:50.204Z INFO  flexo] Content length of path "core/os/x86_64/grep-3.8-2-x86_64.pkg.tar.zst" is 235417
[2022-09-10T22:01:50.232Z INFO  flexo] Request served [CACHE MISS]: "core/os/x86_64/grep-3.8-2-x86_64.pkg.tar.zst"
[2022-09-10T22:01:50.240Z INFO  flexo] Received request for path "core/os/x86_64/grep-3.8-2-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:50.263Z INFO  flexo] Content length of path "community/os/x86_64/python-docker-6.0.0-1-any.pkg.tar.zst" is 192697
[2022-09-10T22:01:50.337Z INFO  flexo] Content length of path "core/os/x86_64/grep-3.8-2-x86_64.pkg.tar.zst.sig" is 119
[2022-09-10T22:01:50.338Z INFO  flexo] Request served [CACHE MISS]: "core/os/x86_64/grep-3.8-2-x86_64.pkg.tar.zst.sig"
[2022-09-10T22:01:50.338Z INFO  flexo] Received request for path "community/os/x86_64/lv2-1.18.10-1-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:50.455Z INFO  flexo] Content length of path "community/os/x86_64/lv2-1.18.10-1-x86_64.pkg.tar.zst" is 161928
[2022-09-10T22:01:50.487Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/lv2-1.18.10-1-x86_64.pkg.tar.zst"
[2022-09-10T22:01:50.514Z INFO  flexo] Received request for path "community/os/x86_64/lv2-1.18.10-1-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:50.604Z INFO  flexo] Content length of path "community/os/x86_64/lv2-1.18.10-1-x86_64.pkg.tar.zst.sig" is 118
[2022-09-10T22:01:50.605Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/lv2-1.18.10-1-x86_64.pkg.tar.zst.sig"
[2022-09-10T22:01:50.607Z INFO  flexo] Received request for path "community/os/x86_64/sratom-0.6.14-1-x86_64.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:50.710Z INFO  flexo] Content length of path "community/os/x86_64/sratom-0.6.14-1-x86_64.pkg.tar.zst" is 19941
[2022-09-10T22:01:50.712Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/sratom-0.6.14-1-x86_64.pkg.tar.zst"
[2022-09-10T22:01:50.718Z INFO  flexo] Received request for path "community/os/x86_64/sratom-0.6.14-1-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:50.785Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/python-docker-6.0.0-1-any.pkg.tar.zst"
[2022-09-10T22:01:50.785Z INFO  flexo] Received request for path "community/os/x86_64/python-docker-6.0.0-1-any.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:50.786Z INFO  flexo] Content length of path "community/os/x86_64/sratom-0.6.14-1-x86_64.pkg.tar.zst.sig" is 119
[2022-09-10T22:01:50.786Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/sratom-0.6.14-1-x86_64.pkg.tar.zst.sig"
[2022-09-10T22:01:50.819Z INFO  flexo] Received request for path "community/os/x86_64/python-certifi-2022.06.15.1-1-any.pkg.tar.zst". Range start: 0
[2022-09-10T22:01:50.886Z INFO  flexo] Content length of path "community/os/x86_64/python-docker-6.0.0-1-any.pkg.tar.zst.sig" is 590
[2022-09-10T22:01:50.886Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/python-docker-6.0.0-1-any.pkg.tar.zst.sig"
[2022-09-10T22:01:51.084Z INFO  flexo] Content length of path "community/os/x86_64/python-certifi-2022.06.15.1-1-any.pkg.tar.zst" is 8808
[2022-09-10T22:01:51.084Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/python-certifi-2022.06.15.1-1-any.pkg.tar.zst"
[2022-09-10T22:01:51.092Z INFO  flexo] Received request for path "community/os/x86_64/python-certifi-2022.06.15.1-1-any.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:51.200Z INFO  flexo] Content length of path "community/os/x86_64/python-certifi-2022.06.15.1-1-any.pkg.tar.zst.sig" is 119
[2022-09-10T22:01:51.200Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/python-certifi-2022.06.15.1-1-any.pkg.tar.zst.sig"
[2022-09-10T22:01:51.873Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/zellij-0.31.4-1-x86_64.pkg.tar.zst"
[2022-09-10T22:01:51.874Z INFO  flexo] Received request for path "community/os/x86_64/zellij-0.31.4-1-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:01:51.954Z INFO  flexo] Content length of path "community/os/x86_64/zellij-0.31.4-1-x86_64.pkg.tar.zst.sig" is 566
[2022-09-10T22:01:51.955Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/zellij-0.31.4-1-x86_64.pkg.tar.zst.sig"
[2022-09-10T22:02:07.402Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/blender-17:3.3.0-2-x86_64.pkg.tar.zst"
[2022-09-10T22:02:07.404Z INFO  flexo] Received request for path "community/os/x86_64/blender-17:3.3.0-2-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:02:07.486Z INFO  flexo] Content length of path "community/os/x86_64/blender-17:3.3.0-2-x86_64.pkg.tar.zst.sig" is 566
[2022-09-10T22:02:07.487Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/blender-17:3.3.0-2-x86_64.pkg.tar.zst.sig"
[2022-09-10T22:02:09.194Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/go-2:1.19.1-1-x86_64.pkg.tar.zst"
[2022-09-10T22:02:09.196Z INFO  flexo] Received request for path "community/os/x86_64/go-2:1.19.1-1-x86_64.pkg.tar.zst.sig". Range start: 0
[2022-09-10T22:02:09.277Z INFO  flexo] Content length of path "community/os/x86_64/go-2:1.19.1-1-x86_64.pkg.tar.zst.sig" is 590
[2022-09-10T22:02:09.277Z INFO  flexo] Request served [CACHE MISS]: "community/os/x86_64/go-2:1.19.1-1-x86_64.pkg.tar.zst.sig"

Here are the differing .pkg.tar.zst files: package_tars.zip

I’m curious why not have an option to have flexo check /etc/pacman.d/mirrorlist? Like I mentioned I already use reflector so I know those mirrors work.

One of flexo’s goal is to minimize the time users need to invest for mirrorlist maintenance, and not everyone uses reflector. But of course, it would be possible to implement this as an additional option.

Thanks for the journalctl output.

I went ahead and updated /etc/pacman.d/mirrorlist on my flexo server. I ran reflector, so if this was the case of a bad mirror, hopefully it is gone now.

Keep in mind that flexo ignores /etc/pacman.d/mirrorlist, it fetches a list of mirrors from the official JSON API and then runs latency tests to select fast mirrors. So, if you want to avoid flexo choosing bad mirrors, you need to use the mirrors_blacklist option, as explained in my previous post.

So it just happened again. This happens on the client machine, during the Checking package Integrity step:

error: linux-lts: signature from "Andreas Radke <andyrtr@archlinux.org>" is invalid
:: File /var/cache/pacman/pkg/linux-lts-5.15.45-1-x86_64.pkg.tar.zst is corrupted (invalid or corrupted package (PGP signature)).
Do you want to delete it? [Y/n] 
error: failed to commit transaction (invalid or corrupted package)
Errors occurred, no packages were upgraded.

The sha256sum before clearing out the package cache for all matching files is:

# sha256sum $( find ./ | grep linux-lts-5.15.45-1-x86_64.pkg.tar.zst | xargs)
d83324c5710c0b59371a53194821d31ff38a50e18af17364248add71ba011d6a  ./core/os/x86_64/linux-lts-5.15.45-1-x86_64.pkg.tar.zst.sig
bfa9b234f73416c3f7d3bb668b28d25467e1007087aadc3d8571a9c838ac316a  ./core/os/x86_64/.linux-lts-5.15.45-1-x86_64.pkg.tar.zst.sig.cfs
1fc9438708ffeabaa9a9bdb95a8cb6e8df922838f8f3f62b30c34180a0d18f8c  ./core/os/x86_64/.linux-lts-5.15.45-1-x86_64.pkg.tar.zst.cfs
1af8f502f87da3c76a3cb5e25f15a90c7ecacb42b535842889aee85077f1dbb7  ./core/os/x86_64/linux-lts-5.15.45-1-x86_64.pkg.tar.zst

I cleared out the pkg cache and restarted the flexo service, ran pacman -Sc on the client, and re-ran the update on the client. Running the sha26sum command on the flexo server again, I see:

# sha256sum $( find ./ | grep linux-lts-5.15.45-1-x86_64.pkg.tar.zst | xargs)
d83324c5710c0b59371a53194821d31ff38a50e18af17364248add71ba011d6a  ./core/os/x86_64/linux-lts-5.15.45-1-x86_64.pkg.tar.zst.sig
bfa9b234f73416c3f7d3bb668b28d25467e1007087aadc3d8571a9c838ac316a  ./core/os/x86_64/.linux-lts-5.15.45-1-x86_64.pkg.tar.zst.sig.cfs
8bdfbbf5bdff5d2ff5863ee25ff027c3532a14b445df39de3af3e0f7265f0c35  ./core/os/x86_64/.linux-lts-5.15.45-1-x86_64.pkg.tar.zst.cfs
c825a66094df4458f410c2bf2f04753a7ed7bb4eefe896d6fbff43ed229a1737  ./core/os/x86_64/linux-lts-5.15.45-1-x86_64.pkg.tar.zst

Edit: This is either caused by misbehaving mirrors or a bug in flexo, but I think a bug in flexo is more likely. I’m looking into this issue, but I still haven’t found a way to reproduce it. If anyone stumbles on this issue, you can help me troubleshoot this issue as follows:

  1. Run the flexo-verify-package python script on the machine that’s running flexo and paste the output of that script.
  2. The journalctl log (or output from docker logs if you use docker) from the time frame when the download has happened, e.g. journalctl --unit=flexo --since today.

The more output I receive, the better!


Original answer:

Could this be a stale package cached in flexo somehow?

I guess so. Probably either the package itself, or the signature (the corresponding file ending with .sig) has changed, but flexo serves the stale version from cache.

I’d like to find out if the package file (the file ending with .zst), or the signature file (ending with .sig), or both files are stale. Next time when this issue happens, can you please check which files change after you clear out the flexo cache? For example, you can run sha256sum <package>.zst and sha256sum <package>.zst.sig before clearing the flexo cache (replace <package> by any package from the error message shown by pacman), and then run the same two commands again after clearing the flexo cache to compare the checksums and see which files have changed.

Once I understand the problem, I can think of a solution.