cargo-binstall spuriously fails in CI

[indietyp]

We at HASH have discovered that either cargo-binstall or cargo-quickinstall spuriously fail when trying to install cargo-make sometimes.

The output of binstall (using the install-action) is:

info: install-action does not support cargo-make@0.36.3; fallback to cargo-binstall
info: installing cargo-binstall
info: downloading https://github.com/cargo-bins/cargo-binstall/releases/download/v0.19.3/cargo-binstall-x86_64-unknown-linux-musl.tgz
info: verifying sha256 checksum for cargo-binstall-x86_64-unknown-linux-musl.tgz
info: cargo-binstall installed at /home/runner/.cargo/bin/cargo-binstall
+ cargo binstall -V
0.19.3
 INFO resolve: Resolving package: 'cargo-make@=0.36.3'
ERROR Fatal error:

  × For crate cargo-make: unexpected EOF during skip
  ╰─▶ unexpected EOF during skip

[passcod]

Hmm, that is curious. From the few logs, I believe this is during the resolution process... @NobodyXu correct me if I'm wrong.

As we can't really get debug logs in CI, especially for spurious issues, I'm going to see if I can replicate locally by repeatedly trying... might take a while!

[NobodyXu]

Yes I also believe this happens during the resolution process.

Based on the error message 'unexpected EOF during skip' and the fact that cargo-make v0.36.3 provides a zip archive for x86_64-unknown-linux-musl, I think it's possible this is a bug in async-zip streaming API.

[NobodyXu]

@indietyp If you could run the CI with --log-level debug then it will be much easier for us to find the culprit.

P.S. @passcod Perhaps we should improve err msg of BinstallError, I think we used too much error(transparent) there that error like this lost context?

[indietyp]

I cannot directly set the log-level in the install-action. Would it be possible for binstall to support setting the log level using an env-variable?

This way, we could just set LOG_LEVEL=debug for the action.

[NobodyXu]

Would it be possible for binstall to support setting the log level using an env-variable?

Yes!

We could also add support for tracing_subscriber::EnvFilter.

I cannot directly set the log-level in the install-action.

As a work around, you could use the install-action to install cargo-binstall first, then manually invoke cargo-binstall.

But I think you can just wait until we support specifying log-level via environment and have better error message.

[NobodyXu]

@indietyp cargo-binstall 0.20.1 released which supports env variable CARGO_BINSTALL_LOG_LEVEL to specify log-level.

[NobodyXu]

@indietyp It turns out that we already has an env called BINSTALL_LOG_LEVEL for this.

We plan to remove CARGO_BINSTALL_LOG_LEVEL in next release in favor of BINSTALL_LOG_LEVEL.

[indietyp]

I have enabled BINSTALL_LOG_LEVEL on the relevant PR and will execute the CI a couple of times until (hopefully?) the problem surfaces again.

[indietyp]

info: installing cargo-hack@0.5.26
info: downloading https://github.com/taiki-e/cargo-hack/releases/download/v0.5.26/cargo-hack-x86_64-unknown-linux-musl.tar.gz
info: verifying sha256 checksum for cargo-hack-x86_64-unknown-linux-musl.tar.gz
info: cargo-hack installed at /home/runner/.cargo/bin/cargo-hack
+ cargo hack --version
cargo-hack 0.5.26

info: install-action does not support cargo-make@0.36.3; fallback to cargo-binstall
info: installing cargo-binstall
info: downloading https://github.com/cargo-bins/cargo-binstall/releases/download/v0.20.1/cargo-binstall-x86_64-unknown-linux-musl.tgz
info: verifying sha256 checksum for cargo-binstall-x86_64-unknown-linux-musl.tgz
info: cargo-binstall installed at /home/runner/.cargo/bin/cargo-binstall
+ cargo binstall -V
0.20.1
DEBUG using (/home/runner/.cargo) as cargo home
DEBUG Using install path: /home/runner/.cargo/bin
DEBUG Reading binstall metadata from /home/runner/.cargo/binstall/crates-v1.json and obtaining exclusive lock
DEBUG Obtaining exclusive lock of cargo install v1 metadata in path /home/runner/.cargo/.crates.toml
 INFO resolve: Resolving package: 'cargo-make@=0.36.3'
DEBUG resolve: Looking up crate information
DEBUG resolve: Found information for crate version: '0.36.3'
DEBUG resolve: Fetching crate from: https://crates.io//api/v1/crates/cargo-make/0.36.3/download and extracting Cargo.toml from it
DEBUG resolve:and_visit_tar{self=Download { client: Client(Inner { client: Client { accepts: Accepts { gzip: true, brotli: true, deflate: true }, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*", "user-agent": "cargo-binstall/0.20.1"} }, service: DelayRequest { inner: Mutex { data: RateLimit { inner: Client { accepts: Accepts { gzip: true, brotli: true, deflate: true }, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*", "user-agent": "cargo-binstall/0.20.1"} }, rate: Rate { num: 1, per: 5ms }, state: Ready { until: Instant { tv_sec: 68, tv_nsec: 524367839 }, rem: 1 }, sleep: Sleep { inner: Inner { deadline: Instant { tv_sec: 68, tv_nsec: 524367839 } }, entry: TimerEntry { driver: MultiThread(multi_thread::Handle { ... }), inner: UnsafeCell { .. }, initial_deadline: Some(Instant { tv_sec: 68, tv_nsec: 524367839 }), _m: PhantomPinned } } } }, hosts_to_delay: Mutex { data: {}, poisoned: false, .. } } }), url: Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("crates.io")), port: None, path: "//api/v1/crates/cargo-make/0.36.3/download", query: None, fragment: None }, _digest: PhantomData<binstalk_downloader::download::NoDigest>, _checksum: [] } fmt=Tgz}: Downloading from: 'https://crates.io//api/v1/crates/cargo-make/0.36.3/download'
DEBUG resolve:and_visit_tar{self=Download { client: Client(Inner { client: Client { accepts: Accepts { gzip: true, brotli: true, deflate: true }, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*", "user-agent": "cargo-binstall/0.20.1"} }, service: DelayRequest { inner: Mutex { data: RateLimit { inner: Client { accepts: Accepts { gzip: true, brotli: true, deflate: true }, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*", "user-agent": "cargo-binstall/0.20.1"} }, rate: Rate { num: 1, per: 5ms }, state: Ready { until: Instant { tv_sec: 68, tv_nsec: 524367839 }, rem: 1 }, sleep: Sleep { inner: Inner { deadline: Instant { tv_sec: 68, tv_nsec: 524367839 } }, entry: TimerEntry { driver: MultiThread(multi_thread::Handle { ... }), inner: UnsafeCell { .. }, initial_deadline: Some(Instant { tv_sec: 68, tv_nsec: 524367839 }), _m: PhantomPinned } } } }, hosts_to_delay: Mutex { data: {}, poisoned: false, .. } } }), url: Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("crates.io")), port: None, path: "//api/v1/crates/cargo-make/0.36.3/download", query: None, fragment: None }, _digest: PhantomData<binstalk_downloader::download::NoDigest>, _checksum: [] } fmt=Tgz}: Downloading and extracting then in-memory processing
DEBUG resolve:and_visit_tar{self=Download { client: Client(Inner { client: Client { accepts: Accepts { gzip: true, brotli: true, deflate: true }, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*", "user-agent": "cargo-binstall/0.20.1"} }, service: DelayRequest { inner: Mutex { data: RateLimit { inner: Client { accepts: Accepts { gzip: true, brotli: true, deflate: true }, proxies: [Proxy(System({}), None)], referer: true, default_headers: {"accept": "*/*", "user-agent": "cargo-binstall/0.20.1"} }, rate: Rate { num: 1, per: 5ms }, state: Ready { until: Instant { tv_sec: 68, tv_nsec: 524367839 }, rem: 1 }, sleep: Sleep { inner: Inner { deadline: Instant { tv_sec: 68, tv_nsec: 524367839 } }, entry: TimerEntry { driver: MultiThread(multi_thread::Handle { ... }), inner: UnsafeCell { .. }, initial_deadline: Some(Instant { tv_sec: 68, tv_nsec: 524367839 }), _m: PhantomPinned } } } }, hosts_to_delay: Mutex { data: {}, poisoned: false, .. } } }), url: Url { scheme: "https", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("crates.io")), port: None, path: "//api/v1/crates/cargo-make/0.36.3/download", query: None, fragment: None }, _digest: PhantomData<binstalk_downloader::download::NoDigest>, _checksum: [] } fmt=Tgz}: Extracting from Tgz archive to process it in memory
DEBUG run time: 547.419677ms
ERROR Fatal error:

  × For crate cargo-make: I/O Error: unexpected EOF during skip
  ╰─▶ I/O Error: unexpected EOF during skip

This is the debug log we got from CI

[NobodyXu]

Thanks @indietyp , the debug log shows that this error occurs when extracting tarball downloads from https://crates.io

I'm still confused on where "unexpected EOF during skip" comes from.
It's likely comes from tokio-tar, but searching this in their repo does not show anything.

I might have to add more logging and re-check and_visit_tar method impl and might open another issue in the upstream.

[indietyp]

It is from tokio-tar, specifically from this snippet:

https://github.com/vorot93/tokio-tar/blob/1bd30fbd1a219e8982571da48eb68f34317d1e15/src/archive.rs#L637-L658

[NobodyXu]

Thanks!

This could be a bug in impl BufRead for StreamReadable, I would submit a PR to fix this.

[indietyp]

Is there a possibility of a new release soon? I'd love to test the changes on our CI to verify everything works and re-enable binstall!

[NobodyXu]

Is there a possibility of a new release soon? I'd love to test the changes on our CI to verify everything works and re-enable binstall!

I am a little busy recently and I might be able to do one next Monday.
If you urgently need it, I can try making a patch release tonight.

[indietyp]

No worries, it isn't urgently needed, I am just very excited to try out the fix :D