Skip to content

Commit

Permalink
Show some HTTP headers in error messages.
Browse files Browse the repository at this point in the history
  • Loading branch information
@ehuss
ehuss committed Apr 12, 2023
1 parent 96f8d6c commit c7c9b8f
Show file tree
Hide file tree
Showing 5 changed files with 197 additions and 6 deletions.
21 changes: 20 additions & 1 deletion src/cargo/core/package.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -379,6 +379,9 @@ struct Download<'cfg> {
/// Actual downloaded data, updated throughout the lifetime of this download.
data: RefCell<Vec<u8>>,

/// HTTP headers for debugging.
headers: RefCell<Vec<String>>,

/// The URL that we're downloading from, cached here for error messages and
/// reenqueuing.
url: String,
Expand Down Expand Up @@ -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, _, _| {
Expand All @@ -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,
Expand Down Expand Up @@ -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);

Expand Down Expand Up @@ -867,6 +885,7 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> {
code,
url: url.to_string(),
body: data,
headers,
}
.into());
}
Expand Down
11 changes: 9 additions & 2 deletions src/cargo/sources/registry/http_remote.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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};
Expand Down Expand Up @@ -142,6 +142,7 @@ struct Headers {
last_modified: Option<String>,
etag: Option<String>,
www_authenticate: Vec<String>,
others: Vec<String>,
}

enum StatusCode {
Expand Down Expand Up @@ -293,6 +294,7 @@ impl<'cfg> HttpRegistry<'cfg> {
code,
url: url.to_owned(),
body: data,
headers: download.header_map.take().others,
}
.into());
}
Expand Down Expand Up @@ -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 {
Expand Down Expand Up @@ -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}"));
}
}
}
}
});
Expand Down
21 changes: 18 additions & 3 deletions src/cargo/util/errors.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -8,11 +8,22 @@ use super::truncate_with_ellipsis;

pub type CargoResult<T> = anyhow::Result<T>;

/// 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<u8>,
pub headers: Vec<String>,
}

impl fmt::Display for HttpNotSuccessful {
Expand All @@ -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}",)
}
}

Expand Down
5 changes: 5 additions & 0 deletions src/cargo/util/network/retry.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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<CargoResult<()>> = vec![Ok(()), Err(error1), Err(error2)];
Expand All @@ -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<CargoResult<()>> = vec![Ok(()), Err(error1), Err(error2)];
Expand All @@ -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();
Expand Down
145 changes: 145 additions & 0 deletions tests/testsuite/registry.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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();
}

0 comments on commit c7c9b8f

Please sign in to comment.