itsscb/cargo
1
0
Fork 0
mirror of https://github.com/rust-lang/cargo.git synced 2025-09-28 11:20:36 +00:00
Code Issues Packages Projects Releases Wiki Activity

Auto merge of #11878 - ehuss:header-diagnostics, r=weihanglo

Browse Source 
Add more information to HTTP errors to help with debugging.

This adds some extra information to the HTTP error message about some headers and the remote IP address that could potentially be useful in diagnosing issues.

Closes #8691
This commit is contained in:
bors 2023-04-12 18:57:04 +00:00
commit 38376893bd
6 changed files with 268 additions and 32 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

32
src/cargo/core/package.rs
View File

@ -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<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,
@ -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);
@ -862,12 +880,12 @@ impl<'a, 'cfg> Downloads<'a, 'cfg> {
let code = handle.response_code()?;
if code != 200 && code != 0 {
let url = handle.effective_url()?.unwrap_or(url);
return Err(HttpNotSuccessful {
code,
url: url.to_string(),
body: data,
}
return Err(HttpNotSuccessful::new_from_handle(
&mut handle,
&url,
data,
headers,
)
.into());
}
Ok(data)

25
src/cargo/sources/registry/http_remote.rs
View File

@ -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<String>,
etag: Option<String>,
www_authenticate: Vec<String>,
others: Vec<String>,
}
enum StatusCode {
@ -287,13 +288,13 @@ impl<'cfg> HttpRegistry<'cfg> {
304 => StatusCode::NotModified,
401 => StatusCode::Unauthorized,
404 | 410 | 451 => StatusCode::NotFound,
code => {
let url = handle.effective_url()?.unwrap_or(&url);
return Err(HttpNotSuccessful {
code,
url: url.to_owned(),
body: data,
}
_ => {
return Err(HttpNotSuccessful::new_from_handle(
&mut handle,
&url,
data,
download.header_map.take().others,
)
.into());
}
};
@ -546,6 +547,8 @@ impl<'cfg> RegistryData for HttpRegistry<'cfg> {
code: 401,
body: result.data,
url: self.full_url(path),
ip: None,
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}"));
}
}
}
}
});

81
src/cargo/util/errors.rs
View File

@ -1,31 +1,100 @@
#![allow(unknown_lints)]
use anyhow::Error;
use std::fmt;
use curl::easy::Easy;
use std::fmt::{self, Write};
use std::path::PathBuf;
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] = &[
// This is the unique ID that identifies the request in CloudFront which
// can be used for looking at the AWS logs.
"x-amz-cf-id",
// This is the CloudFront POP (Point of Presence) that identifies the
// region where the request was routed. This can help identify if an issue
// is region-specific.
"x-amz-cf-pop",
// The unique token used for troubleshooting S3 requests via AWS logs or support.
"x-amz-request-id",
// Another token used in conjunction with x-amz-request-id.
"x-amz-id-2",
// Whether or not there was a cache hit or miss (both CloudFront and Fastly).
"x-cache",
// The cache server that processed the request (Fastly).
"x-served-by",
];
#[derive(Debug)]
pub struct HttpNotSuccessful {
pub code: u32,
pub url: String,
pub ip: Option<String>,
pub body: Vec<u8>,
pub headers: Vec<String>,
}
impl fmt::Display for HttpNotSuccessful {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
impl HttpNotSuccessful {
pub fn new_from_handle(
handle: &mut Easy,
initial_url: &str,
body: Vec<u8>,
headers: Vec<String>,
) -> HttpNotSuccessful {
let ip = handle.primary_ip().ok().flatten().map(|s| s.to_string());
let url = handle
.effective_url()
.ok()
.flatten()
.unwrap_or(initial_url)
.to_string();
HttpNotSuccessful {
code: handle.response_code().unwrap_or(0),
url,
ip,
body,
headers,
}
}
/// Renders the error in a compact form.
pub fn display_short(&self) -> String {
self.render(false)
}
fn render(&self, show_headers: bool) -> String {
let mut result = String::new();
let body = std::str::from_utf8(&self.body)
.map(|s| truncate_with_ellipsis(s, 512))
.unwrap_or_else(|_| format!("[{} non-utf8 bytes]", self.body.len()));
write!(
f,
"failed to get successful HTTP response from `{}`, got {}\nbody:\n{body}",
self.url, self.code
result,
"failed to get successful HTTP response from `{}`",
self.url
)
.unwrap();
if let Some(ip) = &self.ip {
write!(result, " ({ip})").unwrap();
}
write!(result, ", got {}\n", self.code).unwrap();
if show_headers {
if !self.headers.is_empty() {
write!(result, "debug headers:\n{}\n", self.headers.join("\n")).unwrap();
}
}
write!(result, "body:\n{body}").unwrap();
result
}
}
impl fmt::Display for HttpNotSuccessful {
fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
f.write_str(&self.render(true))
}
}

17
src/cargo/util/network/retry.rs
View File

@ -44,10 +44,13 @@ impl<'a> Retry<'a> {
pub fn r#try<T>(&mut self, f: impl FnOnce() -> CargoResult<T>) -> RetryResult<T> {
match f() {
Err(ref e) if maybe_spurious(e) && self.retries < self.max_retries => {
let err_msg = e
.downcast_ref::<HttpNotSuccessful>()
.map(|http_err| http_err.display_short())
.unwrap_or_else(|| e.root_cause().to_string());
let msg = format!(
"spurious network error ({} tries remaining): {}",
"spurious network error ({} tries remaining): {err_msg}",
self.max_retries - self.retries,
e.root_cause(),
);
if let Err(e) = self.config.shell().warn(msg) {
return RetryResult::Err(e);
@ -150,13 +153,17 @@ fn with_retry_repeats_the_call_then_works() {
let error1 = HttpNotSuccessful {
code: 501,
url: "Uri".to_string(),
ip: None,
body: Vec::new(),
headers: Vec::new(),
}
.into();
let error2 = HttpNotSuccessful {
code: 502,
url: "Uri".to_string(),
ip: None,
body: Vec::new(),
headers: Vec::new(),
}
.into();
let mut results: Vec<CargoResult<()>> = vec![Ok(()), Err(error1), Err(error2)];
@ -175,13 +182,17 @@ fn with_retry_finds_nested_spurious_errors() {
let error1 = anyhow::Error::from(HttpNotSuccessful {
code: 501,
url: "Uri".to_string(),
ip: None,
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(),
ip: None,
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)];
@ -199,7 +210,9 @@ fn default_retry_schedule() {
Err(anyhow::Error::from(HttpNotSuccessful {
code: 500,
url: "Uri".to_string(),
ip: None,
body: Vec::new(),
headers: Vec::new(),
}))
};
let config = Config::default().unwrap();

141
tests/testsuite/registry.rs
View File

@ -2743,10 +2743,10 @@ fn sparse_retry_single() {
.with_stderr(
"\
[UPDATING] `dummy-registry` index
warning: spurious network error (3 tries remaining): failed to get successful HTTP response from `[..]`, got 500
warning: spurious network error (3 tries remaining): failed to get successful HTTP response from `[..]` (127.0.0.1), got 500
body:
internal server error
warning: spurious network error (2 tries remaining): failed to get successful HTTP response from `[..]`, got 500
warning: spurious network error (2 tries remaining): failed to get successful HTTP response from `[..]` (127.0.0.1), got 500
body:
internal server error
[DOWNLOADING] crates ...
@ -2816,7 +2816,7 @@ fn sparse_retry_multiple() {
&mut expected,
"warning: spurious network error ({remain} tries remaining): \
failed to get successful HTTP response from \
`http://127.0.0.1:[..]/{ab}/{cd}/{name}`, got 500\n\
`http://127.0.0.1:[..]/{ab}/{cd}/{name}` (127.0.0.1), got 500\n\
body:\n\
internal server error\n"
)
@ -2876,10 +2876,12 @@ fn dl_retry_single() {
.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 500
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` (127.0.0.1), got 500
body:
internal server error
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 500
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` (127.0.0.1), got 500
body:
internal server error
[DOWNLOADED] bar v1.0.0 (registry `dummy-registry`)
@ -2954,7 +2956,7 @@ fn dl_retry_multiple() {
&mut expected,
"warning: spurious network error ({remain} tries remaining): \
failed to get successful HTTP response from \
`http://127.0.0.1:[..]/dl/{name}/1.0.0/download`, got 500\n\
`http://127.0.0.1:[..]/dl/{name}/1.0.0/download` (127.0.0.1), got 500\n\
body:\n\
internal server error\n"
)
@ -3274,3 +3276,130 @@ 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` (127.0.0.1), got 503
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` (127.0.0.1), got 503
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` (127.0.0.1), got 503
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` (127.0.0.1), 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` (127.0.0.1), got 503
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` (127.0.0.1), got 503
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` (127.0.0.1), got 503
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` (127.0.0.1), 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();
}

4
tests/testsuite/registry_auth.rs
View File

@ -57,7 +57,7 @@ fn requires_nightly() {
error: failed to download from `[..]/dl/bar/0.0.1/download`
Caused by:
failed to get successful HTTP response from `[..]`, got 401
failed to get successful HTTP response from `[..]` (127.0.0.1), got 401
body:
Unauthorized message from server.
"#,
@ -415,7 +415,7 @@ fn incorrect_token_git() {
[ERROR] failed to download from `http://[..]/dl/bar/0.0.1/download`
Caused by:
failed to get successful HTTP response from `http://[..]/dl/bar/0.0.1/download`, got 401
failed to get successful HTTP response from `http://[..]/dl/bar/0.0.1/download` (127.0.0.1), got 401
body:
Unauthorized message from server.",
)