Timeout while fetching Servo’s dependencies on Windows

[SimonSapin]

In servo/servo#21863 I wanted to time cargo fetch on Servo with an empty $CARGO_HOME and see how much #6005 helped. With cargo 1.31.0-nightly (de314a8 2018-09-21), I tried four times but was not able to have it complete.

It seemed to spend long stretches of time with the last line of output like:

Downloading 217 crates, extracting influent ...

The filesystem on Windows can be somewhat slow, so if a crate contains many files it’s somewhat expected that extracting can take a while. However, during that time, the number 217 was not changing.

Are all downloads paused while extracting?

At the end, the output looks like:

warning: spurious network error (2 tries remaining): [28] Timeout was reached (Operation too slow. Less than 10 bytes/sec transferred the last 30 seconds)
warning: spurious network error (1 tries remaining): [28] Timeout was reached (Operation too slow. Less than 10 bytes/sec transferred the last 30 seconds)
error: failed to download from `https://crates.io/api/v1/crates/servo-freetype-sys/4.0.4/download`

Caused by:
  [28] Timeout was reached (Operation too slow. Less than 10 bytes/sec transferred the last 30 seconds)

This was on AWS EC2. IIRC, crates.io is hosted on AWS S3. So I don’t expect that the network was actually that slow. Could it be that an ongoing download is paused while extracting a tarball, causing a timeout?

If so, would it be preferable to have a tarball-extracting thread completely separate from downloads, with an unbounded queue between them?

[SimonSapin]

Updating the influent crate from version 0.4.0 (which accidentally included 22095 unnecessary files) allows cargo fetch to complete. Using a Servo commit like 021a24d5bb8dc54bc4496b528d821f11aa3ca745 before the update servo/servo#21865 or using influent 0.4.0 in a synthetic test case should help reproduce the problem.

[alexcrichton]

Oh dear sounds bad! This is almost for sure caused by #6005 and the restructuring of how we're using curl to download crates.

I believe the problem here is that the new strategy is "create a set of a bunch of transfers" and then we finish them (synchronously) one-by-one. While we're finishing a transfer all the other transfers presumably still have their timeout clocks still running, which means once the slow filesystem finishes all the transfers have "timed out". A bug in Cargo's configuration of libcurl!

There's a few ways we could solve this:

• One is to use libcurl APIs to tweak timers. I've posted to their mailing list to clarify whether that'll work in this strategy or not. (or if there's an easier approach)
• Another is to do tarball extraction and writing to the filesystem asynchronously. In addition to not being a trivial change I think this probably still won't account for filesystem locks (we need to lock the destination when writing it out) which shouldn't happen asynchronously (don't want Cargo to print out tons of "locking" messages!). To that end this will probably solve the "only one Cargo in use" use case but wouldn't solve the concurrent Cargo use case.

In any case, I'll try to get this fixed soon!

[alexcrichton]

Ok I think this should be fixed by #6130