Rustup failed (probably because of a spurious network error), but then keeps failing consistently after that

golddranks commented 7 years ago

I tried to update with rustup update. It failed with error: component download failed for rust-std-x86_64-unknown-linux-musl, and I tried again – it keeps failing:

~ $ rustup update
info: syncing channel updates for 'nightly-x86_64-apple-darwin'
info: latest update on 2017-08-26, rust version 1.21.0-nightly (2aeb5930f 2017-08-25)
info: downloading component 'rustc'
info: downloading component 'rust-std'
info: downloading component 'cargo'
info: downloading component 'rust-docs'
info: downloading component 'rust-std' for 'x86_64-unknown-linux-musl'
error: component download failed for rust-std-x86_64-unknown-linux-musl
info: checking for self-updates

  nightly-x86_64-apple-darwin update failed - rustc 1.21.0-nightly (2c0558f63 2017-08-24)

Randomly trying with rustup update nightly, it spouts a more detailed error (I'm not sure, but the difference in the level of detail could be also considered as a bug?):

info: syncing channel updates for 'nightly-x86_64-apple-darwin'
info: latest update on 2017-08-26, rust version 1.21.0-nightly (2aeb5930f 2017-08-25)
info: downloading component 'rustc'
info: downloading component 'rust-std'
info: downloading component 'cargo'
info: downloading component 'rust-docs'
info: downloading component 'rust-std' for 'x86_64-unknown-linux-musl'
error: component download failed for rust-std-x86_64-unknown-linux-musl
info: caused by: could not download file from 'https://static.rust-lang.org/dist/2017-08-26/rust-std-nightly-x86_64-unknown-linux-musl.tar.xz' to '/Users/um003415/.rustup/downloads/e6108b2fa9ad25cb303e21e216a557e11a2a633586b9856de84064fade0651fc.partial'
info: caused by: error during download
info: caused by: [33] Requested range was not delivered by the server (HTTP server doesn't seem to support byte ranges. Cannot resume.)
info: backtrace:

stack backtrace:
   0:        0x1095998ae - backtrace::backtrace::trace::h44539d42e8c86729
   1:        0x10959a12c - backtrace::capture::Backtrace::new::h5f3de869c0349b3d
   2:        0x1095993d6 - error_chain::make_backtrace::h34ae912053f4a126
   3:        0x109560e86 - download::curl::download::hce069bb0f14d5dd2
   4:        0x10955f240 - download::download_to_path_with_backend::h117f20f63fa75168
   5:        0x1094d8057 - rustup_utils::utils::download_file_with_resume::h523bb0f3a635163f
   6:        0x1094a2a8f - rustup_dist::download::DownloadCfg::download::h11601c9bf443ac0a
   7:        0x10949b7d1 - rustup_dist::manifestation::Manifestation::update::h03e87519f12f2de4
   8:        0x10948611f - rustup_dist::dist::update_from_dist_::h9075ed00e47841fe
   9:        0x1094852d9 - rustup_dist::dist::update_from_dist::h68c861ce5520c639
  10:        0x109448290 - rustup::toolchain::Toolchain::install::h8d5d75e7a0a26413
  11:        0x109449011 - rustup::toolchain::Toolchain::install_from_dist_inner::h271107f0a7dae968
  12:        0x109448ca3 - rustup::toolchain::Toolchain::install_from_dist::hda92f29cbfc4b7a4
  13:        0x10939b46e - rustup_init::rustup_mode::update::hdf1cfff907031852
  14:        0x109388c38 - rustup_init::rustup_mode::main::hd56e0e782a4ea323
  15:        0x1093b4370 - rustup_init::run_rustup::hc3aac5a16c6bde4a
  16:        0x1093b3a39 - rustup_init::main::h07c1d4d8cd7703cf
  17:        0x1095c6daa - __rust_maybe_catch_panic
  18:        0x1095c61b6 - std::rt::lang_start::ha1f4f04346e51ef5

Deleting the .partial file allowed the update to succeed.

I'm using macOS 10.12.6.

Nemo157 commented 7 years ago

I got something similar when trying to update nightly that may explain what is happening. First attempt to update gave:

info: syncing channel updates for 'nightly-x86_64-apple-darwin'
info: downloading component 'rustc'
 43.1 MiB /  43.1 MiB (100 %)   1.1 MiB/s ETA:   0 s
info: downloading component 'rust-std'
 58.6 MiB /  58.6 MiB (100 %)   1.1 MiB/s ETA:   0 s
info: downloading component 'cargo'
  3.7 MiB /   3.7 MiB (100 %) 743.4 KiB/s ETA:   0 s
info: downloading component 'rust-docs'
error: component download failed for rust-docs-x86_64-apple-darwin
info: caused by: could not download file from 'https://static.rust-lang.org/dist/2017-10-11/rust-docs-nightly-x86_64-apple-darwin.tar.gz' to '/Users/Nemo157/.rustup/downloads/829f89113a895475250c05fa13af711da00afee2aa18c66cc70ce21a9049a2e2.partial'
info: caused by: http request returned an unsuccessful status code: 500

So, the server returned an error message. Next attempt gave:

info: syncing channel updates for 'nightly-x86_64-apple-darwin'
info: downloading component 'rustc'
info: downloading component 'rust-std'
info: downloading component 'cargo'
info: downloading component 'rust-docs'
 14.5 MiB /  14.5 MiB (100 %)   1.1 MiB/s ETA:   0 s
error: component download failed for rust-docs-x86_64-apple-darwin
info: caused by: checksum failed, expected: '829f89113a895475250c05fa13af711da00afee2aa18c66cc70ce21a9049a2e2', calculated: '6cfc64e3658643b18213213f03d9730683589dfe2410e13f64872466ec6225e3'

So, it successfully finished the download, but the checksum failed. Trying again:

info: syncing channel updates for 'nightly-x86_64-apple-darwin'
info: downloading component 'rustc'
info: downloading component 'rust-std'
info: downloading component 'cargo'
info: downloading component 'rust-docs'
error: component download failed for rust-docs-x86_64-apple-darwin
info: caused by: could not download file from 'https://static.rust-lang.org/dist/2017-10-11/rust-docs-nightly-x86_64-apple-darwin.tar.gz' to '/Users/Nemo157/.rustup/downloads/829f89113a895475250c05fa13af711da00afee2aa18c66cc70ce21a9049a2e2.partial'
info: caused by: error during download
info: caused by: [33] Requested range was not delivered by the server (HTTP server doesn't seem to support byte ranges. Cannot resume.)

Taking a look at /Users/Nemo157/.rustup/downloads/829f89113a895475250c05fa13af711da00afee2aa18c66cc70ce21a9049a2e2.partial shows that it starts with:

<?xml version="1.0" encoding="UTF-8"?>
<Error><Code>InternalError</Code><Message>We encountered an internal error. Please try again.</Message><RequestId>F040E9F386C1C50F</RequestId><HostId>HiLJqBd5mW3kwa0TQCyZJVCfRCYZnCluTyn4QXDxviI6tnOynzlckJsACryNFQOiiic+PjPuAyk=</HostId></Error>

It seems that there are 2 errors here:

When an error response is returned the partial file is not cleared out
When a partial file of the right size exists (after the second attempt) then rustup attempts to download with a 0-byte range to finish it off (this is quite a guess, but makes sense to me with the third error message)

pzmarzly commented 5 years ago

Rustup downloading backend seems to be changed from curl to reqwest, and rust-lang.org architecture seems to have changed as well, but the issue is still present:

$ rustup component add clippy
info: downloading component 'clippy'
^C⏎
$ rustup component add clippy
info: downloading component 'clippy'
error: component download failed for clippy-x86_64-unknown-linux-gnu
info: caused by: could not download file from 'https://static.rust-lang.org/dist/2019-05-12/clippy-nightly-x86_64-unknown-linux-gnu.tar.xz' to '/home/pzmarzly/.rustup/downloads/955c4a09184982b74dbe159c7eba8493b5a65bbce758e075dee61dd5da53a006.partial'
info: caused by: http request returned an unsuccessful status code: 416
$ # repeating the command above yields the same result, while I can download the file using the browser
$ rm rm ~/.rustup/downloads/955c4a09184982b74dbe159c7eba8493b5a65bbce758e075dee61dd5da53a006.partial
$ rustup component add clippy
info: downloading component 'clippy'
info: installing component 'clippy'
$ rustup --version
rustup 1.18.2 (a0bf3c9cb 2019-05-02)

kinnison commented 5 years ago

I don't suppose you retained the .partial file so that we can tell what was in it?

pzmarzly commented 5 years ago

No, but after few minutes of trying, I managed to recreate similar condition (using rust-src, as it's larger):

$ rustup component add rust-src
info: downloading component 'rust-src'
error: component download failed for rust-src
info: caused by: could not download file from 'https://static.rust-lang.org/dist/2019-05-12/rust-src-nightly.tar.xz' to '/home/pzmarzly/.rustup/downloads/f30adf7bff6cf72d1ea27a269fba8e8823d24ef8e42ea0b7048c7500796ba4f4.partial'
info: caused by: http request returned an unsuccessful status code: 416
$ 7z a -tzip -mx1 downloads.zip f30adf7bff6cf72d1ea27a269fba8e8823d24ef8e42ea0b7048c7500796ba4f4.partial
[...]
$ file downloads.zip
downloads.zip: Zip archive data, at least v?[0x30a] to extract

downloads.zip

kinnison commented 5 years ago

Fascinating - so the same thing happened as happened for @Nemo157 (i.e. the file is the right size) but this time the checksums match, so it's as though your download completes yet never signals completion to rustup somehow.

Do you have a proxy of some kind in the way of your internet connection, and if so might it be holding the connection open in a way rustup isn't expecting, I wonder.

I know that macos doesn't have strace, but I wonder if dtrace or truss or tusc or whatever it is that macos has might give us a hint as to what's going on with the first request which never completes.

Regarding the partial file being complete, we probably need some extra handling around that, so there's at least that bug to fix.

pzmarzly commented 5 years ago

In my case, I'm using OpenVPN, but that should be transparent to HTTPS layer. I triggered this bug by hitting Ctrl+C at the right moment, haven't tried or experienced network failures. I probably interrupted rustup during file validation (hashing)/renaming. I'm running Linux. Nemo's issue may be unrelated except for the last error (when file is right size)

kinnison commented 5 years ago

Right, but by whatever means you got the "complete" partial file, #1854 is important to solve so that you can subsequently proceed.

Dealing with the triggers that cause such a file to be laid down can then be the topic of this issue :D

rbtcollins commented 5 years ago

I think there are several related user frictions sitting here. 1) rust-lang infra need to handle range requests that end up sending 0 bytes - its legitimate HTTP traffic.

in download/src/lib.rs line 76. if the partial file doesn't open properly (e.g. readonly, in use, whatever) - it will error; if thats due to running rustup concurrently, thats on us but otherwise the user will have to manually recover.

The curl backend does check for resume offset being > 0 but it doesn't check for the existing file being the length of the desired file AFAICT; now that not being handled by web infra isn't strictly a rustup problem.... because we don't actually want a TOCTTOU race here - much better to make one request and get an empty range response back if we have all the content already.

I'm going to presume the reqwest backend is similar, it certainly looks like it.

2) If we resume a file and end up with the wrong hash we just throw an error - src/dist/download.rs line 87, similarly on line 163, but thats not with resume, just full-or-nothing I think.

in fact looking for whever ChecksumFailed turns up is probably a good thing to do

benaryorg commented 5 years ago

As a user of rustup I'd like rustup to delete the partial file and retry in case the backend returns a 416 Requested Range Not Satisfiable. After all, a 416 doesn't sound like a spurious failure, and hence restoring functionality to the user should take priority.

416 Requested Range Not Satisfiable on http.cat

[![416 Requested Range Not Satisfiable on http.cat](https://http.cat/416.jpg)](https://http.cat)

vojtechkral commented 5 years ago

Our whole team is running into this problem quite often. It seems using a toolchain file provokes this problem, but I can neither confirm that to be objectively true nor reproduce the problem reliably.

kinnison commented 5 years ago

It's highly unlikely to be related to rust-toolchain

marvin-bitterlich commented 5 years ago

Got the same problem on windows, every invocation of the command resumes the download and gets it a bit farther but after a few seconds it errors out. I will just retry until all is downloaded, but this seems to be a retryable problem.

kirillt commented 5 years ago

Got similar error on CentOS 7:

info: syncing channel updates for '1.37.0-x86_64-unknown-linux-gnu' info: latest update on 2019-08-15, rust version 1.37.0 (eae3437df 2019-08-13) info: downloading component 'rustc' info: downloading component 'rust-std' error: component download failed for rust-std-x86_64-unknown-linux-gnu info: caused by: could not download file from 'https://static.rust-lang.org/dist/2019-08-15/rust-> std-1.37.0-x86_64-unknown-linux-gnu.tar.xz' to '/home/kirill/.rustup/downloads/f8090dbd8a2dda674f8832f7999758b248028453465bf83f797569e28065fdbc.partial' info: caused by: http request returned an unsuccessful status code: 416

Downloading https://static.rust-lang.org/dist/2019-08-15/rust-std-1.37.0-x86_64-unknown-linux-gnu.tar.xz with wget succeeds.

Manual removing .partial file helped, but without it rustup appears stuck. Why it doesn't remove/archive broken file and retry?

kinnison commented 5 years ago

We have worked on retrying/fixing partial downloads in the past. Perhaps there's more we can do. I don't suppose you have any more information about the partial file you removed, such as whether or not it was actually complete?

kirillt commented 5 years ago

Sorry, I should have preserve it, but no..

kinnison commented 5 years ago

If it happens again, please preserve it so that we can try and work out what's going on.

kinnison commented 4 years ago

This appears to be related to #2071 and #1889 so I think current master should have fixed it.

rust-lang / rustup

Rustup failed (probably because of a spurious network error), but then keeps failing consistently after that #1243