diff --git a/src/cargo/core/package.rs b/src/cargo/core/package.rs index 912c80cc4..ff91e4a8b 100644 --- a/src/cargo/core/package.rs +++ b/src/cargo/core/package.rs @@ -26,7 +26,7 @@ use crate::core::{Dependency, Manifest, PackageId, SourceId, Target}; use crate::core::{SourceMap, Summary, Workspace}; use crate::ops; use crate::util::config::PackageCacheLock; -use crate::util::errors::{CargoResult, HttpNotSuccessful}; +use crate::util::errors::{CargoResult, HttpNotSuccessful, DEBUG_HEADERS}; use crate::util::interning::InternedString; use crate::util::network::retry::{Retry, RetryResult}; use crate::util::network::sleep::SleepTracker; @@ -379,6 +379,9 @@ struct Download<'cfg> { /// Actual downloaded data, updated throughout the lifetime of this download. data: RefCell>, + /// HTTP headers for debugging. + headers: RefCell>, + /// The URL that we're downloading from, cached here for error messages and /// reenqueuing. url: String, @@ -762,6 +765,19 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> { }); Ok(buf.len()) })?; + handle.header_function(move |data| { + tls::with(|downloads| { + if let Some(downloads) = downloads { + // Headers contain trailing \r\n, trim them to make it easier + // to work with. + let h = String::from_utf8_lossy(data).trim().to_string(); + if DEBUG_HEADERS.iter().any(|p| h.starts_with(p)) { + downloads.pending[&token].0.headers.borrow_mut().push(h); + } + } + }); + true + })?; handle.progress(true)?; handle.progress_function(move |dl_total, dl_cur, _, _| { @@ -787,6 +803,7 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> { let dl = Download { token, data: RefCell::new(Vec::new()), + headers: RefCell::new(Vec::new()), id, url, descriptor, @@ -826,6 +843,7 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> { .remove(&token) .expect("got a token for a non-in-progress transfer"); let data = mem::take(&mut *dl.data.borrow_mut()); + let headers = mem::take(&mut *dl.headers.borrow_mut()); let mut handle = self.set.multi.remove(handle)?; self.pending_ids.remove(&dl.id); @@ -867,6 +885,7 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> { code, url: url.to_string(), body: data, + headers, } .into()); } diff --git a/src/cargo/sources/registry/http_remote.rs b/src/cargo/sources/registry/http_remote.rs index ae89b629d..a9b20e2d4 100644 --- a/src/cargo/sources/registry/http_remote.rs +++ b/src/cargo/sources/registry/http_remote.rs @@ -7,7 +7,7 @@ use crate::ops::{self}; use crate::sources::registry::download; use crate::sources::registry::MaybeLock; use crate::sources::registry::{LoadResponse, RegistryConfig, RegistryData}; -use crate::util::errors::{CargoResult, HttpNotSuccessful}; +use crate::util::errors::{CargoResult, HttpNotSuccessful, DEBUG_HEADERS}; use crate::util::network::retry::{Retry, RetryResult}; use crate::util::network::sleep::SleepTracker; use crate::util::{auth, Config, Filesystem, IntoUrl, Progress, ProgressStyle}; @@ -142,6 +142,7 @@ struct Headers { last_modified: Option, etag: Option, www_authenticate: Vec, + others: Vec, } enum StatusCode { @@ -293,6 +294,7 @@ impl<'cfg> HttpRegistry<'cfg> { code, url: url.to_owned(), body: data, + headers: download.header_map.take().others, } .into()); } @@ -546,6 +548,7 @@ impl<'cfg> RegistryData for HttpRegistry<'cfg> { code: 401, body: result.data, url: self.full_url(path), + headers: result.header_map.others, } .into()); if self.auth_required { @@ -665,7 +668,11 @@ impl<'cfg> RegistryData for HttpRegistry<'cfg> { LAST_MODIFIED => header_map.last_modified = Some(value.to_string()), ETAG => header_map.etag = Some(value.to_string()), WWW_AUTHENTICATE => header_map.www_authenticate.push(value.to_string()), - _ => {} + _ => { + if DEBUG_HEADERS.iter().any(|prefix| tag.starts_with(prefix)) { + header_map.others.push(format!("{tag}: {value}")); + } + } } } }); diff --git a/src/cargo/util/errors.rs b/src/cargo/util/errors.rs index fb63f6ae2..99ac492cb 100644 --- a/src/cargo/util/errors.rs +++ b/src/cargo/util/errors.rs @@ -8,11 +8,22 @@ use super::truncate_with_ellipsis; pub type CargoResult = anyhow::Result; +/// These are headers that are included in error messages to help with +/// diagnosing issues. +pub const DEBUG_HEADERS: &[&str] = &[ + "x-amz-cf-id", + "x-amz-cf-pop", + "x-amz-id-2", + "x-cache", + "x-served-by", +]; + #[derive(Debug)] pub struct HttpNotSuccessful { pub code: u32, pub url: String, pub body: Vec, + pub headers: Vec, } impl fmt::Display for HttpNotSuccessful { @@ -23,9 +34,13 @@ impl fmt::Display for HttpNotSuccessful { write!( f, - "failed to get successful HTTP response from `{}`, got {}\nbody:\n{body}", - self.url, self.code - ) + "failed to get successful HTTP response from `{}`, got {}\n", + self.url, self.code, + )?; + if !self.headers.is_empty() { + write!(f, "debug headers:\n{}\n", self.headers.join("\n"))?; + } + write!(f, "body:\n{body}",) } } diff --git a/src/cargo/util/network/retry.rs b/src/cargo/util/network/retry.rs index 2ee2c1223..9d293b672 100644 --- a/src/cargo/util/network/retry.rs +++ b/src/cargo/util/network/retry.rs @@ -151,12 +151,14 @@ fn with_retry_repeats_the_call_then_works() { code: 501, url: "Uri".to_string(), body: Vec::new(), + headers: Vec::new(), } .into(); let error2 = HttpNotSuccessful { code: 502, url: "Uri".to_string(), body: Vec::new(), + headers: Vec::new(), } .into(); let mut results: Vec> = vec![Ok(()), Err(error1), Err(error2)]; @@ -176,12 +178,14 @@ fn with_retry_finds_nested_spurious_errors() { code: 501, url: "Uri".to_string(), body: Vec::new(), + headers: Vec::new(), }); let error1 = anyhow::Error::from(error1.context("A non-spurious wrapping err")); let error2 = anyhow::Error::from(HttpNotSuccessful { code: 502, url: "Uri".to_string(), body: Vec::new(), + headers: Vec::new(), }); let error2 = anyhow::Error::from(error2.context("A second chained error")); let mut results: Vec> = vec![Ok(()), Err(error1), Err(error2)]; @@ -200,6 +204,7 @@ fn default_retry_schedule() { code: 500, url: "Uri".to_string(), body: Vec::new(), + headers: Vec::new(), })) }; let config = Config::default().unwrap(); diff --git a/tests/testsuite/registry.rs b/tests/testsuite/registry.rs index 68a16d222..d36929500 100644 --- a/tests/testsuite/registry.rs +++ b/tests/testsuite/registry.rs @@ -3274,3 +3274,148 @@ or use environment variable CARGO_REGISTRY_TOKEN .with_status(101) .run(); } + +const SAMPLE_HEADERS: &[&str] = &[ + "x-amz-cf-pop: SFO53-P2", + "x-amz-cf-id: vEc3osJrCAXVaciNnF4Vev-hZFgnYwmNZtxMKRJ5bF6h9FTOtbTMnA==", + "x-cache: Hit from cloudfront", + "server: AmazonS3", + "x-amz-version-id: pvsJYY_JGsWiSETZvLJKb7DeEW5wWq1W", + "x-amz-server-side-encryption: AES256", + "content-type: text/plain", + "via: 1.1 bcbc5b46216015493e082cfbcf77ef10.cloudfront.net (CloudFront)", +]; + +#[cargo_test] +fn debug_header_message_index() { + // The error message should include some headers for debugging purposes. + let _server = RegistryBuilder::new() + .http_index() + .add_responder("/index/3/b/bar", |_, _| Response { + code: 503, + headers: SAMPLE_HEADERS.iter().map(|s| s.to_string()).collect(), + body: b"Please slow down".to_vec(), + }) + .build(); + Package::new("bar", "1.0.0").publish(); + + let p = project() + .file( + "Cargo.toml", + r#" + [package] + name = "foo" + version = "0.1.0" + + [dependencies] + bar = "1.0" + "#, + ) + .file("src/lib.rs", "") + .build(); + p.cargo("fetch").with_status(101).with_stderr("\ +[UPDATING] `dummy-registry` index +warning: spurious network error (3 tries remaining): failed to get successful HTTP response from `http://127.0.0.1:[..]/index/3/b/bar`, got 503 +debug headers: +x-amz-cf-pop: SFO53-P2 +x-amz-cf-id: vEc3osJrCAXVaciNnF4Vev-hZFgnYwmNZtxMKRJ5bF6h9FTOtbTMnA== +x-cache: Hit from cloudfront +body: +Please slow down +warning: spurious network error (2 tries remaining): failed to get successful HTTP response from `http://127.0.0.1:[..]/index/3/b/bar`, got 503 +debug headers: +x-amz-cf-pop: SFO53-P2 +x-amz-cf-id: vEc3osJrCAXVaciNnF4Vev-hZFgnYwmNZtxMKRJ5bF6h9FTOtbTMnA== +x-cache: Hit from cloudfront +body: +Please slow down +warning: spurious network error (1 tries remaining): failed to get successful HTTP response from `http://127.0.0.1:[..]/index/3/b/bar`, got 503 +debug headers: +x-amz-cf-pop: SFO53-P2 +x-amz-cf-id: vEc3osJrCAXVaciNnF4Vev-hZFgnYwmNZtxMKRJ5bF6h9FTOtbTMnA== +x-cache: Hit from cloudfront +body: +Please slow down +error: failed to get `bar` as a dependency of package `foo v0.1.0 ([ROOT]/foo)` + +Caused by: + failed to query replaced source registry `crates-io` + +Caused by: + download of 3/b/bar failed + +Caused by: + failed to get successful HTTP response from `http://127.0.0.1:[..]/index/3/b/bar`, got 503 + debug headers: + x-amz-cf-pop: SFO53-P2 + x-amz-cf-id: vEc3osJrCAXVaciNnF4Vev-hZFgnYwmNZtxMKRJ5bF6h9FTOtbTMnA== + x-cache: Hit from cloudfront + body: + Please slow down +").run(); +} + +#[cargo_test] +fn debug_header_message_dl() { + // Same as debug_header_message_index, but for the dl endpoint which goes + // through a completely different code path. + let _server = RegistryBuilder::new() + .http_index() + .add_responder("/dl/bar/1.0.0/download", |_, _| Response { + code: 503, + headers: SAMPLE_HEADERS.iter().map(|s| s.to_string()).collect(), + body: b"Please slow down".to_vec(), + }) + .build(); + Package::new("bar", "1.0.0").publish(); + let p = project() + .file( + "Cargo.toml", + r#" + [package] + name = "foo" + version = "0.1.0" + + [dependencies] + bar = "1.0" + "#, + ) + .file("src/lib.rs", "") + .build(); + + p.cargo("fetch").with_status(101).with_stderr("\ +[UPDATING] `dummy-registry` index +[DOWNLOADING] crates ... +warning: spurious network error (3 tries remaining): failed to get successful HTTP response from `http://127.0.0.1:[..]/dl/bar/1.0.0/download`, got 503 +debug headers: +x-amz-cf-pop: SFO53-P2 +x-amz-cf-id: vEc3osJrCAXVaciNnF4Vev-hZFgnYwmNZtxMKRJ5bF6h9FTOtbTMnA== +x-cache: Hit from cloudfront +body: +Please slow down +warning: spurious network error (2 tries remaining): failed to get successful HTTP response from `http://127.0.0.1:[..]/dl/bar/1.0.0/download`, got 503 +debug headers: +x-amz-cf-pop: SFO53-P2 +x-amz-cf-id: vEc3osJrCAXVaciNnF4Vev-hZFgnYwmNZtxMKRJ5bF6h9FTOtbTMnA== +x-cache: Hit from cloudfront +body: +Please slow down +warning: spurious network error (1 tries remaining): failed to get successful HTTP response from `http://127.0.0.1:[..]/dl/bar/1.0.0/download`, got 503 +debug headers: +x-amz-cf-pop: SFO53-P2 +x-amz-cf-id: vEc3osJrCAXVaciNnF4Vev-hZFgnYwmNZtxMKRJ5bF6h9FTOtbTMnA== +x-cache: Hit from cloudfront +body: +Please slow down +error: failed to download from `http://127.0.0.1:[..]/dl/bar/1.0.0/download` + +Caused by: + failed to get successful HTTP response from `http://127.0.0.1:[..]/dl/bar/1.0.0/download`, got 503 + debug headers: + x-amz-cf-pop: SFO53-P2 + x-amz-cf-id: vEc3osJrCAXVaciNnF4Vev-hZFgnYwmNZtxMKRJ5bF6h9FTOtbTMnA== + x-cache: Hit from cloudfront + body: + Please slow down +").run(); +}